Bug#918088: Acknowledgement (autofs-ldap: automount dies with SIGABRT after libkrb5-3 upgrade - "(k5_mutex_lock: Assertion `r == 0' failed.)")
Control: reassign -1 libkrb5-3 1.16.2-1
Control: affects -1 autofs-ldap
> After the latest upgrade of libkrb5-3 (1.16.1-1 -> 1.16.2-1) automount
> starts but dies immediately after accessing a automounter point.
>
> Automount is configured to authenticate via GSSAPI using system keytab.
> After the GSSAPI authentication succeeded, any access to a configure
> automount entry causes automount to die with an assertion failure
> (followed by an abort()):
Thanks for your report.
I'm moving this bug report to libkrb5-3 since this is the change that
triggered your regression for assessment whether the bug is there.
On Thu, Jan 03, 2019 at 04:29:24PM +0100, Andreas Maus wrote:
> Maybe the backtrace with libkrb5-dbg installed may provider more clues:
>
> root@dagon:~# gdb /usr/sbin/automount /core
> GNU gdb (Debian 8.2-1) 8.2
> Copyright (C) 2018 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-linux-gnu".
> Type "show configuration" for configuration details.
> For bug reporting instructions, please see:
> <http://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/automount...(no debugging symbols found)...done.
> [New LWP 9037]
> [New LWP 9011]
> [New LWP 9012]
> [New LWP 9013]
> [New LWP 9016]
> [Thread debugging using libthread_db enabled]
> Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
> Core was generated by `/usr/sbin/automount -d -f'.
> Program terminated with signal SIGABRT, Aborted.
> #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
> 50 ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
> [Current thread is 1 (Thread 0x7f8753fff700 (LWP 9037))]
> (gdb) bt
> #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
> #1 0x00007f875be80535 in __GI_abort () at abort.c:79
> #2 0x00007f875be8040f in __assert_fail_base (fmt=0x7f875bfe2ee8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x7f8758f04029 "r == 0", file=0x7f8758f03f58 "../../../../src/include/k5-thread.h", line=376, function=<optimized out>) at assert.c:92
> #3 0x00007f875be8e0a2 in __GI___assert_fail (assertion=assertion@entry=0x7f8758f04029 "r == 0", file=file@entry=0x7f8758f03f58 "../../../../src/include/k5-thread.h", line=line@entry=376, function=function@entry=0x7f8758f04040 <__PRETTY_FUNCTION__.5585> "k5_mutex_lock") at assert.c:101
> #4 0x00007f8758ea8ea3 in k5_mutex_lock (m=0x7f8754040498) at ../../../../src/include/k5-thread.h:376
> #5 0x00007f8758ea9677 in k5_mutex_lock (m=0x7f8754040498) at ../../../../src/include/k5-thread.h:376
> #6 k5_cc_mutex_lock (context=context@entry=0x7f874c014ed0, m=m@entry=0x7f8754040498) at ../../../../src/lib/krb5/ccache/ccbase.c:460
> #7 0x00007f8758eb1776 in krb5_mcc_start_seq_get (context=0x7f874c014ed0, id=<optimized out>, cursor=0x7f8753ff7e48) at ../../../../src/lib/krb5/ccache/cc_memory.c:357
> #8 0x00007f8758eaa2bd in has_content (cache=0x7f874c00b910, context=0x7f874c014ed0) at ../../../../src/lib/krb5/ccache/cccursor.c:278
> #9 krb5_cccol_have_content (context=context@entry=0x7f874c014ed0) at ../../../../src/lib/krb5/ccache/cccursor.c:278
> #10 0x00007f8758c6eb63 in acquire_init_cred (cred=0x7f874c0150d0, client_keytab=0x0, password=0x0, req_ccache=0x0, minor_status=0x7f8753ff85a4, context=0x7f874c014ed0) at ../../../../src/lib/gssapi/krb5/acquire_cred.c:735
> #11 acquire_cred_context (context=0x7f874c014ed0, minor_status=minor_status@entry=0x7f8753ff85a4, desired_name=desired_name@entry=0x0, password=password@entry=0x0, cred_usage=cred_usage@entry=1, ccache=ccache@entry=0x0, client_keytab=0x0, keytab=0x0, rcname=0x0, iakerb=0, output_cred_handle=0x7f8753ff8178, time_rec=0x0, time_req=4294967295) at ../../../../src/lib/gssapi/krb5/acquire_cred.c:827
> #12 0x00007f8758c6ee18 in acquire_cred (minor_status=minor_status@entry=0x7f8753ff85a4, desired_name=desired_name@entry=0x0, password=password@entry=0x0, cred_usage=cred_usage@entry=1, ccache=ccache@entry=0x0, keytab=keytab@entry=0x0, iakerb=0, output_cred_handle=0x7f8753ff8178, time_rec=0x0, time_req=4294967295) at ../../../../src/lib/gssapi/krb5/acquire_cred.c:920
> #13 0x00007f8758c6ef4c in krb5_gss_acquire_cred (minor_status=minor_status@entry=0x7f8753ff85a4, desired_name=desired_name@entry=0x0, time_req=time_req@entry=4294967295, desired_mechs=desired_mechs@entry=0x0, cred_usage=cred_usage@entry=1, output_cred_handle=output_cred_handle@entry=0x7f8753ff8178, actual_mechs=0x0, time_rec=0x0) at ../../../../src/lib/gssapi/krb5/acquire_cred.c:1079
> #14 0x00007f8758c71d9f in kg_get_defcred (minor_status=minor_status@entry=0x7f8753ff85a4, cred=cred@entry=0x7f8753ff8178) at ../../../../src/lib/gssapi/krb5/gssapi_krb5.c:202
> #15 0x00007f8758c76a08 in krb5_gss_init_sec_context_ext (minor_status=minor_status@entry=0x7f8753ff85a4, claimant_cred_handle=claimant_cred_handle@entry=0x0, context_handle=context_handle@entry=0x7f874c01b490, target_name=0x7f874c01c550, mech_type=0x7f8758c975a0 <krb5_gss_oid_array>, req_flags=req_flags@entry=10, time_req=0, input_chan_bindings=0x0, input_token=0x0, actual_mech_type=0x0, output_token=0x7f8753ff85c0,
> ret_flags=0x7f8753ff85a8, time_rec=0x0, exts=0x7f8753ff8420) at ../../../../src/lib/gssapi/krb5/init_sec_context.c:967
> #16 0x00007f8758c77702 in krb5_gss_init_sec_context (minor_status=minor_status@entry=0x7f8753ff85a4, claimant_cred_handle=claimant_cred_handle@entry=0x0, context_handle=context_handle@entry=0x7f874c01b490, target_name=<optimized out>, mech_type=<optimized out>, req_flags=req_flags@entry=10, time_req=0, input_chan_bindings=0x0, input_token=0x0, actual_mech_type=0x0, output_token=0x7f8753ff85c0,
> ret_flags=0x7f8753ff85a8, time_rec=0x0) at ../../../../src/lib/gssapi/krb5/init_sec_context.c:1089
> #17 0x00007f8758c6222b in gss_init_sec_context (minor_status=0x7f8753ff85a4, claimant_cred_handle=<optimized out>, context_handle=0x7f874c019558, target_name=0x7f874c00b840, req_mech_type=<optimized out>, req_flags=10, time_req=0, input_chan_bindings=0x0, input_token=0x0, actual_mech_type=0x0, output_token=0x7f8753ff85c0, ret_flags=0x7f8753ff85a8, time_rec=0x0)
> at ../../../../src/lib/gssapi/mechglue/g_init_sec_context.c:215
> #18 0x00007f875812e637 in ?? () from /usr/lib/x86_64-linux-gnu/sasl2/libgssapiv2.so
> #19 0x00007f8758f6202d in sasl_client_step () from /usr/lib/x86_64-linux-gnu/libsasl2.so.2
> #20 0x00007f8758f62644 in sasl_client_start () from /usr/lib/x86_64-linux-gnu/libsasl2.so.2
> #21 0x00007f875900b6c4 in sasl_bind_mech () from /usr/lib/x86_64-linux-gnu/autofs/lookup_ldap.so
> #22 0x00007f875900ba73 in autofs_sasl_bind () from /usr/lib/x86_64-linux-gnu/autofs/lookup_ldap.so
> #23 0x00007f87590036cd in ?? () from /usr/lib/x86_64-linux-gnu/autofs/lookup_ldap.so
> #24 0x00007f87590041c6 in ?? () from /usr/lib/x86_64-linux-gnu/autofs/lookup_ldap.so
> #25 0x00007f8759007b40 in lookup_mount () from /usr/lib/x86_64-linux-gnu/autofs/lookup_ldap.so
> #26 0x000055692aab70ed in do_lookup_mount ()
> #27 0x000055692aab7e39 in lookup_nss_mount ()
> #28 0x000055692aaade25 in ?? ()
> #29 0x00007f875c1edfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
> #30 0x00007f875bf5788f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
> (gdb) bt full
> #0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
> set = {__val = {18446744067266836999, 140219072427984, 140219206565440, 140219339597447, 4222451712, 140219072427984, 140219072427984, 140219072427984, 140219072427984, 140219072428078, 140219072428084, 140219072427984, 140219072428084, 0, 0, 0}}
> pid = <optimized out>
> tid = <optimized out>
> ret = <optimized out>
> #1 0x00007f875be80535 in __GI_abort () at abort.c:79
> save_stage = 1
> act = {__sigaction_handler = {sa_handler = 0x7f874c00b7d0, sa_sigaction = 0x7f874c00b7d0}, sa_mask = {__val = {0, 140219072380960, 140219340656256, 0, 0, 0, 140219206565096, 21474836480, 140219206564944, 140219340712624, 140219340697320, 0, 7821802371936316416, 140219340682170, 0, 140219340697320}}, sa_flags = 1492139864, sa_restorer = 0x7f8758f04029}
> sigs = {__val = {32, 0 <repeats 15 times>}}
> #2 0x00007f875be8040f in __assert_fail_base (fmt=0x7f875bfe2ee8 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x7f8758f04029 "r == 0", file=0x7f8758f03f58 "../../../../src/include/k5-thread.h", line=376, function=<optimized out>) at assert.c:92
> str = 0x7f874c00b7d0 ""
> total = 4096
> #3 0x00007f875be8e0a2 in __GI___assert_fail (assertion=assertion@entry=0x7f8758f04029 "r == 0", file=file@entry=0x7f8758f03f58 "../../../../src/include/k5-thread.h", line=line@entry=376, function=function@entry=0x7f8758f04040 <__PRETTY_FUNCTION__.5585> "k5_mutex_lock") at assert.c:101
> No locals.
> #4 0x00007f8758ea8ea3 in k5_mutex_lock (m=0x7f8754040498) at ../../../../src/include/k5-thread.h:376
> r = <optimized out>
> __PRETTY_FUNCTION__ = "k5_mutex_lock"
> #5 0x00007f8758ea9677 in k5_mutex_lock (m=0x7f8754040498) at ../../../../src/include/k5-thread.h:376
> r = 22
> r = <optimized out>
> __PRETTY_FUNCTION__ = "k5_mutex_lock"
> #6 k5_cc_mutex_lock (context=context@entry=0x7f874c014ed0, m=m@entry=0x7f8754040498) at ../../../../src/lib/krb5/ccache/ccbase.c:460
> No locals.
> #7 0x00007f8758eb1776 in krb5_mcc_start_seq_get (context=0x7f874c014ed0, id=<optimized out>, cursor=0x7f8753ff7e48) at ../../../../src/lib/krb5/ccache/cc_memory.c:357
> mcursor = 0x7f874c01b4d0
> d = 0x7f8754040490
> #8 0x00007f8758eaa2bd in has_content (cache=0x7f874c00b910, context=0x7f874c014ed0) at ../../../../src/lib/krb5/ccache/cccursor.c:278
> ret = <optimized out>
> found = 0
> cache_cursor = 0x0
> creds = {magic = 0, client = 0x0, server = 0x0, keyblock = {magic = 0, enctype = 0, length = 1275154128, contents = 0x6c8c9fd0ca926c00 <error: Cannot access memory at address 0x6c8c9fd0ca926c00>}, times = {authtime = 1275154128, starttime = 32647, endtime = 0, renew_till = 0}, is_skey = 1, ticket_flags = 0, addresses = 0x0, ticket = {magic = 1275154640, length = 32647,
> data = 0x7f8758c6d66d <can_get_initial_creds+141> "\205\300\017\224\300\017\266\300\353\276\350$\256\376\377\017\037@"}, second_ticket = {magic = 0, length = 0, data = 0x7f874c0150d0 ""}, authdata = 0x7f8753ff85a4}
> ret = <optimized out>
> found = <optimized out>
> cache_cursor = <optimized out>
> creds = <optimized out>
> #9 krb5_cccol_have_content (context=context@entry=0x7f874c014ed0) at ../../../../src/lib/krb5/ccache/cccursor.c:278
> ret = 0
> col_cursor = 0x7f874c002750
> cache = 0x7f874c00b910
> found = 0
> errsave = {code = 0, msg = 0x0}
> defname = <optimized out>
> #10 0x00007f8758c6eb63 in acquire_init_cred (cred=0x7f874c0150d0, client_keytab=0x0, password=0x0, req_ccache=0x0, minor_status=0x7f8753ff85a4, context=0x7f874c014ed0) at ../../../../src/lib/gssapi/krb5/acquire_cred.c:735
> pwcopy = {magic = 0, length = 0, data = 0x0}
> caller_ccname = 0
> code = <optimized out>
> pwdata = {magic = 1492141261, length = 32647, data = 0x7f8758f0676e "err_fmt"}
> code = <optimized out>
> pwdata = <optimized out>
> pwcopy = <optimized out>
> caller_ccname = <optimized out>
> __PRETTY_FUNCTION__ = "acquire_init_cred"
> #11 acquire_cred_context (context=0x7f874c014ed0, minor_status=minor_status@entry=0x7f8753ff85a4, desired_name=desired_name@entry=0x0, password=password@entry=0x0, cred_usage=cred_usage@entry=1, ccache=ccache@entry=0x0, client_keytab=0x0, keytab=0x0, rcname=0x0, iakerb=0, output_cred_handle=0x7f8753ff8178, time_rec=0x0, time_req=4294967295) at ../../../../src/lib/gssapi/krb5/acquire_cred.c:827
> cred = <optimized out>
> name = 0x0
> ret = <optimized out>
> code = <optimized out>
> __PRETTY_FUNCTION__ = "acquire_cred_context"
> #12 0x00007f8758c6ee18 in acquire_cred (minor_status=minor_status@entry=0x7f8753ff85a4, desired_name=desired_name@entry=0x0, password=password@entry=0x0, cred_usage=cred_usage@entry=1, ccache=ccache@entry=0x0, keytab=keytab@entry=0x0, iakerb=0, output_cred_handle=0x7f8753ff8178, time_rec=0x0, time_req=4294967295) at ../../../../src/lib/gssapi/krb5/acquire_cred.c:920
> context = 0x7f874c014ed0
> code = <optimized out>
> ret = <optimized out>
> #13 0x00007f8758c6ef4c in krb5_gss_acquire_cred (minor_status=minor_status@entry=0x7f8753ff85a4, desired_name=desired_name@entry=0x0, time_req=time_req@entry=4294967295, desired_mechs=desired_mechs@entry=0x0, cred_usage=cred_usage@entry=1, output_cred_handle=output_cred_handle@entry=0x7f8753ff8178, actual_mechs=0x0, time_rec=0x0) at ../../../../src/lib/gssapi/krb5/acquire_cred.c:1079
> No locals.
> #14 0x00007f8758c71d9f in kg_get_defcred (minor_status=minor_status@entry=0x7f8753ff85a4, cred=cred@entry=0x7f8753ff8178) at ../../../../src/lib/gssapi/krb5/gssapi_krb5.c:202
> major = <optimized out>
> #15 0x00007f8758c76a08 in krb5_gss_init_sec_context_ext (minor_status=minor_status@entry=0x7f8753ff85a4, claimant_cred_handle=claimant_cred_handle@entry=0x0, context_handle=context_handle@entry=0x7f874c01b490, target_name=0x7f874c01c550, mech_type=0x7f8758c975a0 <krb5_gss_oid_array>, req_flags=req_flags@entry=10, time_req=0, input_chan_bindings=0x0, input_token=0x0, actual_mech_type=0x0, output_token=0x7f8753ff85c0,
> ret_flags=0x7f8753ff85a8, time_rec=0x0, exts=0x7f8753ff8420) at ../../../../src/lib/gssapi/krb5/init_sec_context.c:967
> context = 0x7f874c017fb0
> defcred = 0x0
> cred = <optimized out>
> kerr = <optimized out>
> major_status = 851968
> tmp_min_stat = 0
> #16 0x00007f8758c77702 in krb5_gss_init_sec_context (minor_status=minor_status@entry=0x7f8753ff85a4, claimant_cred_handle=claimant_cred_handle@entry=0x0, context_handle=context_handle@entry=0x7f874c01b490, target_name=<optimized out>, mech_type=<optimized out>, req_flags=req_flags@entry=10, time_req=0, input_chan_bindings=0x0, input_token=0x0, actual_mech_type=0x0, output_token=0x7f8753ff85c0,
> ret_flags=0x7f8753ff85a8, time_rec=0x0) at ../../../../src/lib/gssapi/krb5/init_sec_context.c:1089
> exts = {iakerb = {conv = 0x0, verified = 0}}
> #17 0x00007f8758c6222b in gss_init_sec_context (minor_status=0x7f8753ff85a4, claimant_cred_handle=<optimized out>, context_handle=0x7f874c019558, target_name=0x7f874c00b840, req_mech_type=<optimized out>, req_flags=10, time_req=0, input_chan_bindings=0x0, input_token=0x0, actual_mech_type=0x0, output_token=0x7f8753ff85c0, ret_flags=0x7f8753ff85a8, time_rec=0x0)
> at ../../../../src/lib/gssapi/mechglue/g_init_sec_context.c:215
> status = <optimized out>
> temp_minor_status = 0
> union_name = 0x7f874c00b840
> union_cred = <optimized out>
> internal_name = 0x7f874c01c550
> union_ctx_id = 0x7f874c01b480
> selected_mech = 0x7f875402a030
> mech = 0x7f875402a030
> input_cred_handle = 0x0
> #18 0x00007f875812e637 in ?? () from /usr/lib/x86_64-linux-gnu/sasl2/libgssapiv2.so
> No symbol table info available.
> #19 0x00007f8758f6202d in sasl_client_step () from /usr/lib/x86_64-linux-gnu/libsasl2.so.2
> No symbol table info available.
> #20 0x00007f8758f62644 in sasl_client_start () from /usr/lib/x86_64-linux-gnu/libsasl2.so.2
> No symbol table info available.
> #21 0x00007f875900b6c4 in sasl_bind_mech () from /usr/lib/x86_64-linux-gnu/autofs/lookup_ldap.so
> No symbol table info available.
> #22 0x00007f875900ba73 in autofs_sasl_bind () from /usr/lib/x86_64-linux-gnu/autofs/lookup_ldap.so
> No symbol table info available.
> #23 0x00007f87590036cd in ?? () from /usr/lib/x86_64-linux-gnu/autofs/lookup_ldap.so
> No symbol table info available.
> #24 0x00007f87590041c6 in ?? () from /usr/lib/x86_64-linux-gnu/autofs/lookup_ldap.so
> No symbol table info available.
> #25 0x00007f8759007b40 in lookup_mount () from /usr/lib/x86_64-linux-gnu/autofs/lookup_ldap.so
> No symbol table info available.
> #26 0x000055692aab70ed in do_lookup_mount ()
> No symbol table info available.
> #27 0x000055692aab7e39 in lookup_nss_mount ()
> No symbol table info available.
> #28 0x000055692aaade25 in ?? ()
> No symbol table info available.
> #29 0x00007f875c1edfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
> ret = <optimized out>
> pd = <optimized out>
> now = <optimized out>
> unwind_buf = {cancel_jmp_buf = {{jmp_buf = {140219206596352, 4725770880340707005, 140219299088510, 140219299088511, 140219206596352, 0, -4711917034381261123, -4711900256637958467}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
> not_first_call = <optimized out>
> #30 0x00007f875bf5788f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
> No locals.
>
> So long,
>
> Andreas.
Reply to: