Skip to content

Instantly share code, notes, and snippets.

@hyc

hyc/ITS#9112.txt

Created October 29, 2019 05:29
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save hyc/0d3d656fe792400c0cd7855d8f6cfe63 to your computer and use it in GitHub Desktop.
Save hyc/0d3d656fe792400c0cd7855d8f6cfe63 to your computer and use it in GitHub Desktop.
Download ZIP
Stack trace and log snippet for identifying bug in ITS#9112
Raw
ITS#9112.txt
The backtrace for this clearly shows that the GSSAPI library is closing a socket that doesn't belong to it.
Thread 1 (Thread 0x7fc11edfe700 (LWP 54101)):
#0 0x00007fc65e1c7207 in raise () from /lib64/libc.so.6
No symbol table info available.
#1 0x00007fc65e1c88f8 in abort () from /lib64/libc.so.6
No symbol table info available.
#2 0x00007fc65e1c0026 in __assert_fail_base () from /lib64/libc.so.6
No symbol table info available.
#3 0x00007fc65e1c00d2 in __assert_fail () from /lib64/libc.so.6
No symbol table info available.
#4 0x0000000000432099 in close (s=309) at /home/build/git/sold/sold-2448/openldap/servers/slapd/daemon.c:859
__PRETTY_FUNCTION__ = "close"
#5 0x00007fc65d703985 in connect_unix (s=0x7fc11417a530) at /home/build/git/sold/sold-2448/heimdal/lib/ipc/client.c:336
addr = {sun_family = 1,
sun_path = "/var/run/.heim_org.h5l.kcm-socket\000\000\000\000\000\004\000\000\000\000\000\000\000`\320\337\036\301\177\000\000\360\071p]\306\177\000\000\004\000\000\000\000\000\000\000\230\337*\024\301\177\000\000\364\004q]\306\177\000\000\332xp]\306\177\000\000\020\000\000\000\000\000\000\000\060\245\027\024\301\177"}
#6 0x00007fc65d703a5e in unix_socket_init (service=0x7fc65d7078da "org.h5l.kcm", ctx=0x7fc1142adf98)
at /home/build/git/sold/sold-2448/heimdal/lib/ipc/client.c:373
ret = 0
#7 0x00007fc65d703dae in heim_ipc_init_context (name=0x7fc65d7078d6 "ANY:org.h5l.kcm", ctx=0x7fc65d9262a8 <kcm_ipc>)
at /home/build/git/sold/sold-2448/heimdal/lib/ipc/client.c:528
prefix_len = 3
c = 0x7fc1142adf90
i = 0
ret = 32705
any = 1
#8 0x00007fc65d6d3392 in kcm_send_request (context=0x7fc1141e0390, request=0x7fc11414c2f0, response_data=0x7fc11edfd160)
at /home/build/git/sold/sold-2448/heimdal/lib/krb5/kcm.c:78
ret = 0
request_data = {length = 18, data = 0x7fc11414c2f0}
#9 0x00007fc65d6d363b in krb5_kcm_call (context=0x7fc1141e0390, request=0x7fc11414c2f0, response_p=0x7fc11edfd1c0,
response_data_p=0x7fc11edfd1b0) at /home/build/git/sold/sold-2448/heimdal/lib/krb5/kcm.c:183
response_data = {length = 0, data = 0x0}
ret = 0
status = 32705
response = 0x7fc11414c2f0
#10 0x00007fc65d6d42dc in kcm_get_cache_first (context=0x7fc1141e0390, cursor=0x7fc11437ef78)
at /home/build/git/sold/sold-2448/heimdal/lib/krb5/kcm.c:795
ret = 0
c = 0x7fc1141242e0
request = 0x7fc11414c2f0
response = 0x0
response_data = {length = 16, data = 0x7fc1143a6090}
#11 0x00007fc65d6ab99b in krb5_cc_cache_get_first (context=0x7fc1141e0390, type=0x7fc65d707935 "KCM", cursor=0x7fc1142da248)
at /home/build/git/sold/sold-2448/heimdal/lib/krb5/cache.c:1145
ops = 0x7fc65d920420 <krb5_kcm_ops>
ret = -1765328191
#12 0x00007fc65d6ac207 in krb5_cccol_cursor_next (context=0x7fc1141e0390, cursor=0x7fc1142da240, cache=0x7fc11edfd2c0)
at /home/build/git/sold/sold-2448/heimdal/lib/krb5/cache.c:1532
ret = -1765328191
#13 0x00007fc65d6abbad in krb5_cc_cache_match (context=0x7fc1141e0390, client=0x7fc114162f70, id=0x7fc11437dbb8)
at /home/build/git/sold/sold-2448/heimdal/lib/krb5/cache.c:1227
cursor = 0x7fc1142da240
ret = 2
cache = 0x0
expired_match = 0x0
#14 0x00007fc65d95c28e in get_ccache (context=0x7fc1141e0390, destroy=0x7fc11437dbd0, id=0x7fc11437dbb8)
at /home/build/git/sold/sold-2448/heimdal/lib/gssapi/ntlm/kdc.c:87
principal = 0x7fc114162f70
ret = 0
kt = 0x0
#15 0x00007fc65d95c588 in kdc_alloc (minor=0x7fc11edfd77c, ctx=0x7fc114378498)
at /home/build/git/sold/sold-2448/heimdal/lib/gssapi/ntlm/kdc.c:176
ret = 0
c = 0x7fc11437dba0
junk = 0
#16 0x00007fc65d958a45 in _gss_ntlm_allocate_ctx (minor_status=0x7fc11edfd77c, ctx=0x7fc11edfd490)
at /home/build/git/sold/sold-2448/heimdal/lib/gssapi/ntlm/accept_sec_context.c:56
maj_stat = 32705
ns_interface = 0x7fc65db720a0 <ntlmsspi_kdc_digest>
#17 0x00007fc65d9591ef in _gss_ntlm_acquire_cred (min_stat=0x7fc11edfd77c, desired_name=0x7fc114118f60, time_req=4294967295,
desired_mechs=0x7fc11edfd510, cred_usage=2, output_cred_handle=0x7fc114003108, actual_mechs=0x0, time_rec=0x7fc11edfd50c)
at /home/build/git/sold/sold-2448/heimdal/lib/gssapi/ntlm/acquire_cred.c:60
name = 0x7fc114118f60
domain = 0x0
maj_stat = 32710
ctx = 0x7fc114378490
#18 0x00007fc65d94d662 in gss_acquire_cred (minor_status=0x7fc11edfd77c, desired_name=0x7fc114132fc0, time_req=4294967295,
desired_mechs=0x7fc11edfd5c0, cred_usage=2, output_cred_handle=0x7fc11435e658, actual_mechs=0x0, time_rec=0x7fc11edfd65c)
at /home/build/git/sold/sold-2448/heimdal/lib/gssapi/mech/gss_acquire_cred.c:125
mn = 0x7fc11439eda0
major_status = 0
mechs = 0x7fc11edfd5c0
set = {count = 1, elements = 0x7fc11439e890}
name = 0x7fc114132fc0
m = 0x7fc12c139b88
cred = 0x7fc1141f7440
mc = 0x7fc1140030f0
min_time = 4294967295
cred_time = 4294967295
i = 0
#19 0x00007fc65d960078 in _gss_spnego_acquire_cred (minor_status=0x7fc11edfd77c, desired_name=0x7fc114297c80, time_req=4294967295,
desired_mechs=0x7fc11edfd660, cred_usage=2, output_cred_handle=0x7fc11435e658, actual_mechs=0x0, time_rec=0x7fc11edfd65c)
at /home/build/git/sold/sold-2448/heimdal/lib/gssapi/spnego/cred_stubs.c:109
dname = 0x7fc114297c80
name = 0x7fc114132fc0
ret = 0
tmp = 0
actual_desired_mechs = {count = 2, elements = 0x7fc11439e890}
mechs = 0x7fc11415e4a0
i = 3
j = 2
#20 0x00007fc65d94d662 in gss_acquire_cred (minor_status=0x7fc11edfd77c, desired_name=0x7fc114261bc0, time_req=4294967295,
desired_mechs=0x0, cred_usage=2, output_cred_handle=0x7fc11414d320, actual_mechs=0x0, time_rec=0x0)
at /home/build/git/sold/sold-2448/heimdal/lib/gssapi/mech/gss_acquire_cred.c:125
mn = 0x7fc114336210
major_status = 0
mechs = 0x7fc12c12de00
set = {count = 1, elements = 0x7fc12c19ea30}
name = 0x7fc114261bc0
m = 0x7fc12c184348
cred = 0x7fc11421f8e0
mc = 0x7fc11435e640
min_time = 4294967295
cred_time = 0
i = 1
#21 0x00007fc65db75d95 in gssapi_server_mech_authneg (text=0x7fc11414d2f0, params=0x7fc100442ad0, clientin=0x7fc11423f0fb "`\202",
clientinlen=109, serverout=0x7fc11edfd978, serveroutlen=0x7fc11edfd96c, oparams=0x7fc10039b950)
at /home/build/git/sold/sold-2448/cyrus-sasl/plugins/gssapi.c:721
input_token = 0x7fc11edfd790
output_token = 0x7fc11edfd780
real_input_token = {length = 0, value = 0x0}
real_output_token = {length = 0, value = 0x0}
maj_stat = 0
min_stat = 0
name_token = {length = 30, value = 0x0}
ret = 32705
equal = 0
out_flags = 0
server_creds = 0x0
name_without_realm = {length = 140467240960032, value = 0x1}
client_name_MN = 0x0
without = 0x0
mech_type = 0x16
__PRETTY_FUNCTION__ = "gssapi_server_mech_authneg"
#22 0x00007fc65db76e73 in gssapi_server_mech_step (conn_context=0x7fc11414d2f0, params=0x7fc100442ad0, clientin=0x7fc11423f0fb "`\202",
clientinlen=109, serverout=0x7fc11edfd978, serveroutlen=0x7fc11edfd96c, oparams=0x7fc10039b950)
at /home/build/git/sold/sold-2448/cyrus-sasl/plugins/gssapi.c:1266
text = 0x7fc11414d2f0
ret = 32705
#23 0x00007fc65f9ec635 in sasl_server_step (conn=0x7fc10039b0e0, clientin=0x7fc11423f0fb "`\202", clientinlen=109,
serverout=0x7fc11edfd978, serveroutlen=0x7fc11edfd96c) at /home/build/git/sold/sold-2448/cyrus-sasl/lib/server.c:1618
ret = 32705
s_conn = 0x7fc10039b0e0
#24 0x00007fc65f9ec3cb in sasl_server_start (conn=0x7fc10039b0e0, mech=0x7fc11423f180 "GSS-SPNEGO", clientin=0x7fc11423f0fb "`\202",
clientinlen=109, serverout=0x7fc11edfd978, serveroutlen=0x7fc11edfd96c) at /home/build/git/sold/sold-2448/cyrus-sasl/lib/server.c:1533
s_conn = 0x7fc10039b0e0
result = 0
cur = 0x0
prev = 0x7fc10039c2c8
m = 0x14e97a0
mech_len = 10
plus = 0
#25 0x00000000004ab5f8 in slap_sasl_bind (op=0x7fc1201ae900, rs=0x7fc11edfda80)
at /home/build/git/sold/sold-2448/openldap/servers/slapd/sasl.c:1524
ctx = 0x7fc10039b0e0
response = {bv_len = 140467423402384, bv_val = 0x0}
reslen = 0
sc = 32710
#26 0x00000000004641b0 in fe_op_bind (op=0x7fc1201ae900, rs=0x7fc11edfda80)
at /home/build/git/sold/sold-2448/openldap/servers/slapd/bind.c:280
bd = 0x76aac0 <slap_frontendDB>
#27 0x0000000000463d55 in do_bind (op=0x7fc1201ae900, rs=0x7fc11edfda80)
at /home/build/git/sold/sold-2448/openldap/servers/slapd/bind.c:205
ber = 0x7fc114333a60
version = 3
method = 163
mech = {bv_len = 10, bv_val = 0x7fc11423f0ef "GSS-SPNEGO"}
dn = {bv_len = 0, bv_val = 0x7fc11423f0eb ""}
tag = 0
be = 0x0
#28 0x000000000043b8fb in connection_operation (ctx=0x7fc11edfdbb0, arg_v=0x7fc1201ae900)
at /home/build/git/sold/sold-2448/openldap/servers/slapd/connection.c:1167
rc = 80
cancel = 32710
op = 0x7fc1201ae900
rs = {sr_type = REP_RESULT, sr_tag = 0, sr_msgid = 0, sr_err = 0, sr_matched = 0x0, sr_text = 0x0, sr_ref = 0x0, sr_ctrls = 0x0,
sr_un = {sru_search = {r_entry = 0x0, r_attr_flags = 0, r_operational_attrs = 0x0, r_attrs = 0x0, r_nentries = 0,
r_v2ref = 0x0}, sru_sasl = {r_sasldata = 0x0}, sru_extended = {r_rspoid = 0x0, r_rspdata = 0x0}}, sr_flags = 0}
tag = 96
opidx = SLAP_OP_BIND
conn = 0x7fc65a629fc8
memctx = 0x7fc1140125f0
memctx_null = 0x0
memsiz = 1048576
__PRETTY_FUNCTION__ = "connection_operation"
#29 0x000000000043bee3 in connection_read_thread (ctx=0x7fc11edfdbb0, argv=0x153)
at /home/build/git/sold/sold-2448/openldap/servers/slapd/connection.c:1314
rc = 0
cri = {op = 0x7fc1201ae900, func = 0x0, arg = 0x0, ctx = 0x7fc11edfdbb0, nullop = 0}
s = 339
#30 0x00007fc65fe1b735 in ldap_int_thread_pool_wrapper (xpool=0x14e1340)
at /home/build/git/sold/sold-2448/openldap/libraries/libldap_r/tpool.c:963
pq = 0x14e1340
pool = 0x14e1230
task = 0x7fc154002420
work_list = 0x14e13b0
ctx = {ltu_pq = 0x14e1340, ltu_id = 140467423405824, ltu_key = {{ltk_key = 0x43b18f <conn_counter_init>,
ltk_data = 0x7fc114013e70, ltk_free = 0x43afe1 <conn_counter_destroy>}, {ltk_key = 0x4af0cf <slap_sl_mem_init>,
ltk_data = 0x7fc1140125f0, ltk_free = 0x4aeee8 <slap_sl_mem_destroy>}, {ltk_key = 0x16d4340, ltk_data = 0x7fc114113f90,
ltk_free = 0x7fc65b18a197 <mdb_reader_free>}, {ltk_key = 0x7fc65b17e45b <search_stack>, ltk_data = 0x7fc11d0fc010,
ltk_free = 0x7fc65b17e438 <search_stack_free>}, {ltk_key = 0x7fc65b17ae9e <scope_chunk_get>, ltk_data = 0x7fc11e2fd010,
ltk_free = 0x7fc65b17ae56 <scope_chunk_free>}, {ltk_key = 0x45656a <slap_op_free>, ltk_data = 0x7fc114292e70,
ltk_free = 0x4564bd <slap_op_q_destroy>}, {ltk_key = 0x0, ltk_data = 0x7fc10c11e160, ltk_free = 0x0}, {ltk_key = 0x0,
ltk_data = 0x0, ltk_free = 0x0} <repeats 25 times>}}
kctx = 0x0
i = 32
keyslot = 36
hash = 3908644
pool_lock = 0
freeme = 0
__PRETTY_FUNCTION__ = "ldap_int_thread_pool_wrapper"
#31 0x00007fc65e565dd5 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#32 0x00007fc65e28fb3d in clone () from /lib64/libc.so.6
No symbol table info available.
We can see in the slapd log that it closed fd 309 which belonged to an active slapd connection.
5db6fb6a daemon: accept() = 309
5db6fb6a daemon: listen=7, new connection on 309
5db6fb6a daemon: added 309r (active) listener=(nil)
5db6fb6a conn=142919 fd=309 ACCEPT from IP=10.10.35.216:58648 (IP=0.0.0.0:389)
...
5db6fb6b daemon: activity on: 149rdaemon: close(309)
5db6fb6b
slapd: /home/build/git/sold/sold-2448/openldap/servers/slapd/daemon.c:859: close: Assertion `newconns[s] == 2' failed.
/opt/symas/etc/solserver: line 351: 54060 Aborted (core dumped) "$EXEC_DIR/$PROC" $ARGS -h "$HOST_LIST" $EXTRA_SLAPD_ARGS
[FAILED]
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment