freeipa

#9713 crash in krb5kdc on shutdown
Opened by slev. Modified

Open
Close Issue

The crash occurs quite often in azure CI.

backtrace:

GNU gdb (GDB) 14.1.0.56.d739d4fd457-alt1 (ALT Sisyphus)
Copyright (C) 2023 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-alt-linux".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/sbin/krb5kdc...
Reading symbols from /usr/lib/debug/usr/sbin/krb5kdc.debug...
[New LWP 2584]
Missing separate debuginfo for /lib64/libverto-libev.so.1.
Try to install the hash file /usr/lib/debug/.build-id/99/51414e3f81a6c931a53b65d1721f3371a17f08.debug
Missing separate debuginfo for /lib64/libev.so.4.
Try to install the hash file /usr/lib/debug/.build-id/9b/4a8b610baa66186cc37f25aaa863fd1d252f79.debug
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/sbin/krb5kdc -P /run/krb5kdc.pid -w 2'.
Program terminated with signal SIGABRT, Aborted.
#0  __pthread_kill_implementation (threadid=<optimized out>, 
    signo=signo@entry=6, no_tid=no_tid@entry=0) at pthread_kill.c:44
44        return INTERNAL_SYSCALL_ERROR_P (ret) ? INTERNAL_SYSCALL_ERRNO (ret) : 0;
Thread 1 (Thread 0x7f249cc70180 (LWP 2584)):
#0  __pthread_kill_implementation (threadid=<optimized out>, signo=signo@entry=6, no_tid=no_tid@entry=0) at pthread_kill.c:44
        tid = <optimized out>
        ret = 0
        pd = <optimized out>
        old_mask = {__val = {206158430256}}
        ret = <optimized out>
#1  0x00007f249ce266df in __pthread_kill_internal (signo=6, threadid=<optimized out>) at pthread_kill.c:78
No locals.
#2  0x00007f249cdd7982 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
        ret = <optimized out>
#3  0x00007f249cdc04ef in __GI_abort () at abort.c:79
        save_stage = 1
        act = {__sigaction_handler = {sa_handler = 0x20, sa_sigaction = 0x20}, sa_mask = {__val = {140734487287120, 94001382866640, 94001382866640, 6, 0, 11219809880, 0, 140734487287288, 0, 5, 140734487287136, 18446744073709551464, 2, 139795217477792, 95, 139795217486260}}, sa_flags = -1662825841, sa_restorer = 0x7f249cf72070 <_IO_file_jumps>}
#4  0x00007f249cdc0417 in __assert_fail_base (fmt=0x7f249cf39b98 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x7f249c4791b4 "ld != NULL", file=file@entry=0x7f249c4770a0 "search.c", line=line@entry=95, function=function@entry=0x7f249c47c1b0 <__PRETTY_FUNCTION__.3.lto_priv.0> "ldap_pvt_search") at assert.c:92
        str = 0x557e6708bed0 "k\034\3560{U"
        total = 4096
#5  0x00007f249cdd03a2 in __assert_fail (assertion=assertion@entry=0x7f249c4791b4 "ld != NULL", file=file@entry=0x7f249c4770a0 "search.c", line=line@entry=95, function=function@entry=0x7f249c47c1b0 <__PRETTY_FUNCTION__.3.lto_priv.0> "ldap_pvt_search") at assert.c:101
No locals.
#6  0x00007f249c4478d4 in ldap_pvt_search (ld=ld@entry=0x0, base=base@entry=0x557e66f66940 "dc=ipa,dc=test", scope=scope@entry=2, filter=filter@entry=0x557e66f1a540 "(&(|(objectclass=krbprincipalaux)(objectclass=krbprincipal)(objectclass=ipakrbprincipal))(|(ipakrbprincipalalias=host/master1.ipa.test@IPA.TEST)(krbprincipalname:caseIgnoreIA5Match:=host/master1.ipa.t"..., attrs=attrs@entry=0x7f249cc10860 <std_principal_attrs>, attrsonly=attrsonly@entry=0, sctrls=0x0, cctrls=0x0, timeout=0x7f249cc104f0 <std_timeout>, sizelimit=0, deref=-1, msgidp=0x7fff4d1f5764) at /usr/src/debug/openldap-2.6.8/libraries/libldap/search.c:95
        rc = <optimized out>
        ber = <optimized out>
        timelimit = <optimized out>
        id = 0
        __PRETTY_FUNCTION__ = "ldap_pvt_search"
#7  0x00007f249c44a77e in ldap_pvt_search_s (ld=0x0, base=base@entry=0x557e66f66940 "dc=ipa,dc=test", scope=scope@entry=2, filter=filter@entry=0x557e66f1a540 "(&(|(objectclass=krbprincipalaux)(objectclass=krbprincipal)(objectclass=ipakrbprincipal))(|(ipakrbprincipalalias=host/master1.ipa.test@IPA.TEST)(krbprincipalname:caseIgnoreIA5Match:=host/master1.ipa.t"..., attrs=attrs@entry=0x7f249cc10860 <std_principal_attrs>, attrsonly=attrsonly@entry=0, sctrls=0x0, cctrls=0x0, timeout=0x7f249cc104f0 <std_timeout>, sizelimit=0, deref=-1, res=0x7fff4d1f58b0) at /usr/src/debug/openldap-2.6.8/libraries/libldap/search.c:174
        rc = <optimized out>
        msgid = 21886
#8  0x00007f249c44a830 in ldap_search_ext_s (ld=<optimized out>, base=base@entry=0x557e66f66940 "dc=ipa,dc=test", scope=scope@entry=2, filter=filter@entry=0x557e66f1a540 "(&(|(objectclass=krbprincipalaux)(objectclass=krbprincipal)(objectclass=ipakrbprincipal))(|(ipakrbprincipalalias=host/master1.ipa.test@IPA.TEST)(krbprincipalname:caseIgnoreIA5Match:=host/master1.ipa.t"..., attrs=attrs@entry=0x7f249cc10860 <std_principal_attrs>, attrsonly=attrsonly@entry=0, sctrls=0x0, cctrls=0x0, timeout=0x7f249cc104f0 <std_timeout>, sizelimit=0, res=0x7fff4d1f58b0) at /usr/src/debug/openldap-2.6.8/libraries/libldap/search.c:150
No locals.
#9  0x00007f249cbfce24 in ipadb_simple_search (ipactx=0x557e66f29b30, basedn=0x557e66f66940 "dc=ipa,dc=test", scope=2, filter=0x557e66f1a540 "(&(|(objectclass=krbprincipalaux)(objectclass=krbprincipal)(objectclass=ipakrbprincipal))(|(ipakrbprincipalalias=host/master1.ipa.test@IPA.TEST)(krbprincipalname:caseIgnoreIA5Match:=host/master1.ipa.t"..., attrs=0x7f249cc10860 <std_principal_attrs>, res=0x7fff4d1f58b0) at /usr/src/debug/freeipa-4.12.2/daemons/ipa-kdb/ipa_kdb_common.c:252
        ret = -1
#10 ipadb_simple_search (ipactx=0x557e66f29b30, basedn=0x557e66f66940 "dc=ipa,dc=test", scope=2, filter=0x557e66f1a540 "(&(|(objectclass=krbprincipalaux)(objectclass=krbprincipal)(objectclass=ipakrbprincipal))(|(ipakrbprincipalalias=host/master1.ipa.test@IPA.TEST)(krbprincipalname:caseIgnoreIA5Match:=host/master1.ipa.t"..., attrs=0x7f249cc10860 <std_principal_attrs>, res=0x7fff4d1f58b0) at /usr/src/debug/freeipa-4.12.2/daemons/ipa-kdb/ipa_kdb_common.c:232
        ret = <optimized out>
#11 0x00007f249cc0968b in ipadb_fetch_principals_with_extra_filter.isra.0 (ipactx=0x557e66f29b30, principal=0x557e67076270 "host/master1.ipa.test@IPA.TEST", filter=<optimized out>, result=0x7fff4d1f58b0, flags=<optimized out>) at /usr/src/debug/freeipa-4.12.2/daemons/ipa-kdb/ipa_kdb_principals.c:1219
        kerr = <optimized out>
        src_filter = 0x557e66f1a540 "(&(|(objectclass=krbprincipalaux)(objectclass=krbprincipal)(objectclass=ipakrbprincipal))(|(ipakrbprincipalalias=host/master1.ipa.test@IPA.TEST)(krbprincipalname:caseIgnoreIA5Match:=host/master1.ipa.t"...
        esc_original_princ = 0x557e6708b770 "host/master1.ipa.test@IPA.TEST"
        ret = <optimized out>
        len = <optimized out>
