Bug#929473: sssd-kcm: talloc_abort call via schedule_fd_processing

2019-05-31 Thread Bernhard Übelacker
Dear Maintainer,
I just tried to reproduce this crash and may have
found some more information.

It looks like this memory got freed already at
this location [1].

Then on the second free attempt the talloc
recognises this and aborts [2].

Could not find a related upstream bug report in [3].

It does not always crash so it looks timing related.

Attached file shows some details on my attempt to
reproduce this issue.

Kind regards,
Bernhard


[1]
(rr) bt
#0  _talloc_free (ptr=0x5622b5453df0, location=0x7f8594c8e15d 
"../tevent_timed.c:391") at ../talloc.c:1743
#1  0x7f8594c8ace1 in tevent_common_invoke_timer_handler 
(te=te@entry=0x5622b5453df0, current_time=..., removed=removed@entry=0x0) at 
../tevent_timed.c:391
#2  0x7f8594c8adea in tevent_common_loop_timer_delay 
(ev=ev@entry=0x5622b5431920) at ../tevent_timed.c:441
#3  0x7f8594c8be67 in epoll_event_loop_once (ev=0x5622b5431920, 
location=) at ../tevent_epoll.c:922
#4  0x7f8594c8a2d7 in std_event_loop_once (ev=0x5622b5431920, 
location=0x7f85948c9178 "../src/util/server.c:725") at ../tevent_standard.c:110
#5  0x7f8594c857e4 in _tevent_loop_once (ev=ev@entry=0x5622b5431920, 
location=location@entry=0x7f85948c9178 "../src/util/server.c:725") at 
../tevent.c:772
#6  0x7f8594c85a2b in tevent_common_loop_wait (ev=0x5622b5431920, 
location=0x7f85948c9178 "../src/util/server.c:725") at ../tevent.c:895
#7  0x7f8594c8a277 in std_event_loop_wait (ev=0x5622b5431920, 
location=0x7f85948c9178 "../src/util/server.c:725") at ../tevent_standard.c:141
#8  0x7f85948a48e3 in server_loop (main_ctx=0x5622b5432df0) at 
../src/util/server.c:725
#9  0x5622b38e4c70 in main (argc=, argv=) at 
../src/responder/kcm/kcm.c:318
(rr) when
Current event: 12824


