35667 2018-11-29 10:08:26 +0300 FreeIPA installation fails 2018-11-29 13:21:50 +0300 1 1 4 Development Sisyphus libkrb5 unstable all Linux CLOSED FIXED P3 major --- 1 slev iv iv shaba qa-sisyphus oldest_to_newest 176165 0 slev 2018-11-29 10:08:26 +0300 Symptom: 389-ds crashes on FreeIPA installation: ``` Done configuring DNS key synchronization service (ipa-dnskeysyncd). Restarting ipa-dnskeysyncd Restarting named Named service failed to start (CalledProcessError(Command ['/sbin/systemctl', 'restart', 'bind.service'] returned non-zero exit status 1: 'Job for bind.service failed because the control process exited with error code.\nSee "systemctl status bind.service" and "journalctl -xe" for details.\n')) named service failed to start ``` Name debug log: ``` 29-Nov-2018 09:50:34.015 trying to establish LDAP connection to ldapi://%2fvar%2frun%2fslapd-IPASL-IPATEST.socket 29-Nov-2018 09:50:34.015 Using default keytab file name: FILE:/etc/named.keytab 29-Nov-2018 09:50:34.015 Credentials are not present in cache (Matching credential not found) 29-Nov-2018 09:50:34.015 Attempting to acquire new Kerberos credentials Missing separate debuginfo for /usr/lib64/krb5/plugins/libkrb5/sssd_krb5_locator_plugin.so Try to install the hash file /usr/lib/debug/.build-id/70/8f27e90579e8a1bb44d9ada32e82f61438f694.debug 29-Nov-2018 09:50:34.047 trying interactive bind using 'GSSAPI' mechanism 29-Nov-2018 09:50:34.047 doing interactive bind 29-Nov-2018 09:50:34.047 got request for SASL_CB_USER k5_mutex_lock: Received error 22 (Invalid argument) named: ../../../include/k5-thread.h:376: k5_mutex_lock: Assertion `r == 0' failed. Thread 2 "isc-worker0000" received signal SIGABRT, Aborted. [Switching to Thread 0x7ffff4e53700 (LWP 14531)] __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51 ``` bt ``` #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51 #1 0x00007ffff60ae371 in __GI_abort () at abort.c:79 #2 0x00007ffff60a5b1a in __assert_fail_base ( fmt=0x7ffff61f8e88 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x7ffff1429da5 "r == 0", file=file@entry=0x7ffff1429d88 "../../../include/k5-thread.h", line=line@entry=376, function=function@entry=0x7ffff1429e70 <__PRETTY_FUNCTION__.5551> "k5_mutex_lock") at assert.c:92 #3 0x00007ffff60a5b92 in __GI___assert_fail ( assertion=assertion@entry=0x7ffff1429da5 "r == 0", file=file@entry=0x7ffff1429d88 "../../../include/k5-thread.h", line=line@entry=376, function=function@entry=0x7ffff1429e70 <__PRETTY_FUNCTION__.5551> "k5_mutex_lock") at assert.c:101 #4 0x00007ffff13cd143 in k5_mutex_lock (m=0x7fffec36e358) at ../../../include/k5-thread.h:376 #5 0x00007ffff13d386f in k5_mutex_lock (m=0x7fffec36e358) at /usr/include/bits/stdio2.h:97 #6 k5_cc_mutex_lock (context=context@entry=0x7fffec3715c0, m=m@entry=0x7fffec36e358) at ccbase.c:460 #7 0x00007ffff13db5d8 in krb5_mcc_close (context=0x7fffec3715c0, id=<optimized out>) at cc_memory.c:212 #8 0x00007ffff13d647b in realm_choose (context=0x7fffec3715c0, data=<optimized out>, server=0x7fffec371370, cache_out=0x7ffff4e503e0, princ_out=0x7ffff4e503f8) at ccselect_realm.c:69 #9 0x00007ffff13d579e in krb5_cc_select (context=context@entry=0x7fffec3715c0, server=0x7fffec371370, cache_out=cache_out@entry=0x7fffec371a78, princ_out=princ_out@entry=0x7ffff4e50448) at ccselect.c:171 #10 0x00007fffea3e7edb in kg_cred_resolve (minor_status=minor_status@entry=0x7ffff4e508d8, context=0x7fffec3715c0, cred_handle=cred_handle@entry=0x7fffec371a20, target_name=target_name@entry=0x7fffec371570) at acquire_cred.c:959 #11 0x00007fffea3ef945 in krb5_gss_init_sec_context_ext ( minor_status=minor_status@entry=0x7ffff4e508d8, claimant_cred_handle=0x7fffec371a20, claimant_cred_handle@entry=0x0, context_handle=context_handle@entry=0x7fffec36f630, target_name=0x7fffec371570, mech_type=0x7fffea60e5c0 <krb5_gss_oid_array>, req_flags=req_flags@entry=58, time_req=0, input_chan_bindings=0x0, input_token=0x0, actual_mech_type=0x0, output_token=0x7ffff4e508f0, ret_flags=0x7ffff4e508dc, time_rec=0x0, exts=0x7ffff4e50790) at init_sec_context.c:976 #12 0x00007fffea3f0b42 in krb5_gss_init_sec_context ( minor_status=minor_status@entry=0x7ffff4e508d8, claimant_cred_handle=claimant_cred_handle@entry=0x0, context_handle=context_handle@entry=0x7fffec36f630, target_name=<optimized out>, mech_type=<optimized out>, req_flags=req_flags@entry=58, time_req=0, input_chan_bindings=0x0, input_token=0x0, actual_mech_type=0x0, output_token=0x7ffff4e508f0, ret_flags=0x7ffff4e508dc, time_rec=0x0) at init_sec_context.c:1089 #13 0x00007fffea3dbfc8 in gss_init_sec_context (minor_status=0x7ffff4e508d8, claimant_cred_handle=<optimized out>, context_handle=0x7fffec36c2a8, target_name=0x7fffec370090, req_mech_type=<optimized out>, req_flags=58, time_req=0, input_chan_bindings=0x0, input_token=0x0, actual_mech_type=0x0, output_token=0x7ffff4e508f0, ret_flags=0x7ffff4e508dc, time_rec=0x0) at g_init_sec_context.c:215 --Type <RET> for more, q to quit, c to continue without paging-- #14 0x00007fffe9d88c83 in ?? () from /usr/lib64/sasl2-3/libgssapiv2.so #15 0x00007ffff04e04fd in sasl_client_step (conn=conn@entry=0x7fffec376b90, serverin=serverin@entry=0x0, serverinlen=serverinlen@entry=0, prompt_need=prompt_need@entry=0x7ffff4e50aa0, clientout=clientout@entry=0x7ffff4e50ab8, clientoutlen=clientoutlen@entry=0x7ffff4e50a90) at client.c:922 #16 0x00007ffff04e0686 in sasl_client_start (conn=conn@entry=0x7fffec376b90, mechlist=mechlist@entry=0x7ffff7fcb2d8 "GSSAPI", prompt_need=prompt_need@entry=0x7ffff4e50aa0, clientout=clientout@entry=0x7ffff4e50ab8, clientoutlen=clientoutlen@entry=0x7ffff4e50a90, mech=mech@entry=0x7ffff4e50a98) at client.c:868 #17 0x00007ffff1171ab7 in ldap_int_sasl_bind (ld=ld@entry=0x7fffec36dc20, dn=dn@entry=0x0, mechs=mechs@entry=0x7ffff7fcb2d8 "GSSAPI", sctrls=sctrls@entry=0x0, cctrls=cctrls@entry=0x0, flags=2, interact=0x7ffff189de20 <ldap_sasl_interact>, defaults=0x7ffff7fbe448, result=0x0, rmech=0x7ffff4e50c60, msgid=0x7ffff4e50c5c) at cyrus.c:501 #18 0x00007ffff1174f0b in ldap_sasl_interactive_bind (ld=ld@entry=0x7fffec36dc20, dn=dn@entry=0x0, mechs=mechs@entry=0x7ffff7fcb2d8 "GSSAPI", serverControls=serverControls@entry=0x0, clientControls=clientControls@entry=0x0, flags=flags@entry=2, interact=0x7ffff189de20 <ldap_sasl_interact>, defaults=0x7ffff7fbe448, result=0x0, rmech=0x7ffff4e50c60, msgid=0x7ffff4e50c5c) at sasl.c:487 #19 0x00007ffff11750ab in ldap_sasl_interactive_bind_s (ld=0x7fffec36dc20, dn=dn@entry=0x0, mechs=0x7ffff7fcb2d8 "GSSAPI", serverControls=serverControls@entry=0x0, clientControls=clientControls@entry=0x0, flags=flags@entry=2, interact=0x7ffff189de20 <ldap_sasl_interact>, defaults=0x7ffff7fbe448) at sasl.c:521 #20 0x00007ffff189b13b in ldap_reconnect (force=isc_boolean_false, ldap_conn=0x7ffff7fa4640, ldap_inst=0x7ffff7fbe448) at ldap_helper.c:2894 #21 ldap_connect (ldap_inst=ldap_inst@entry=0x7ffff7fbe448, ldap_conn=ldap_conn@entry=0x7ffff7fa4640, force=force@entry=isc_boolean_false) at ldap_helper.c:2794 #22 0x00007ffff18a6336 in ldap_pool_connect (ldap_inst=0x7ffff7fbe448, pool=0x7ffff7fc5358) at ldap_helper.c:3664 #23 new_ldap_instance (mctx=mctx@entry=0x6bf6d0, db_name=db_name@entry=0x7ffff7fba1c8 "ipa", parameters=parameters@entry=0x7ffff7fbe298 "\n\turi \"ldapi://%2fvar%2frun%2fslapd-IPASL-IPATEST.socket\";\n\tbase \"cn=dns, dc=ipasl,dc=ipatest\";\n\tserver_id \"dcsl.ipasl.ipatest\";\n\tauth_method \"sasl\";\n\tsasl_mech \"GSSAPI\";\n\tsasl_user \"DNS/dcsl.ipasl.ip"..., file=file@entry=0x7ffff7fcb1e0 "/etc/named.conf", line=line@entry=59, dctx=dctx@entry=0x7ffff7fa4448, ldap_instp=<optimized out>) at ldap_helper.c:661 #24 0x00007ffff18989ac in dyndb_init (mctx=0x6bf6d0, name=0x7ffff7fba1c8 "ipa", parameters=0x7ffff7fbe298 "\n\turi \"ldapi://%2fvar%2frun%2fslapd-IPASL-IPATEST.socket\";\n\tbase \"cn=dns, dc=ipasl,dc=ipatest\";\n\tserver_id \"dcsl.ipasl.ipatest\";\n\tauth_method \"sasl\";\n\tsasl_mech \"GSSAPI\";\n\tsasl_user \"DNS/dcsl.ipasl.ip"..., file=0x7ffff7fcb1e0 "/etc/named.conf", line=59, dctx=0x7ffff7fa4448, instp=0x7ffff7fd63f8) at ldap_driver.c:1075 #25 0x00007ffff78120f2 in dns_dyndb_load ( libname=libname@entry=0x7ffff7fa67c0 "/usr/lib64/bind/ldap.so", name=name@entry=0x7ffff7fba1c8 "ipa", parameters=0x7ffff7fbe298 "\n\turi \"ldapi://%2fvar%2frun%2fslapd-IPASL-IPATEST.socket\";\n\tbase \"cn=dns, dc=ipasl,dc=ipatest\";\n\tserver_id \"dcsl.ipasl.ipatest\";\n\tauth_method \"s--Type <RET> for more, q to quit, c to continue without paging-- asl\";\n\tsasl_mech \"GSSAPI\";\n\tsasl_user \"DNS/dcsl.ipasl.ip"..., file=file@entry=0x7ffff7fcb1e0 "/etc/named.conf", line=line@entry=59, mctx=mctx@entry=0x6bf6d0, dctx=0x7ffff7fa4448) at dyndb.c:372 #26 0x000000000042234f in configure_dyndb (dctx=0x7ffff7fa4448, mctx=0x6bf6d0, dyndb=<optimized out>) at ./server.c:1490 #27 configure_view (view=0x7fffec128cf0, viewlist=viewlist@entry=0x7ffff4e529c0, config=0x7ffff7fd87e0, vconfig=vconfig@entry=0x0, cachelist=cachelist@entry=0x7ffff4e529e0, bindkeys=0x7ffff7fde588, mctx=0x6bf6d0, actx=0x7ffff7fa7090, need_hints=<optimized out>) at ./server.c:4741 #28 0x00000000004624be in load_configuration (filename=<optimized out>, server=server@entry=0x7ffff7fb1010, first_time=first_time@entry=isc_boolean_true) at ./server.c:7994 #29 0x00000000004638e3 in run_server (task=<optimized out>, event=<optimized out>) at ./server.c:8734 #30 0x00007ffff6ca0e79 in dispatch (manager=0x7ffff7fa9010) at task.c:1141 #31 run (uap=0x7ffff7fa9010) at task.c:1313 #32 0x00007ffff643959a in start_thread (arg=0x7ffff4e53700) at pthread_create.c:463 #33 0x00007ffff616efaf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95 ``` Versions: freeipa-server-4.7.1-alt3.x86_64 bind-9.11.4.P2-alt1.x86_64 libkrb5-1.16.2-alt1.x86_64 The issue happens on libkrb5-1.16.2, after applying https://github.com/krb5/krb5/commit/6d784809fe07c2d5f60c1a692bcac08b0d40f0a7. Ivan Melnikov(ALTLinux maintainer of krb5) suggests to check https://github.com/krb5/krb5/commit/49bb627fed70c5258c151c5135ac3d95ed1ee55d. 176166 1 slev 2018-11-29 10:12:50 +0300 There is a typo: 389-ds crashes => named (bind-dyndb-ldap plugin) crashes. Let me check the suggestion against this issue and https://bugzilla.altlinux.org/show_bug.cgi?id=35597 one. 176168 2 slev 2018-11-29 12:12:56 +0300 There is a typo: 389-ds crashes => named (bind-dyndb-ldap plugin) crashes. Let me check the suggestion against this issue and https://bugzilla.altlinux.org/show_bug.cgi?id=35597 one.(В ответ на комментарий №1) > There is a typo: 389-ds crashes => named (bind-dyndb-ldap plugin) crashes. > > Let me check the suggestion against this issue and > https://bugzilla.altlinux.org/show_bug.cgi?id=35597 one. I confirm the bug 35597 on libkrb5-1.16.2-alt1. But both issues are gone away with @49bb627fed. I pushed a task #216877. Please review. 176169 3 iv 2018-11-29 12:29:37 +0300 > But both issues are gone away with @49bb627fed. > I pushed a task #216877. Awesome! And thank you for the great work. I've approved the subtask 200. 176170 4 repository-robot 2018-11-29 13:21:50 +0300 krb5-1.16.2-alt2 -> sisyphus: Thu Nov 29 2018 Stanislav Levin <slev@altlinux> 1.16.2-alt2 - Fixed yield of cache from MEMORY ccache (closes #35597, #35667). Wed Aug 29 2018 Alexey Shabalin <shaba@altlinux> 1.16.1-alt2 - rebuild with openssl-1.1 Mon Aug 27 2018 Ivan A. Melnikov <iv@altlinux> 1.16.1-alt1 - 1.16.1 (CVE-2018-5729, CVE-2018-5730) Mon Jan 22 2018 Evgeny Sinelnikov <sin@altlinux> 1.16-alt1 - Update to latest stable release 1.16 Fri Nov 03 2017 Evgeny Sinelnikov <sin@altlinux> 1.15.2-alt2 - Fix build-pdf on Sisyphus - Add noport, nss_wrapper and socket_wrapper for tests running Wed Nov 01 2017 Evgeny Sinelnikov <sin@altlinux> 1.15.2-alt1 - Update to latest stable release 1.15.2 with kdcpreauth from 1.16.x Sun Aug 20 2017 Evgeny Sinelnikov <sin@altlinux.ru> 1.15.1-alt1 - Update to latest stable release 1.15.1 with kdcpreauth from 1.16.x Fri Mar 24 2017 Evgeny Sinelnikov <sin@altlinux.ru> 1.14.5-alt1 - Update to first spring release 1.14.5 Tue Feb 28 2017 Evgeny Sinelnikov <sin@altlinux.ru> 1.14.4-alt2 - Add _keytab group for default keytab /etc/krb5.keytab Wed Feb 15 2017 Evgeny Sinelnikov <sin@altlinux.ru> 1.14.4-alt1 - 1.14.4 - fixed CVE-2016-3120