The nightly test fedora-rawhide/test_forced_client_enrolment failed because of krb5kdc coredump. See PR #140 with the following logs.
fedora-rawhide/test_forced_client_enrolment
The stack trace can be found in the master's journal:
Feb 16 11:18:02 master.ipa.test systemd[1]: krb5kdc.service: Main process exited, code=dumped, status=11/SEGV Feb 16 11:18:02 master.ipa.test systemd[1]: krb5kdc.service: Failed with result 'core-dump'. Feb 16 11:18:02 master.ipa.test audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=krb5kdc comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed' Feb 16 11:18:02 master.ipa.test systemd-coredump[31826]: Process 29572 (krb5kdc) of user 0 dumped core. Stack trace of thread 29572: #0 0x00007f77dad466e0 krb5_dbe_lookup_tl_data (libkdb5.so.10 + 0x86e0) #1 0x00007f77dad470a4 krb5_dbe_get_string (libkdb5.so.10 + 0x90a4) #2 0x00007f77da2d4b12 ipadb_get_ldap_mod_auth_ind (ipadb.so + 0x9b12) #3 0x00007f77da2d720d ipadb_modify_principal (ipadb.so + 0xc20d) #4 0x00007f77da2dcc20 ipadb_audit_as_req (ipadb.so + 0x11c20) #5 0x000055a586330f26 log_as_req (krb5kdc + 0x1bf26) #6 0x000055a58631f077 finish_process_as_req (krb5kdc + 0xa077) #7 0x000055a58631fcf0 process_as_req (krb5kdc + 0xacf0) #8 0x000055a58631eb99 dispatch (krb5kdc + 0x9b99) #9 0x000055a586334336 process_tcp_connection_read (krb5kdc + 0x1f336) #10 0x00007f77dabf871c verto_fire (libverto.so.1 + 0x471c) #11 0x00007f77d6bba173 ev_invoke_pending (libev.so.4 + 0x6173) #12 0x00007f77d6bbe21b ev_run (libev.so.4 + 0xa21b) #13 0x000055a58631d85b main (krb5kdc + 0x885b) #14 0x00007f77daa51042 __libc_start_main (libc.so.6 + 0x27042) #15 0x000055a58631dcde _start (krb5kdc + 0x8cde) Feb 16 11:18:02 master.ipa.test systemd[1]: systemd-coredump@0-31825-0.service: Succeeded. Feb 16 11:18:02 master.ipa.test audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-coredump@0-31825-0 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
The last command before the failure was ipa host-del client0.ipa.test, then unshare --net ipa-client-install --uninstall -U.
ipa host-del client0.ipa.test
unshare --net ipa-client-install --uninstall -U
Initial investigation by @abbra
[10:51] <ab> Feb 16 11:18:01 master.ipa.test krb5kdc[29572](info): AS_REQ (6 etypes {aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), aes256-cts-hmac-sha384-192(20), camellia256-cts-cmac(26), aes128-cts-hmac-sha256-128(19), camellia128-cts-cmac(25)}) 192.168.122.123: CLIENT_NOT_FOUND: host/client0.ipa.test@IPA.TEST for krbtgt/IPA.TEST@IPA.TEST, Client not found in Kerberos database [10:51] <ab> in krb5kdc.log [10:52] <ab> then [10:52] <ab> Feb 16 11:18:01 master.ipa.test kernel: traps: krb5kdc[29572] general protection fault ip:7f77dad466e0 sp:7ffcf25f65a0 error:0 in libkdb5.so.10.0[7f77dad43000+c000] [10:52] <ab> Feb 16 11:18:01 master.ipa.test audit[29572]: ANOM_ABEND auid=4294967295 uid=0 gid=0 ses=4294967295 subj=system_u:system_r:krb5kdc_t:s0 pid=29572 comm="krb5kdc" exe="/usr/sbin/krb5kdc" sig=11 res=1 [10:52] <ab> I wonder what principal we are trying to modify [10:53] <ab> the client? (host/client0...) [10:54] <ab> it is most likely ipadb_put_principal() in ipadb_audit_as_req() [10:54] <ab> so it operates on the client [10:56] <flo> the last command before this timestamp is 'ipa', 'host-del', 'client0.ipa.test' and then 'unshare', '--net', 'ipa-client-install', '--uninstall', '-U' [10:56] <ab> yeah, so it is a principal that went away while kdc operated on it [10:57] <ab> so ipadb_modify_principal() tried to access something that disappeared [10:58] <flo> I will open a ticket with that info [10:58] <ab> we do [10:58] <ab> ret = krb5_dbe_get_string(kcontext, entry, "require_auth", &ais); [10:58] <ab> on entry [11:01] <ab> the krb5_dbe_lookup_tl_data() is within begin_attrs(), so this is not operating at all on ldap at this point [11:01] <ab> basically, we have a kerberos principal entry in KDC, MIT library operates on that one and the entry object is corrupted [11:02] <ab> the code in krb5_dbe_lookup_tl_data() does no checks on tl_data internals [11:03] <ab> e.g. some of that is NULL and tried to be unresolved [11:04] <ab> https://github.com/krb5/krb5/blob/master/src/lib/kdb/kdb5.c#L1514
PR: https://github.com/freeipa/freeipa/pull/4249
Metadata Update from @abbra: - Issue assigned to abbra
Metadata Update from @frenaud: - Custom field rhbz adjusted to https://bugzilla.redhat.com/show_bug.cgi?id=1803786
master:
ipa-4-8:
Metadata Update from @fcami: - Issue close_status updated to: fixed - Issue status updated to: Closed (was: Open)
Login to comment on this ticket.