#12 0x00007f249cc0447c in ipadb_fetch_principals (ipactx=0x557e66f29b30, flags=1728548376, principal=<optimized out>, result=0x7fff4d1f58b0) at /usr/src/debug/freeipa-4.12.2/daemons/ipa-kdb/ipa_kdb_principals.c:1232
No locals.
#13 dbget_princ (kcontext=kcontext@entry=warning: could not convert '_krb5_context' from the host encoding (UTF-8) to UTF-32.
This normally should not happen, please file a bug report.
0x557e66f63e40, ipactx=ipactx@entry=0x557e66f29b30, search_for=search_for@entry=0x557e670751e0, flags=flags@entry=80, entry=entry@entry=0x557e67078e18) at /usr/src/debug/freeipa-4.12.2/daemons/ipa-kdb/ipa_kdb_principals.c:1701
        kerr = 0
        principal = 0x557e67076270 "host/master1.ipa.test@IPA.TEST"
        res = 0x0
        lentry = 0x557e67078b10
        pol = 1247014367
        check = 64
#14 0x00007f249cc04b31 in ipadb_get_principal (kcontext=0x557e66f63e40, search_for=0x557e670751e0, flags=80, entry=0x557e67078e18) at /usr/src/debug/freeipa-4.12.2/daemons/ipa-kdb/ipa_kdb_principals.c:1981
        ipactx = 0x557e66f29b30
        is_local_tgs_princ = <optimized out>
        opt_pac_tkt_chksum_val = <optimized out>
        kerr = <optimized out>
#15 0x00007f249d0c614d in krb5_db_get_principal (kcontext=kcontext@entry=0x557e66f63e40, search_for=<optimized out>, flags=flags@entry=80, entry=entry@entry=0x557e67078e18) at /usr/src/debug/krb5-1.21.3/src/lib/kdb/kdb5.c:804
        status = 0
        v = <optimized out>
#16 0x0000557e6524ad10 in lookup_client (entry_out=0x557e67078e18, flags=80, req=0x557e67086c50, context=0x557e66f63e40) at /usr/src/debug/krb5-1.21.3/src/kdc/do_as_req.c:149
        pa = <optimized out>
        cert = {magic = 0, length = 0, data = 0x7f2498c68b42 <ev_io_stop+130> "HcE(\307E"}
        pa = <optimized out>
        cert = <optimized out>
#17 process_as_req (respond=0x557e65241aa0 <finish_dispatch_cache>, arg=<optimized out>, vctx=0x557e66f1aff0, realm=0x557e66ecbaa0, remote_addr=0x557e66ecef70, local_addr=<optimized out>, req_pkt=0x557e67084f10, request=<optimized out>) at /usr/src/debug/krb5-1.21.3/src/kdc/do_as_req.c:577
        context = 0x557e66f63e40
        encoded_req_body = {magic = 1293900720, length = 147, data = 0x557e66f71853 "0\201\220\240\a\003\005"}
        state = 0x557e67078cc0
        au_state = 0x557e67077260
        errcode = <optimized out>
        useenctype = <optimized out>
        context = <optimized out>
        errcode = <optimized out>
        encoded_req_body = <optimized out>
        useenctype = <optimized out>
        state = <optimized out>
        au_state = <optimized out>
        errout = <optimized out>
#18 dispatch (cb=<optimized out>, local_addr=<optimized out>, remote_addr=0x557e66ecef70, pkt=0x557e67084f10, is_tcp=<optimized out>, vctx=0x557e66f1aff0, respond=0x557e65250eb0 <process_tcp_response>, arg=0x557e67084e60) at /usr/src/debug/krb5-1.21.3/src/kdc/dispatch.c:168
        retval = <optimized out>
        req = 0x557e67086c50
        response = 0x0
        state = <optimized out>
        handle = <optimized out>
        kdc_err_context = <optimized out>
#19 0x0000557e6525126c in process_tcp_connection_read (ctx=0x557e66f1aff0, ev=0x557e66f187c0) at ../lib/apputils/net-server.c:1362
        local_saddrlen = 16
        state = 0x557e67084e60
        conn = 0x557e66ecee80
        nread = <optimized out>
        len = 194
#20 0x00007f249cf86398 in verto_fire (ev=0x557e66f187c0) at /usr/src/debug/libverto-0.3.2/src/verto.c:1020
        priv = <optimized out>
        __PRETTY_FUNCTION__ = "verto_fire"
#21 0x00007f2498c675b6 in ev_invoke_pending () from /lib64/libev.so.4
No symbol table info available.
#22 0x00007f2498c6b16c in ev_run () from /lib64/libev.so.4
No symbol table info available.
#23 0x0000557e65240d3e in main (argc=5, argv=0x7fff4d1f6148) at /usr/src/debug/krb5-1.21.3/src/kdc/main.c:1039
        retval = 0
        kcontext = 0x557e66ecaff0
        realm = <optimized out>
        ctx = 0x557e66f1aff0
        tcp_listen_backlog = 5
        errout = 0
        i = <optimized out>

krb5kdc logs:

Dec 05 04:54:45 master1.ipa.test krb5kdc[2583](info): closing down fd 11
Dec 05 04:56:30 master1.ipa.test krb5kdc[2584](Warning): MS-PAC generator: Failed to fetch SID of POSIX group mapped as local fallback primary group
Dec 05 04:56:31 master1.ipa.test krb5kdc[2581](Error): worker 2584 exited with status 134
Dec 05 04:56:31 master1.ipa.test krb5kdc[2583](info): AS_REQ (8 etypes {aes256-cts-hmac-sha1-96(18), aes128-cts-hmac-sha1-96(17), aes256-cts-hmac-sha384-192(20), aes128-cts-hmac-sha256-128(19), camellia128-cts-cmac(25), camellia256-cts-cmac(26), DEPRECATED:des3-cbc-sha1(16), DEPRECATED:arcfour-hmac(23)}) 172.18.0.2: LOOKING_UP_CLIENT: host/master1.ipa.test@IPA.TEST for krbtgt/IPA.TEST@IPA.TEST, Server error
Dec 05 04:56:31 master1.ipa.test krb5kdc[2583](info): shutting down
Dec 05 04:56:31 master1.ipa.test krb5kdc[2583](info): IPA certauth plugin un-loaded.

syslog:

Dec 05 04:56:30 master1.ipa.test ns-slapd[3933]: [05/Dec/2024:04:56:30.950775720 +0000] - INFO - bdb_pre_close - All database threads now stopped
Dec 05 04:56:30 master1.ipa.test ns-slapd[3933]: [05/Dec/2024:04:56:30.977663364 +0000] - INFO - ldbm_back_instance_set_destructor - Set of instances destroyed
Dec 05 04:56:30 master1.ipa.test ns-slapd[3933]: [05/Dec/2024:04:56:30.978870333 +0000] - INFO - connection_post_shutdown_cleanup - slapd shutting down - freed 2 work q stack objects - freed 3 op stack objects
Dec 05 04:56:30 master1.ipa.test ns-slapd[3933]: [05/Dec/2024:04:56:30.979526971 +0000] - INFO - main - slapd stopped.
Dec 05 04:56:31 master1.ipa.test systemd[1]: dirsrv@IPA-TEST.service: Deactivated successfully.
Dec 05 04:56:31 master1.ipa.test systemd[1]: Stopped dirsrv@IPA-TEST.service - 389 Directory Server IPA-TEST..
Dec 05 04:56:31 master1.ipa.test systemd[1]: Starting dirsrv@IPA-TEST.service - 389 Directory Server IPA-TEST....
Dec 05 04:56:31 master1.ipa.test krb5kdc[2583]: closing down fd 10
Dec 05 04:56:31 master1.ipa.test certmonger[3975]: Error obtaining initial credentials: Generic error (see e-text).
Dec 05 04:56:31 master1.ipa.test certmonger[3975]: Error setting up ccache at the client: Generic error (see e-text).
Dec 05 04:56:31 master1.ipa.test krb5kdc[2583]: closing down fd 9
Dec 05 04:56:31 master1.ipa.test krb5kdc[2583]: closing down fd 8
Dec 05 04:56:31 master1.ipa.test krb5kdc[2583]: closing down fd 7
Dec 05 04:56:31 master1.ipa.test systemd[1]: krb5kdc.service: Deactivated successfully.

Considering the crash happens on retry (ldap server down):
https://pagure.io/freeipa/blob/master/f/daemons/ipa-kdb/ipa_kdb_common.c#_252

    /* first test if we need to retry to connect */
    if (ret != 0 &&
        ipadb_need_retry(ipactx, ret)) {
        ldap_msgfree(*res);
        ret = ldap_search_ext_s(ipactx->lcontext, basedn, scope,

ipadb_need_retry returns true but somehow sets ipactx->lcontext to NULL. This can happen if the underlying ipadb_get_connection succeeds. It in turn, ignores possible
negative result of ipadb_reinit_mspac and only warns on log. But there is no actual check for possible nulled ipactx->lcontext after.
https://pagure.io/freeipa/blob/master/f/daemons/ipa-kdb/ipa_kdb.c#_533

    ret = ipadb_reinit_mspac(ipactx, false, &stmsg);
    if (ret && stmsg)
        krb5_klog_syslog(LOG_WARNING, "MS-PAC generator: %s", stmsg);
    ret = 0;
Metadata
None
None
None
None
None
Static archive. pagure.io was sunset in 2026; this is a read-only snapshot.
Red Hat Logo

Fedora is sponsored by Red Hat. Learn more about the relationship between Red Hat and Fedora »

© Red Hat, Inc. and others.