[2]
(rr) bt
#0  _talloc_free (ptr=0x5622b5453df0, location=0x5622b391d27a 
"../src/util/tev_curl.c:449") at ../talloc.c:1743
#1  0x5622b38f98fb in schedule_fd_processing (multi=, 
timeout_ms=0, userp=) at ../src/util/tev_curl.c:449
#2  0x7f8594cd88cc in update_timer (multi=multi@entry=0x5622b5440a50) at 
multi.c:2941
#3  0x7f8594cd9f76 in curl_multi_add_handle (data=0x5622b6871250, 
multi=0x5622b5440a50) at multi.c:500
#4  curl_multi_add_handle (multi=0x5622b5440a50, data=0x5622b6871250) at 
multi.c:376
#5  0x5622b38f9fa9 in tcurl_request_send 
(mem_ctx=mem_ctx@entry=0x5622b544e740, ev=ev@entry=0x5622b5431920, 
tcurl_ctx=tcurl_ctx@entry=0x5622b543c0f0, 
tcurl_req=tcurl_req@entry=0x5622b686b890, timeout=timeout@entry=5) at 
../src/util/tev_curl.c:700
#6  0x5622b38faa98 in tcurl_http_send (mem_ctx=0x5622b544e740, 
ev=ev@entry=0x5622b5431920, tcurl_ctx=0x5622b543c0f0, 
method=method@entry=TCURL_HTTP_GET, 
socket_path=socket_path@entry=0x5622b39154a3 "/var/run/secrets.socket", 
url=, headers=0x5622b39379b0 , body=0x0, timeout=5) 
at ../src/util/tev_curl.c:1017
#7  0x5622b38ef659 in sec_list_send (mem_ctx=, 
ev=ev@entry=0x5622b5431920, client=client@entry=0x5622b686a4e0, 
secdb=) at ../src/responder/kcm/kcmsrv_ccache_secrets.c:163
#8  0x5622b38efc4e in sec_get_ccache_send (mem_ctx=, 
ev=ev@entry=0x5622b5431920, secdb=secdb@entry=0x5622b54409d0, 
client=client@entry=0x5622b686a4e0, name=name@entry=0x5622b543cea0 "0", 
uuid=uuid@entry=0x7ffdbedbd470 "") at 
../src/responder/kcm/kcmsrv_ccache_secrets.c:482
#9  0x5622b38f016d in ccdb_sec_getbyname_send (mem_ctx=, 
ev=0x5622b5431920, db=, client=0x5622b686a4e0, 
name=0x5622b543cea0 "0") at ../src/responder/kcm/kcmsrv_ccache_secrets.c:1275
#10 0x5622b38e7e39 in kcm_ccdb_getbyname_send (mem_ctx=, 
ev=ev@entry=0x5622b5431920, db=0x5622b543d630, client=0x5622b686a4e0, 
name=0x5622b543cea0 "0") at ../src/responder/kcm/kcmsrv_ccache.c:692
#11 0x5622b38f18d7 in kcm_op_get_kdc_offset_send (mem_ctx=, 
ev=0x5622b5431920, op_ctx=0x5622b544de60) at 
../src/responder/kcm/kcmsrv_ops.c:1731
#12 0x5622b38f09f3 in kcm_cmd_queue_done (subreq=0x0) at 
../src/responder/kcm/kcmsrv_ops.c:196
#13 0x7f8594c86479 in tevent_common_invoke_immediate_handler 
(im=0x5622b5430520, removed=removed@entry=0x0) at ../tevent_immediate.c:165
#14 0x7f8594c864a3 in tevent_common_loop_immediate 
(ev=ev@entry=0x5622b5431920) at ../tevent_immediate.c:202
#15 0x7f8594c8be5b in epoll_event_loop_once (ev=0x5622b5431920, 
location=) at ../tevent_epoll.c:917
#16 0x7f8594c8a2d7 in std_event_loop_once (ev=0x5622b5431920, 
location=0x7f85948c9178 "../src/util/server.c:725") at ../tevent_standard.c:110
#17 0x7f8594c857e4 in _tevent_loop_once (ev=ev@entry=0x5622b5431920, 
location=location@entry=0x7f85948c9178 "../src/util/server.c:725") at 
../tevent.c:772
#18 0x7f8594c85a2b in tevent_common_loop_wait (ev=0x5622b5431920, 
location=0x7f85948c9178 "../src/util/server.c:725") at ../tevent.c:895
#19 0x7f8594c8a277 in std_event_loop_wait (ev=0x5622b5431920, 
location=0x7f85948c9178 "../src/util/server.c:725") at ../tevent_standard.c:141
#20 0x7f85948a48e3 in server_loop (main_ctx=0x5622b5432df0) at 
../src/util/server.c:725
#21 

Bug#929473: sssd-kcm: talloc_abort call via schedule_fd_processing

2019-05-24 Thread Sam Morris
Package: sssd-kcm
Version: 1.16.3-3.1
Severity: important

-BEGIN PGP SIGNED MESSAGE-
Hash: SHA256

Having installed sssd-kcm and setting default_ccache_name = KCM: in
krb5.conf, after running kinit and klist a few times I started getting
the following crash:

