Winbind kerberos login
Evgeny Sinelnikov
sin at altlinux.ru
Wed Dec 28 22:15:05 UTC 2016
Hello,
today I got a strange behavior during login via PAM winbind.
Firstly, it looks like that krb5_ccache_type = KEYRING don't save
credential cache after "successful" login. But later, when I enable
debug level = 10, I found next logs with identical errors.
For krb5_ccache_type = FILE:
[2016/12/28 15:17:12.101783, 10, pid=21122, effective(0, 0), real(0,
0), class=winbind]
../source3/winbindd/winbindd_dual.c:512(child_process_request)
child_process_request: request fn PAM_AUTH
[2016/12/28 15:17:12.101800, 3, pid=21122, effective(0, 0), real(0,
0), class=winbind]
../source3/winbindd/winbindd_pam.c:1678(winbindd_dual_pam_auth)
[21119]: dual pam auth TEST\petrov
[2016/12/28 15:17:12.101815, 10, pid=21122, effective(0, 0), real(0,
0), class=winbind]
../source3/winbindd/winbindd_pam.c:1720(winbindd_dual_pam_auth)
winbindd_dual_pam_auth: domain: TEST last was online
[2016/12/28 15:17:12.101828, 10, pid=21122, effective(0, 0), real(0,
0), class=winbind]
../source3/winbindd/winbindd_pam.c:1172(winbindd_dual_pam_auth_kerberos)
winbindd_dual_pam_auth_kerberos
[2016/12/28 15:17:12.101843, 8, pid=21122, effective(0, 0), real(0,
0)] ../source3/lib/util.c:1239(is_myname)
is_myname("TEST") returns 0
[2016/12/28 15:17:12.101860, 10, pid=21122, effective(0, 0), real(0,
0), class=winbind]
../source3/winbindd/winbindd_pam.c:545(generate_krb5_ccache)
using ccache: FILE:/tmp/krb5cc_10002
[2016/12/28 15:17:12.101880, 10, pid=21122, effective(10002, 0),
real(10002, 0), class=winbind]
../source3/winbindd/winbindd_pam.c:668(winbindd_raw_kerberos_login)
winbindd_raw_kerberos_login: uid is 10002
[2016/12/28 15:17:12.101940, 10, pid=21122, effective(10002, 0),
real(10002, 0)]
../source3/libads/kerberos.c:228(kerberos_kinit_password_ext)
kerberos_kinit_password: as petrov at TEST.ALTLINUX using
[FILE:/tmp/krb5cc_10002] as ccache and config
[/var/lib/samba/smb_krb5/krb5.conf.TEST]
[2016/12/28 15:17:12.151696, 10, pid=21122, effective(10002, 0),
real(10002, 0)] ../source3/libads/authdata.c:180(kerberos_return_pac)
got TGT for petrov at TEST.ALTLINUX in FILE:/tmp/krb5cc_10002
valid until: Чт, 29 дек 2016 01:17:12 MSK (1482963432)
renewable till: Ср, 04 янв 2017 15:17:12 MSK (1483532232)
[2016/12/28 15:17:12.158284, 3, pid=21122, effective(10002, 0),
real(10002, 0)]
../lib/krb5_wrap/krb5_samba.c:376(ads_cleanup_expired_creds)
ads_cleanup_expired_creds: Ticket in ccache[FILE:/tmp/krb5cc_10002]
expiration Чт, 29 дек 2016 01:17:12 MSK
[2016/12/28 15:17:12.158908, 10, pid=21122, effective(10002, 0),
real(10002, 0)] ../lib/krb5_wrap/krb5_samba.c:643(ads_krb5_mk_req)
ads_krb5_mk_req: Ticket (KDESKTOP$@TEST.ALTLINUX) in ccache
(FILE:/tmp/krb5cc_10002) is valid until: (Чт, 29 дек 2016 01:17:12 MSK
- 1482963432)
[2016/12/28 15:17:12.159651, 10, pid=21122, effective(10002, 0),
real(10002, 0)]
../lib/krb5_wrap/krb5_samba.c:931(get_krb5_smb_session_key)
Got KRB5 session key of length 32
[2016/12/28 15:17:12.160255, 5, pid=21122, effective(10002, 0),
real(10002, 0)] ../auth/gensec/gensec_start.c:681(gensec_start_mech)
Starting GENSEC mechanism gse_krb5
[2016/12/28 15:17:12.162507, 10, pid=21122, effective(10002, 0),
real(10002, 0)] ../source3/lib/util.c:1986(name_to_fqdn)
name_to_fqdn: lookup for KDESKTOP -> KDESKTOP.test.altlinux.
[2016/12/28 15:17:12.162907, 1, pid=21122, effective(10002, 0),
real(10002, 0)]
../source3/librpc/crypto/gse_krb5.c:449(fill_mem_keytab_from_system_keytab)
../source3/librpc/crypto/gse_krb5.c:449: krb5_kt_start_seq_get
failed (Отказано в доступе)
[2016/12/28 15:17:12.162930, 1, pid=21122, effective(10002, 0),
real(10002, 0)]
../source3/librpc/crypto/gse_krb5.c:627(gse_krb5_get_server_keytab)
../source3/librpc/crypto/gse_krb5.c:627: Error! Unable to set mem keytab - 13
[2016/12/28 15:17:12.162949, 1, pid=21122, effective(10002, 0),
real(10002, 0)] ../auth/gensec/gensec_start.c:698(gensec_start_mech)
Failed to start GENSEC server mech gse_krb5: NT_STATUS_INTERNAL_ERROR
[2016/12/28 15:17:12.162965, 1, pid=21122, effective(10002, 0),
real(10002, 0)] ../source3/libads/authdata.c:274(kerberos_return_pac)
../source3/libads/authdata.c:274Failed to start server-side GENSEC
krb5 to validate a Kerberos ticket: NT_STATUS_INTERNAL_ERROR
[2016/12/28 15:17:12.162988, 10, pid=21122, effective(0, 0), real(0,
0), class=winbind]
../source3/winbindd/winbindd_pam.c:1734(winbindd_dual_pam_auth)
winbindd_dual_pam_auth_kerberos failed: NT_STATUS_INTERNAL_ERROR
[2016/12/28 15:17:12.163012, 3, pid=21122, effective(0, 0), real(0,
0), class=winbind]
../source3/winbindd/winbindd_pam.c:1763(winbindd_dual_pam_auth)
falling back to samlogon
[2016/12/28 15:17:12.163025, 10, pid=21122, effective(0, 0), real(0,
0), class=winbind]
../source3/winbindd/winbindd_pam.c:1503(winbindd_dual_pam_auth_samlogon)
winbindd_dual_pam_auth_samlogon
For krb5_ccache_type = KEYRING:
[2016/12/28 13:39:21.599512, 10, pid=16979, effective(0, 0), real(0,
0), class=winbind]
../source3/winbindd/winbindd_dual.c:512(child_process_request)
child_process_request: request fn PAM_AUTH
[2016/12/28 13:39:21.600103, 3, pid=16979, effective(0, 0), real(0,
0), class=winbind]
../source3/winbindd/winbindd_pam.c:1678(winbindd_dual_pam_auth)
[16977]: dual pam auth TEST\petrov
[2016/12/28 13:39:21.600796, 10, pid=16979, effective(0, 0), real(0,
0), class=winbind]
../source3/winbindd/winbindd_pam.c:1720(winbindd_dual_pam_auth)
winbindd_dual_pam_auth: domain: TEST last was online
[2016/12/28 13:39:21.601219, 10, pid=16979, effective(0, 0), real(0,
0), class=winbind]
../source3/winbindd/winbindd_pam.c:1172(winbindd_dual_pam_auth_kerberos)
winbindd_dual_pam_auth_kerberos
[2016/12/28 13:39:21.601563, 8, pid=16979, effective(0, 0), real(0,
0)] ../source3/lib/util.c:1239(is_myname)
is_myname("TEST") returns 0
[2016/12/28 13:39:21.601646, 10, pid=16979, effective(0, 0), real(0,
0), class=winbind]
../source3/winbindd/winbindd_pam.c:545(generate_krb5_ccache)
using ccache: KEYRING:persistent:10002
[2016/12/28 13:39:21.601669, 10, pid=16979, effective(10002, 0),
real(10002, 0), class=winbind]
../source3/winbindd/winbindd_pam.c:668(winbindd_raw_kerberos_login)
winbindd_raw_kerberos_login: uid is 10002
[2016/12/28 13:39:21.601730, 10, pid=16979, effective(10002, 0),
real(10002, 0)]
../source3/libads/kerberos.c:228(kerberos_kinit_password_ext)
kerberos_kinit_password: as petrov at TEST.ALTLINUX using
[KEYRING:persistent:10002] as ccache and config
[/var/lib/samba/smb_krb5/krb5.conf.TEST]
[2016/12/28 13:39:21.635637, 10, pid=16979, effective(10002, 0),
real(10002, 0)] ../source3/libads/authdata.c:180(kerberos_return_pac)
got TGT for petrov at TEST.ALTLINUX in KEYRING:persistent:10002
valid until: Ср, 28 дек 2016 23:39:21 MSK (1482957561)
renewable till: Ср, 04 янв 2017 13:39:21 MSK (1483526361)
[2016/12/28 13:39:21.642937, 3, pid=16979, effective(10002, 0),
real(10002, 0)]
../lib/krb5_wrap/krb5_samba.c:376(ads_cleanup_expired_creds)
ads_cleanup_expired_creds: Ticket in
ccache[KEYRING:persistent:10002:10002] expiration Ср, 28 дек 2016
23:39:21 MSK
[2016/12/28 13:39:21.643575, 10, pid=16979, effective(10002, 0),
real(10002, 0)] ../lib/krb5_wrap/krb5_samba.c:643(ads_krb5_mk_req)
ads_krb5_mk_req: Ticket (KDESKTOP$@TEST.ALTLINUX) in ccache
(KEYRING:persistent:10002:10002) is valid until: (Ср, 28 дек 2016
23:39:21 MSK - 1482957561)
[2016/12/28 13:39:21.644461, 10, pid=16979, effective(10002, 0),
real(10002, 0)]
../lib/krb5_wrap/krb5_samba.c:931(get_krb5_smb_session_key)
Got KRB5 session key of length 32
[2016/12/28 13:39:21.645050, 5, pid=16979, effective(10002, 0),
real(10002, 0)] ../auth/gensec/gensec_start.c:681(gensec_start_mech)
Starting GENSEC mechanism gse_krb5
[2016/12/28 13:39:21.646592, 10, pid=16979, effective(10002, 0),
real(10002, 0)] ../source3/lib/util.c:1986(name_to_fqdn)
name_to_fqdn: lookup for KDESKTOP -> KDESKTOP.test.altlinux.
[2016/12/28 13:39:21.646903, 1, pid=16979, effective(10002, 0),
real(10002, 0)]
../source3/librpc/crypto/gse_krb5.c:449(fill_mem_keytab_from_system_keytab)
../source3/librpc/crypto/gse_krb5.c:449: krb5_kt_start_seq_get
failed (Отказано в доступе)
[2016/12/28 13:39:21.647673, 1, pid=16979, effective(10002, 0),
real(10002, 0)]
../source3/librpc/crypto/gse_krb5.c:627(gse_krb5_get_server_keytab)
../source3/librpc/crypto/gse_krb5.c:627: Error! Unable to set mem keytab - 13
[2016/12/28 13:39:21.647704, 1, pid=16979, effective(10002, 0),
real(10002, 0)] ../auth/gensec/gensec_start.c:698(gensec_start_mech)
Failed to start GENSEC server mech gse_krb5: NT_STATUS_INTERNAL_ERROR
[2016/12/28 13:39:21.647721, 1, pid=16979, effective(10002, 0),
real(10002, 0)] ../source3/libads/authdata.c:274(kerberos_return_pac)
../source3/libads/authdata.c:274Failed to start server-side GENSEC
krb5 to validate a Kerberos ticket: NT_STATUS_INTERNAL_ERROR
[2016/12/28 13:39:21.648480, 3, pid=16979, effective(0, 0), real(0,
0), class=winbind]
../source3/winbindd/winbindd_pam.c:794(winbindd_raw_kerberos_login)
winbindd_raw_kerberos_login: could not remove ccache for user TEST\petrov
[2016/12/28 13:39:21.648504, 10, pid=16979, effective(0, 0), real(0,
0), class=winbind]
../source3/winbindd/winbindd_pam.c:1734(winbindd_dual_pam_auth)
winbindd_dual_pam_auth_kerberos failed: NT_STATUS_INTERNAL_ERROR
[2016/12/28 13:39:21.648519, 3, pid=16979, effective(0, 0), real(0,
0), class=winbind]
../source3/winbindd/winbindd_pam.c:1763(winbindd_dual_pam_auth)
falling back to samlogon
[2016/12/28 13:39:21.648532, 10, pid=16979, effective(0, 0), real(0,
0), class=winbind]
../source3/winbindd/winbindd_pam.c:1503(winbindd_dual_pam_auth_samlogon)
winbindd_dual_pam_auth_samlogon
So, at first time credential cache saved after login via samlogon, but
not at second time.
It was because at first time existing valid credential cache not
deleted in winbindd_raw_kerberos_login():
failed:
/*
* Do not delete an existing valid credential cache, if the user
* e.g. enters a wrong password
*/
if ((strequal(krb5_cc_type, "FILE") || strequal(krb5_cc_type,
"WRFILE") || strequal(krb5_cc_type, "KEYRING"))
&& user_ccache_file != NULL) {
DEBUG(10,("winbindd_raw_kerberos_login: do not delete
an existing valid credential cache\n"));
return result;
}
/* we could have created a new credential cache with a valid tgt in it
* but we werent able to get or verify the service ticket for this
* local host and therefor didn't get the PAC, we need to remove that
* cache entirely now */
I applied patch that fix it for KEYRING. But it is not looks like
solution. It is workaround.
$ su - petrov
Password:
[petrov at kdesktop ~]$ klist
Ticket cache: KEYRING:persistent:10002:10002
Default principal: petrov at TEST.ALTLINUX
Valid starting Expires Service principal
29.12.2016 00:49:37 29.12.2016 10:49:37 KDESKTOP$@TEST.ALTLINUX
renew until 05.01.2017 00:49:37
29.12.2016 00:49:37 29.12.2016 10:49:37 krbtgt/TEST.ALTLINUX at TEST.ALTLINUX
renew until 05.01.2017 00:49:37
Basic problem occures in this part of winbindd_raw_kerberos_login()
during gse_krb5_get_server_keytab() without permisions:
/************************ ENTERING NON-ROOT **********************/
if (user_ccache_file != NULL) {
set_effective_uid(uid);
DEBUG(10,("winbindd_raw_kerberos_login: uid is %d\n", uid));
}
result = kerberos_return_pac(mem_ctx,
principal_s,
pass,
time_offset,
&ticket_lifetime,
&renewal_until,
cc,
true,
true,
WINBINDD_PAM_AUTH_KRB5_RENEW_TIME,
NULL,
local_service,
&pac_data_ctr);
if (user_ccache_file != NULL) {
gain_root_privilege();
}
/************************ RETURNED TO ROOT **********************/
[2016/12/28 13:39:21.646903, 1, pid=16979, effective(10002, 0),
real(10002, 0)]
../source3/librpc/crypto/gse_krb5.c:449(fill_mem_keytab_from_system_keytab)
../source3/librpc/crypto/gse_krb5.c:449: krb5_kt_start_seq_get
failed (Отказано в доступе)
[2016/12/28 13:39:21.647673, 1, pid=16979, effective(10002, 0),
real(10002, 0)]
../source3/librpc/crypto/gse_krb5.c:627(gse_krb5_get_server_keytab)
../source3/librpc/crypto/gse_krb5.c:627: Error! Unable to set mem keytab - 13
[2016/12/28 13:39:21.647704, 1, pid=16979, effective(10002, 0),
real(10002, 0)] ../auth/gensec/gensec_start.c:698(gensec_start_mech)
Failed to start GENSEC server mech gse_krb5: NT_STATUS_INTERNAL_ERROR
[2016/12/28 13:39:21.647721, 1, pid=16979, effective(10002, 0),
real(10002, 0)] ../source3/libads/authdata.c:274(kerberos_return_pac)
../source3/libads/authdata.c:274Failed to start server-side GENSEC
krb5 to validate a Kerberos ticket: NT_STATUS_INTERNAL_ERROR
And I don't understand yet how it should work correctly by design.
--
Sin (Sinelnikov Evgeny)
-------------- next part --------------
A non-text attachment was scrubbed...
Name: 0001-s3-winbind-do-not-delete-an-existing-valid-credentia.patch
Type: text/x-patch
Size: 1019 bytes
Desc: not available
URL: <http://lists.samba.org/pipermail/samba-technical/attachments/20161229/92659a64/0001-s3-winbind-do-not-delete-an-existing-valid-credentia.bin>
More information about the samba-technical
mailing list