#3009 detect invalid cached credentials in ipasam
Closed: Fixed None Opened 11 years ago by abbra.

When developing and testing in the same environment, multiple re-installs
may be needed. This means previously issued and cached Kerberos credentials
will become invalid upon new install.

ipasam passdb module for Samba uses Kerberos authentication when talking to
IPA LDAP server. Obtained Kerberos credentials are cached during their lifetime.
However, the ccache is not removed automatically and if IPA setup is made
again, cached credentials are used, only to discover that they are invalid.

Aug 20 12:41:28 head smbd[17691]: [2012/08/20 12:41:28.771650,  0] ../source3/smbd/server.c:1253(main)
Aug 20 12:41:28 head smbd[17691]:   standard input is not a socket, assuming -D option
Aug 20 12:41:28 head systemd[1]: PID file /run/winbindd.pid not readable (yet?) after start.
Aug 20 12:41:28 head smbd[17692]: [2012/08/20 12:41:28.853959,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:28 head smbd[17692]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:28 head smbd[17692]: [2012/08/20 12:41:28.854871,  0] ../source3/lib/smbldap.c:998(smbldap_connect_system)
Aug 20 12:41:28 head smbd[17692]:   failed to bind to server ldapi://%2fvar%2frun%2fslapd-IPA-LOCAL.socket with dn="[Anonymous bind]" Error: Invalid credentials
Aug 20 12:41:28 head smbd[17692]:   #011SASL(-13): authentication failure: GSSAPI Failure: gss_accept_sec_context
Aug 20 12:41:28 head winbindd[17697]: [2012/08/20 12:41:28.867380,  0] ../source3/winbindd/winbindd_cache.c:3146(initialize_winbindd_cache)
Aug 20 12:41:28 head winbindd[17697]:   initialize_winbindd_cache: clearing cache and re-creating with version number 2
Aug 20 12:41:28 head winbindd[17700]: [2012/08/20 12:41:28.915248,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:28 head winbindd[17700]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:28 head winbindd[17700]: [2012/08/20 12:41:28.916178,  0] ../source3/lib/smbldap.c:998(smbldap_connect_system)
Aug 20 12:41:28 head winbindd[17700]:   failed to bind to server ldapi://%2fvar%2frun%2fslapd-IPA-LOCAL.socket with dn="[Anonymous bind]" Error: Invalid credentials
Aug 20 12:41:28 head winbindd[17700]:   #011SASL(-13): authentication failure: GSSAPI Failure: gss_accept_sec_context
Aug 20 12:41:29 head smbd[17692]: [2012/08/20 12:41:29.868730,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:29 head smbd[17692]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:29 head winbindd[17700]: [2012/08/20 12:41:29.925578,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:29 head winbindd[17700]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:30 head smbd[17692]: [2012/08/20 12:41:30.876198,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:30 head smbd[17692]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:30 head winbindd[17700]: [2012/08/20 12:41:30.938932,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:30 head winbindd[17700]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:31 head smbd[17692]: [2012/08/20 12:41:31.885482,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:31 head smbd[17692]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:31 head winbindd[17700]: [2012/08/20 12:41:31.947330,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:31 head winbindd[17700]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:32 head smbd[17692]: [2012/08/20 12:41:32.893327,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:32 head smbd[17692]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:32 head winbindd[17700]: [2012/08/20 12:41:32.952906,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:32 head winbindd[17700]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:33 head smbd[17692]: [2012/08/20 12:41:33.900073,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:33 head smbd[17692]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:33 head winbindd[17700]: [2012/08/20 12:41:33.959149,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:33 head winbindd[17700]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:34 head smbd[17692]: [2012/08/20 12:41:34.908732,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:34 head smbd[17692]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:34 head winbindd[17700]: [2012/08/20 12:41:34.966917,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:34 head winbindd[17700]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:35 head smbd[17692]: [2012/08/20 12:41:35.917586,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:35 head smbd[17692]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:35 head winbindd[17700]: [2012/08/20 12:41:35.971400,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:35 head winbindd[17700]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:36 head smbd[17692]: [2012/08/20 12:41:36.924611,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:36 head smbd[17692]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:36 head winbindd[17700]: [2012/08/20 12:41:36.980196,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:36 head winbindd[17700]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:37 head smbd[17692]: [2012/08/20 12:41:37.930819,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:37 head smbd[17692]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:37 head winbindd[17700]: [2012/08/20 12:41:37.985999,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:37 head winbindd[17700]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:38 head smbd[17692]: [2012/08/20 12:41:38.942878,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:38 head smbd[17692]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:38 head winbindd[17700]: [2012/08/20 12:41:38.996649,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:38 head winbindd[17700]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:39 head smbd[17692]: [2012/08/20 12:41:39.951291,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:39 head smbd[17692]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:40 head winbindd[17700]: [2012/08/20 12:41:40.003914,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:40 head winbindd[17700]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:40 head smbd[17692]: [2012/08/20 12:41:40.955784,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:40 head smbd[17692]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:41 head winbindd[17700]: [2012/08/20 12:41:41.012368,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:41 head winbindd[17700]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:41 head smbd[17692]: [2012/08/20 12:41:41.967464,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:41 head smbd[17692]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:42 head winbindd[17700]: [2012/08/20 12:41:42.022401,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:42 head winbindd[17700]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:42 head smbd[17692]: [2012/08/20 12:41:42.974147,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:42 head smbd[17692]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:43 head winbindd[17700]: [2012/08/20 12:41:43.030228,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:43 head winbindd[17700]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:43 head smbd[17692]: [2012/08/20 12:41:43.986674,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:43 head smbd[17692]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:44 head winbindd[17700]: [2012/08/20 12:41:44.034830,  0] ipa_sam.c:3340(bind_callback)
Aug 20 12:41:44 head winbindd[17700]:   bind_callback: cannot perform interactive SASL bind with GSSAPI
Aug 20 12:41:44 head smbd[17692]: [2012/08/20 12:41:44.987429,  0] ipa_sam.c:3501(pdb_init_ipasam)
Aug 20 12:41:44 head smbd[17692]:   Failed to get base DN.
Aug 20 12:41:44 head smbd[17692]: [2012/08/20 12:41:44.987646,  0] ../source3/passdb/pdb_interface.c:177(make_pdb_method_name)
Aug 20 12:41:44 head smbd[17692]:   pdb backend ipasam:ldapi://%2fvar%2frun%2fslapd-IPA-LOCAL.socket did not correctly init (error was NT_STATUS_UNSUCCESSFUL)
Aug 20 12:41:44 head systemd[1]: smb.service: main process exited, code=exited, status=1
Aug 20 12:41:44 head systemd[1]: Unit smb.service entered failed state.
Aug 20 12:41:45 head winbindd[17700]: [2012/08/20 12:41:45.035356,  0] ipa_sam.c:3501(pdb_init_ipasam)
Aug 20 12:41:45 head winbindd[17700]:   Failed to get base DN.
Aug 20 12:41:45 head winbindd[17700]: [2012/08/20 12:41:45.035426,  0] ../source3/passdb/pdb_interface.c:177(make_pdb_method_name)
Aug 20 12:41:45 head winbindd[17700]:   pdb backend ipasam:ldapi://%2fvar%2frun%2fslapd-IPA-LOCAL.socket did not correctly init (error was NT_STATUS_UNSUCCESSFUL)
Aug 20 12:41:45 head winbindd[17700]: [2012/08/20 12:41:45.035680,  0] ../source3/lib/util.c:892(smb_panic_s3)
Aug 20 12:41:45 head winbindd[17700]:   PANIC (pid 17700): pdb_get_methods: failed to get pdb methods for backend ipasam:ldapi://%2fvar%2frun%2fslapd-IPA-LOCAL.socket
Aug 20 12:41:45 head winbindd[17700]: 
Aug 20 12:41:45 head winbindd[17700]: [2012/08/20 12:41:45.112913,  0] ../source3/lib/util.c:1003(log_stack_trace)
Aug 20 12:41:45 head winbindd[17700]:   BACKTRACE: 26 stack frames:
Aug 20 12:41:45 head winbindd[17700]:    #0 /lib64/libsmbconf.so.0(log_stack_trace+0x1a) [0x7ffc94c5f0fa]
Aug 20 12:41:45 head winbindd[17700]:    #1 /lib64/libsmbconf.so.0(smb_panic_s3+0x20) [0x7ffc94c5f1d0]
Aug 20 12:41:45 head winbindd[17700]:    #2 /lib64/libsamba-util.so.0(smb_panic+0x2f) [0x7ffc98f0770f]
Aug 20 12:41:45 head winbindd[17700]:    #3 /usr/lib64/samba/libpdb.so.0(+0x2032f) [0x7ffc9729632f]
Aug 20 12:41:45 head winbindd[17700]:    #4 /usr/lib64/samba/libpdb.so.0(pdb_enum_trusteddoms+0x21) [0x7ffc97299221]
Aug 20 12:41:45 head winbindd[17700]:    #5 /usr/sbin/winbindd(_lsa_EnumTrustDom+0x93) [0x49b9e3]
Aug 20 12:41:45 head winbindd[17700]:    #6 /usr/sbin/winbindd() [0x4ab0b4]
Aug 20 12:41:45 head winbindd[17700]:    #7 /usr/sbin/winbindd() [0x4782d4]
Aug 20 12:41:45 head winbindd[17700]:    #8 /lib64/libdcerpc-binding.so.0(dcerpc_binding_handle_raw_call_send+0x9e) [0x7ffc974bc58e]
Aug 20 12:41:45 head winbindd[17700]:    #9 /lib64/libdcerpc-binding.so.0(dcerpc_binding_handle_call_send+0x258) [0x7ffc974bcd88]
Aug 20 12:41:45 head winbindd[17700]:    #10 /lib64/libdcerpc-binding.so.0(dcerpc_binding_handle_call+0x7e) [0x7ffc974bcebe]
Aug 20 12:41:45 head winbindd[17700]:    #11 /usr/lib64/samba/libdcerpc-samba.so(dcerpc_lsa_EnumTrustDom_r+0x1d) [0x7ffc9793399d]
Aug 20 12:41:45 head winbindd[17700]:    #12 /usr/lib64/samba/libdcerpc-samba.so(dcerpc_lsa_EnumTrustDom+0x22) [0x7ffc97933be2]
Aug 20 12:41:45 head winbindd[17700]:    #13 /usr/sbin/winbindd(rpc_trusted_domains+0x6d) [0x44966d]
Aug 20 12:41:45 head winbindd[17700]:    #14 /usr/sbin/winbindd() [0x44df4c]
Aug 20 12:41:45 head winbindd[17700]:    #15 /usr/sbin/winbindd() [0x4387ce]
Aug 20 12:41:45 head winbindd[17700]:    #16 /usr/sbin/winbindd(winbindd_dual_list_trusted_domains+0x3b) [0x43ec7b]
Aug 20 12:41:45 head winbindd[17700]:    #17 /usr/sbin/winbindd() [0x452f7c]
Aug 20 12:41:45 head winbindd[17700]:    #18 /usr/sbin/winbindd() [0x453a15]
Aug 20 12:41:45 head winbindd[17700]:    #19 /lib64/libtevent.so.0(tevent_common_loop_immediate+0xe2) [0x7ffc933ba752]
Aug 20 12:41:45 head winbindd[17700]:    #20 /lib64/libsmbconf.so.0(run_events_poll+0x47) [0x7ffc94c76717]
Aug 20 12:41:45 head winbindd[17700]:    #21 /lib64/libsmbconf.so.0(+0x3bb36) [0x7ffc94c76b36]
Aug 20 12:41:45 head winbindd[17700]:    #22 /lib64/libtevent.so.0(_tevent_loop_once+0x90) [0x7ffc933b9ed0]
Aug 20 12:41:45 head winbindd[17700]:    #23 /usr/sbin/winbindd(main+0x822) [0x4206b2]
Aug 20 12:41:45 head winbindd[17700]:    #24 /lib64/libc.so.6(__libc_start_main+0xf5) [0x7ffc92dd2735]
Aug 20 12:41:45 head winbindd[17700]:    #25 /usr/sbin/winbindd() [0x420ba1]
Aug 20 12:41:45 head winbindd[17700]: [2012/08/20 12:41:45.119814,  0] ../source3/lib/dumpcore.c:317(dump_core)
Aug 20 12:41:45 head winbindd[17700]:   dumping core in /var/log/samba/cores/winbindd
Aug 20 12:41:45 head winbindd[17700]:

Committed to master: 14c48ba

Committed to 3.0: 0552744

Moving closed RC1 tickets to Beta 3.

Metadata Update from @abbra:
- Issue assigned to abbra
- Issue set to the milestone: FreeIPA 3.0 Beta 3

7 years ago

Login to comment on this ticket.

Metadata