#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x7f7ce3493535 in __GI_abort () at abort.c:79
#2  0x7f7ce3a8b621 in talloc_abort (reason=0x7f7ce3a99070 "Bad talloc magic 
value - unknown value")
at ../talloc.c:500
#3  0x7f7ce3a8b591 in talloc_abort_unknown_value () at ../talloc.c:529
#4  talloc_chunk_from_ptr (ptr=0x55db7c89de20) at ../talloc.c:529
#5  _talloc_free (ptr=0x55db7c89de20, location=0x55db7b05b27a 
"../src/util/tev_curl.c:449") at ../talloc.c:1747
#6  0x55db7b0378fb in schedule_fd_processing (multi=, 
timeout_ms=0, userp=)
at ../src/util/tev_curl.c:449
#7  0x7f7ce3af78cc in update_timer (multi=multi@entry=0x55db7c89d4a0) at 
multi.c:2941
#8  0x7f7ce3af8f76 in curl_multi_add_handle (data=0x55db7dcc6b80, 
multi=0x55db7c89d4a0) at multi.c:500
#9  curl_multi_add_handle (multi=0x55db7c89d4a0, data=0x55db7dcc6b80) at 
multi.c:376
#10 0x55db7b037fa9 in tcurl_request_send 
(mem_ctx=mem_ctx@entry=0x55db7c8aade0, ev=ev@entry=0x55db7c839830,
tcurl_ctx=tcurl_ctx@entry=0x55db7c89d480, 
tcurl_req=tcurl_req@entry=0x55db7dcc91d0, timeout=timeout@entry=5)
at ../src/util/tev_curl.c:700
#11 0x55db7b038a98 in tcurl_http_send (mem_ctx=0x55db7c8aade0, 
ev=ev@entry=0x55db7c839830,
tcurl_ctx=0x55db7c89d480, method=method@entry=TCURL_HTTP_GET,
socket_path=socket_path@entry=0x55db7b0534a3 "/var/run/secrets.socket", 
url=,
headers=0x55db7b0759b0 , body=0x0, timeout=5) at 
../src/util/tev_curl.c:1017
#12 0x55db7b02d659 in sec_list_send (mem_ctx=, 
ev=ev@entry=0x55db7c839830,
client=client@entry=0x55db7c89a7d0, secdb=) at 
../src/responder/kcm/kcmsrv_ccache_secrets.c:163
#13 0x55db7b02dc4e in sec_get_ccache_send (mem_ctx=, 
ev=ev@entry=0x55db7c839830,
secdb=secdb@entry=0x55db7c89a440, client=client@entry=0x55db7c89a7d0, 
name=name@entry=0x55db7c89d300 "1000",
uuid=uuid@entry=0x7fff37adda30 "") at 
../src/responder/kcm/kcmsrv_ccache_secrets.c:482
#14 0x55db7b02e16d in ccdb_sec_getbyname_send (mem_ctx=, 
ev=0x55db7c839830, db=,
client=0x55db7c89a7d0, name=0x55db7c89d300 "1000") at 
../src/responder/kcm/kcmsrv_ccache_secrets.c:1275
#15 0x55db7b025e39 in kcm_ccdb_getbyname_send (mem_ctx=, 
ev=ev@entry=0x55db7c839830,
db=0x55db7c89a220, client=0x55db7c89a7d0, name=0x55db7c89d300 "1000")
at ../src/responder/kcm/kcmsrv_ccache.c:692
#16 0x55db7b02fa6e in kcm_op_get_cred_by_uuid_send (mem_ctx=, ev=0x55db7c839830,
op_ctx=0x55db7dcc9110) at ../src/responder/kcm/kcmsrv_ops.c:1099
#17 0x55db7b02e9f3 in kcm_cmd_queue_done (subreq=0x0) at 
../src/responder/kcm/kcmsrv_ops.c:196
#18 0x7f7ce3aa7479 in tevent_common_invoke_immediate_handler 
(im=0x55db7c838460, removed=removed@entry=0x0)
at ../tevent_immediate.c:165
#19 0x7f7ce3aa74a3 in tevent_common_loop_immediate 
(ev=ev@entry=0x55db7c839830) at ../tevent_immediate.c:202
#20 0x7f7ce3aace5b in epoll_event_loop_once (ev=0x55db7c839830, 
location=)
at ../tevent_epoll.c:917
#21 0x7f7ce3aab2d7 in std_event_loop_once (ev=0x55db7c839830,
location=0x7f7ce36e8178 "../src/util/server.c:725") at 
../tevent_standard.c:110
#22 0x7f7ce3aa67e4 in _tevent_loop_once (ev=ev@entry=0x55db7c839830,
location=location@entry=0x7f7ce36e8178 "../src/util/server.c:725") at 
../tevent.c:772
#23 0x7f7ce3aa6a2b in tevent_common_loop_wait (ev=0x55db7c839830,
location=0x7f7ce36e8178 "../src/util/server.c:725") at ../tevent.c:895
#24 0x7f7ce3aab277 in std_event_loop_wait (ev=0x55db7c839830,
location=0x7f7ce36e8178 "../src/util/server.c:725") at 
../tevent_standard.c:141
#25 0x7f7ce36c38e3 in server_loop () from 
/usr/lib/x86_64-linux-gnu/sssd/libsss_util.so
#26 0x55db7b022c70 in main (argc=, argv=) at 
../src/responder/kcm/kcm.c:318

In sssd_kcm.log we have only the following message:

(Fri May 24 09:13:18 2019) [sssd[kcm]] [talloc_log_fn] (0x0010): Bad talloc 
magic value - unknown value

... putting debug_level=9 in the [kcm] section of sssd.conf doesn't
cause any more detailed messages to be logged.

- -- System Information:
Debian Release: 10.0
  APT prefers testing-debug
  APT policy: (550, 'testing-debug'), (550, 'testing'), (520, 
'unstable-debug'), (520, 'unstable'), (510, 'experimental-debug'), (510, 
'experimental')
Architecture: amd64 (x86_64)
Foreign Architectures: arm64

Kernel: Linux 4.19.0-5-amd64 (SMP w/2 CPU cores)
Kernel taint flags: TAINT_OOT_MODULE, TAINT_UNSIGNED_MODULE
Locale: LANG=en_GB.UTF-8, LC_CTYPE=en_GB.UTF-8 (charmap=UTF-8), 
LANGUAGE=en_GB.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled

Versions of packages sssd-kcm depends on:
ii  libc62.28-10