[
https://issues.apache.org/jira/browse/DISPATCH-1989?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17298158#comment-17298158
]
Alex Ward edited comment on DISPATCH-1989 at 3/9/21, 5:00 PM:
--------------------------------------------------------------
Hi Clifford
I've attached a couple of log files for a test run exhibiting the asan use
after free.
* qdrouterd.txt - the qd_log logs with just an extra log enabled that dumps
all the proton events.
* mtrace.txt - some more detailed logging that is tracing the creation and
deletion of pconnections.
The asan event is for a read this time as I added a dump of the
loop->handle_cache before the previously failing QUEUE_REMOVE in
uv__finish_close.
Here's the last couple of closes, I can;t see anything obvious, although for
most of the connection closes I see the pattern of:
# uv_safe_close - for the connection handle
# uv_close
# uv__tcp_close
# uv__make_close_pending
# uv__run_closing_handles
# uv__finish_close - calls close_cb
# on_close_pconnection - needs to close timer before deleting connection
# uv_safe_close - for the timer handle
# uv_close
# uv__timer_close
# uv__make_close_pending
# uv__run_closing_handles
# on_close_pconnection_final - the callback was set to delete the connection
as we know timer is closed now
# pconnection_free - finally the pconnection is safe to be freed and this is
done
On the close of handle 0x61d0003e44c8 before the failure there is still a
reference to that handle on line 2745 in the handle_queue after QUEUE_REMOVE
was called, which seems weird. Is this suspect?
Oh and there is a PN_TRANSPORT_CLOSED event just before the failure, that seems
relevent.
Last few lines of the attached mtrace.txt here:
[2710] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void uv_safe_close(uv_handle_t
*, uv_close_cb) handle 0x61d0003e44c8 is_closing 0"
distro/c/src/proactor/libuv.c:440
[2711] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv_safe_close(uv_handle_t *, uv_close_cb) handle 0x61d0003e44c8 before
uv_close" distro/c/src/proactor/libuv.c:446
[2712] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void uv_close(uv_handle_t *,
uv_close_cb) handle 0x61d0003e44c8 type 12 data 0x61d0003e4480 is_closing 0
flags c008" ../../../../distro/src/unix/core.c:123
[2713] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void uv__tcp_close(uv_tcp_t
*) handle 0x61d0003e44c8" ../../../../distro/src/unix/tcp.c:469
[2714] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__make_close_pending(uv_handle_t *) handle 0x61d0003e44c8 data 0x61d0003e4480
current 0x0" ../../../../distro/src/unix/core.c:232
[2715] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__run_closing_handles(uv_loop_t *) loop 0x61a0000c4f88"
../../../../distro/src/unix/core.c:393
[2716] (2021-03-08 14:46:10) tid:0x61a0000ca880 "p 0x61d0003e44c8 conn
0x61d0003e4480" ../../../../distro/src/unix/core.c:394
[2717] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__finish_close(uv_handle_t *) handle 0x61d0003e44c8 data 0x61d0003e4480 flags
9 type 12" ../../../../distro/src/unix/core.c:303
[2718] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__finish_close(uv_handle_t *) before QUEUE_REMOVE handle_queue
0x61d0003e4c48,0x61d0003e5648" ../../../../distro/src/unix/core.c:367
[2719] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [--I] signal 0x61a0000c51b0
[0x61a0000c51d0,0x61a0000c51d8]" ../../../../distro/src/unix/core.c:293
[2720] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [-AI] async 0x61a0000c5018
[0x61a0000c5038,0x61a0000c5040]" ../../../../distro/src/unix/core.c:293
[2721] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] async 0x61a0000c4e80
[0x61a0000c4ea0,0x61a0000c4ea8]" ../../../../distro/src/unix/core.c:293
[2722] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] async 0x61a0000c4f00
[0x61a0000c4f20,0x61a0000c4f28]" ../../../../distro/src/unix/core.c:293
[2723] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] timer 0x61a0000c5250
[0x61a0000c5270,0x61a0000c5278]" ../../../../distro/src/unix/core.c:293
[2724] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] tcp 0x612000030350
[0x612000030370,0x612000030378]" ../../../../distro/src/unix/core.c:293
[2725] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [---] tcp 0x61d0003e44c8
[0x61d0003e44e8,0x61d0003e44f0]" ../../../../distro/src/unix/core.c:293
[2726] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [R--] timer 0x61d0003e4c28
[0x61d0003e4c48,0x61d0003e4c50]" ../../../../distro/src/unix/core.c:293
[2727] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__finish_close(uv_handle_t *) before close_cb 0x61d0003e44c8 3"
../../../../distro/src/unix/core.c:378
[2728] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
on_close_pconnection(uv_handle_t *) handle 0x61d0003e44c8 pc 0x61d0003e4480
timer due 0" distro/c/src/proactor/libuv.c:467
[2729] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
on_close_pconnection(uv_handle_t *) last timer now 626726 next 0 pc
0x61d0003e4e80 now 626728" distro/c/src/proactor/libuv.c:470
[2730] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv_safe_close(uv_handle_t *, uv_close_cb) handle 0x61d0003e4c28 is_closing 0"
distro/c/src/proactor/libuv.c:440
[2731] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv_safe_close(uv_handle_t *, uv_close_cb) handle 0x61d0003e4c28 before
uv_close" distro/c/src/proactor/libuv.c:446
[2732] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void uv_close(uv_handle_t *,
uv_close_cb) handle 0x61d0003e4c28 type 13 data 0x61d0003e4480 is_closing 0
flags 8" ../../../../distro/src/unix/core.c:123
[2733] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__timer_close(uv_timer_t *) handle 0x61d0003e4c28"
../../../../distro/src/timer.c:191
[2734] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__make_close_pending(uv_handle_t *) handle 0x61d0003e4c28 data 0x61d0003e4480
current 0x0" ../../../../distro/src/unix/core.c:232
[2735] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__run_closing_handles(uv_loop_t *) loop 0x61a0000c4f88"
../../../../distro/src/unix/core.c:393
[2736] (2021-03-08 14:46:10) tid:0x61a0000ca880 "p 0x61d0003e4c28 conn
0x61d0003e4480" ../../../../distro/src/unix/core.c:394
[2737] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__finish_close(uv_handle_t *) handle 0x61d0003e4c28 data 0x61d0003e4480 flags
9 type 13" ../../../../distro/src/unix/core.c:303
[2738] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__finish_close(uv_handle_t *) before QUEUE_REMOVE handle_queue
0x61a0000c4f98,0x61d0003e5648" ../../../../distro/src/unix/core.c:367
[2739] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [--I] signal 0x61a0000c51b0
[0x61a0000c51d0,0x61a0000c51d8]" ../../../../distro/src/unix/core.c:293
[2740] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [-AI] async 0x61a0000c5018
[0x61a0000c5038,0x61a0000c5040]" ../../../../distro/src/unix/core.c:293
[2741] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] async 0x61a0000c4e80
[0x61a0000c4ea0,0x61a0000c4ea8]" ../../../../distro/src/unix/core.c:293
[2742] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] async 0x61a0000c4f00
[0x61a0000c4f20,0x61a0000c4f28]" ../../../../distro/src/unix/core.c:293
[2743] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] timer 0x61a0000c5250
[0x61a0000c5270,0x61a0000c5278]" ../../../../distro/src/unix/core.c:293
[2744] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] tcp 0x612000030350
[0x612000030370,0x612000030378]" ../../../../distro/src/unix/core.c:293
[2745] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [---] tcp 0x61d0003e44c8
[0x61d0003e44e8,0x61d0003e44f0]" ../../../../distro/src/unix/core.c:293
[2746] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [---] timer 0x61d0003e4c28
[0x61d0003e4c48,0x61d0003e4c50]" ../../../../distro/src/unix/core.c:293
[2747] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__finish_close(uv_handle_t *) before close_cb 0x61d0003e4c28 3"
../../../../distro/src/unix/core.c:378
[2748] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
on_close_pconnection_final(uv_handle_t *) handle 0x61d0003e4c28 pc
0x61d0003e4480" distro/c/src/proactor/libuv.c:431
[2749] (2021-03-08 14:46:10) tid:0x61a0000ca880 "pconnection_free() pc
0x61d0003e4480" distro/c/src/proactor/libuv.c:364
[2750] (2021-03-08 14:46:10) tid:0x2d2310 <alloc_memory_for_dlsym> "_Bool
handle(qd_server_t *, pn_event_t *, pn_connection_t *, qd_connection_t *)
pn_conn 0x61200001ec50 ctx 0x61e0000cb510 event PN_TRANSPORT_CLOSED"
distro/src/server.c:982
[2751] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv_safe_close(uv_handle_t *, uv_close_cb) handle 0x61d0003e4ec8 is_closing 0"
distro/c/src/proactor/libuv.c:440
[2752] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv_safe_close(uv_handle_t *, uv_close_cb) handle 0x61d0003e4ec8 before
uv_close" distro/c/src/proactor/libuv.c:446
[2753] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void uv_close(uv_handle_t *,
uv_close_cb) handle 0x61d0003e4ec8 type 12 data 0x61d0003e4e80 is_closing 0
flags c008" ../../../../distro/src/unix/core.c:123
[2754] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void uv__tcp_close(uv_tcp_t
*) handle 0x61d0003e4ec8" ../../../../distro/src/unix/tcp.c:469
[2755] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__make_close_pending(uv_handle_t *) handle 0x61d0003e4ec8 data 0x61d0003e4e80
current 0x0" ../../../../distro/src/unix/core.c:232
[2756] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__run_closing_handles(uv_loop_t *) loop 0x61a0000c4f88"
../../../../distro/src/unix/core.c:393
[2757] (2021-03-08 14:46:10) tid:0x61a0000ca880 "p 0x61d0003e4ec8 conn
0x61d0003e4e80" ../../../../distro/src/unix/core.c:394
[2758] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__finish_close(uv_handle_t *) handle 0x61d0003e4ec8 data 0x61d0003e4e80 flags
9 type 12" ../../../../distro/src/unix/core.c:303
[2759] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__finish_close(uv_handle_t *) before QUEUE_REMOVE handle_queue
0x61d0003e5648,0x61d000410848" ../../../../distro/src/unix/core.c:367
[2760] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [--I] signal 0x61a0000c51b0
[0x61a0000c51d0,0x61a0000c51d8]" ../../../../distro/src/unix/core.c:293
[2761] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [-AI] async 0x61a0000c5018
[0x61a0000c5038,0x61a0000c5040]" ../../../../distro/src/unix/core.c:293
[2762] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] async 0x61a0000c4e80
[0x61a0000c4ea0,0x61a0000c4ea8]" ../../../../distro/src/unix/core.c:293
[2763] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] async 0x61a0000c4f00
[0x61a0000c4f20,0x61a0000c4f28]" ../../../../distro/src/unix/core.c:293
[2764] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] timer 0x61a0000c5250
[0x61a0000c5270,0x61a0000c5278]" ../../../../distro/src/unix/core.c:293
[2765] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] tcp 0x612000030350
[0x612000030370,0x612000030378]" ../../../../distro/src/unix/core.c:293
(ugdb-x86_64-7.11-261) exit
asan report:
==9350==ERROR: AddressSanitizer: heap-use-after-free on address 0x61d0003e44d8
at pc 0x0008006b5746 bp 0x000806005bf0 sp 0x000806005be8
{{[11|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#11]
READ of size 4 at 0x61d0003e44d8 thread
T6}}{{[12|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#12]
#0 0x8006b5745 in uv__trace_handles
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:276:16}}{{[13|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#13]
#1 0x8006b3d6e in uv__finish_close
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:369:3}}{{[14|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#14]
#2 0x8006af093 in uv__run_closing_handles
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:397:5}}{{[15|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#15]
#3 0x8006aeb03 in uv_run
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:467:5}}{{[16|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#16]
#4 0x800b52d85 in leader_lead_lh
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:1085:5}}{{[17|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#17]
#5 0x800b52f2c in pn_proactor_wait
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:1118:15}}{{[18|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#18]
#6 0x8005b6c90 in thread_run
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/server.c:1086:36}}{{[19|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#19]
#7 0x8005bfea2 in _thread_init
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/posix/threading.c:172:12}}{{[20|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#20]
#8 0x800ed01d4 in thread_start
/x/eng/bbrtp2/daemon/DOT/dev/daemon_base/bsd99/bedrock/private/x86_64/bsd_libthr/lib/libthr/../../../../../../src/lib/libthr/thread/thr_create.c:299:16}}{{[22|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#22]
0x61d0003e44d8 is located 88 bytes inside of 2408-byte region
[0x61d0003e4480,0x61d0003e4de8)}}{{[23|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#23]
freed by thread T6
here:}}{{[24|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#24]
#0 0x28d28d in free
/x/eng/bbrtp2/daemon/DOT/dev/daemon_base/third_party/open_source/llvm/distro/compiler-rt/lib/asan/asan_malloc_linux.cpp:123:3}}{{[25|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#25]
#1 0x800b57d8f in pconnection_free
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:373:3}}{{[26|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#26]
#2 0x800b579b4 in on_close_pconnection_final
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:433:3}}{{[27|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#27]
#3 0x8006b3e63 in uv__finish_close
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:379:5}}{{[28|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#28]
#4 0x8006af093 in uv__run_closing_handles
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:397:5}}{{[29|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#29]
#5 0x8006aeb03 in uv_run
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:467:5}}{{[30|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#30]
#6 0x800b52d85 in leader_lead_lh
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:1085:5}}{{[31|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#31]
#7 0x800b52f2c in pn_proactor_wait
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:1118:15}}{{[32|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#32]
#8 0x8005b6c90 in thread_run
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/server.c:1086:36}}{{[33|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#33]
#9 0x8005bfea2 in _thread_init
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/posix/threading.c:172:12}}{{[34|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#34]
#10 0x800ed01d4 in thread_start
/x/eng/bbrtp2/daemon/DOT/dev/daemon_base/bsd99/bedrock/private/x86_64/bsd_libthr/lib/libthr/../../../../../../src/lib/libthr/thread/thr_create.c:299:16}}{{}}{{[35|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#35]}}{{previously
allocated by thread T0
here:}}{{[37|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#37]
#0 0x28d572 in calloc
/x/eng/bbrtp2/daemon/DOT/dev/daemon_base/third_party/open_source/llvm/distro/compiler-rt/lib/asan/asan_malloc_linux.cpp:154:3}}{{[38|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#38]
#1 0x800b53a79 in pconnection
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:345:39}}{{[39|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#39]
#2 0x800b536b3 in pn_proactor_connect2
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:1214:23}}{{[40|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#40]
#3 0x800b63dbd in pn_proactor_connect
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/proactor-internal.c:97:3}}{{[41|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#41]
#4 0x8005b9c66 in try_open_lh
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/server.c:1204:5}}{{[42|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#42]
#5 0x8005b7aee in try_open_cb
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/server.c:1313:14}}{{[43|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#43]
#6 0x8005c11bd in qd_timer_visit
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/timer.c:201:9}}{{[44|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#44]
#7 0x8005b87ba in handle
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/server.c:998:9}}{{[45|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#45]
#8 0x8005b6d14 in thread_run
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/server.c:1101:23}}{{[46|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#46]
(distro/router/src/main.c:44)}}
was (Author: vorlauf):
Hi Clifford
I've attached a couple of log files for a test run exhibiting the asan use
after free.
* qdrouterd.txt - the qd_log logs with just an extra log enabled that dumps
all the proton events.
* mtrace.txt - some more detailed logging that is tracing the creation and
deletion of pconnections.
The asan event is for a read this time as I added a dump of the
loop->handle_cache before the previously failing QUEUE_REMOVE in
uv__finish_close.
Here's the last couple of closes, I can;t see anything obvious, although for
most of the connection closes I see the pattern of:
# uv_safe_close - for the connection handle
# uv_close
# uv__tcp_close
# uv__make_close_pending
# uv__run_closing_handles
# uv__finish_close - calls close_cb
# on_close_pconnection - needs to close timer before deleting connection
# uv_safe_close - for the timer handle
# uv_close
# uv__timer_close
# uv__make_close_pending
# uv__run_closing_handles
# on_close_pconnection_final - the callback was set to delete the connection
as we know timer is closed now
# pconnection_free - finally the pconnection is safe to be freed and this is
done
On the close of handle 0x61d0003e44c8 before the failure there is still a
reference to that handle on line 2745 in the handle_queue after QUEUE_REMOVE
was called, which seems weird. Is this suspect?
Oh and there is a PN_TRANSPORT_CLOSED event just before the failure, that seems
relevent.
Last few lines of the attached mtrace.txt here:
[2710] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void uv_safe_close(uv_handle_t
*, uv_close_cb) handle 0x61d0003e44c8 is_closing 0"
distro/c/src/proactor/libuv.c:440
[2711] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void uv_safe_close(uv_handle_t
*, uv_close_cb) handle 0x61d0003e44c8 before uv_close"
distro/c/src/proactor/libuv.c:446
[2712] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void uv_close(uv_handle_t *,
uv_close_cb) handle 0x61d0003e44c8 type 12 data 0x61d0003e4480 is_closing 0
flags c008" ../../../../distro/src/unix/core.c:123
[2713] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void uv__tcp_close(uv_tcp_t *)
handle 0x61d0003e44c8" ../../../../distro/src/unix/tcp.c:469
[2714] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__make_close_pending(uv_handle_t *) handle 0x61d0003e44c8 data 0x61d0003e4480
current 0x0" ../../../../distro/src/unix/core.c:232
[2715] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__run_closing_handles(uv_loop_t *) loop 0x61a0000c4f88"
../../../../distro/src/unix/core.c:393
[2716] (2021-03-08 14:46:10) tid:0x61a0000ca880 "p 0x61d0003e44c8 conn
0x61d0003e4480" ../../../../distro/src/unix/core.c:394
[2717] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__finish_close(uv_handle_t *) handle 0x61d0003e44c8 data 0x61d0003e4480 flags
9 type 12" ../../../../distro/src/unix/core.c:303
[2718] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__finish_close(uv_handle_t *) before QUEUE_REMOVE handle_queue
0x61d0003e4c48,0x61d0003e5648" ../../../../distro/src/unix/core.c:367
[2719] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [--I] signal 0x61a0000c51b0
[0x61a0000c51d0,0x61a0000c51d8]" ../../../../distro/src/unix/core.c:293
[2720] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [-AI] async 0x61a0000c5018
[0x61a0000c5038,0x61a0000c5040]" ../../../../distro/src/unix/core.c:293
[2721] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] async 0x61a0000c4e80
[0x61a0000c4ea0,0x61a0000c4ea8]" ../../../../distro/src/unix/core.c:293
[2722] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] async 0x61a0000c4f00
[0x61a0000c4f20,0x61a0000c4f28]" ../../../../distro/src/unix/core.c:293
[2723] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] timer 0x61a0000c5250
[0x61a0000c5270,0x61a0000c5278]" ../../../../distro/src/unix/core.c:293
[2724] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] tcp 0x612000030350
[0x612000030370,0x612000030378]" ../../../../distro/src/unix/core.c:293
[2725] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [---] tcp 0x61d0003e44c8
[0x61d0003e44e8,0x61d0003e44f0]" ../../../../distro/src/unix/core.c:293
[2726] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [R--] timer 0x61d0003e4c28
[0x61d0003e4c48,0x61d0003e4c50]" ../../../../distro/src/unix/core.c:293
[2727] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__finish_close(uv_handle_t *) before close_cb 0x61d0003e44c8 3"
../../../../distro/src/unix/core.c:378
[2728] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
on_close_pconnection(uv_handle_t *) handle 0x61d0003e44c8 pc 0x61d0003e4480
timer due 0" distro/c/src/proactor/libuv.c:467
[2729] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
on_close_pconnection(uv_handle_t *) last timer now 626726 next 0 pc
0x61d0003e4e80 now 626728" distro/c/src/proactor/libuv.c:470
[2730] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void uv_safe_close(uv_handle_t
*, uv_close_cb) handle 0x61d0003e4c28 is_closing 0"
distro/c/src/proactor/libuv.c:440
[2731] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void uv_safe_close(uv_handle_t
*, uv_close_cb) handle 0x61d0003e4c28 before uv_close"
distro/c/src/proactor/libuv.c:446
[2732] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void uv_close(uv_handle_t *,
uv_close_cb) handle 0x61d0003e4c28 type 13 data 0x61d0003e4480 is_closing 0
flags 8" ../../../../distro/src/unix/core.c:123
[2733] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__timer_close(uv_timer_t *) handle 0x61d0003e4c28"
../../../../distro/src/timer.c:191
[2734] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__make_close_pending(uv_handle_t *) handle 0x61d0003e4c28 data 0x61d0003e4480
current 0x0" ../../../../distro/src/unix/core.c:232
[2735] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__run_closing_handles(uv_loop_t *) loop 0x61a0000c4f88"
../../../../distro/src/unix/core.c:393
[2736] (2021-03-08 14:46:10) tid:0x61a0000ca880 "p 0x61d0003e4c28 conn
0x61d0003e4480" ../../../../distro/src/unix/core.c:394
[2737] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__finish_close(uv_handle_t *) handle 0x61d0003e4c28 data 0x61d0003e4480 flags
9 type 13" ../../../../distro/src/unix/core.c:303
[2738] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__finish_close(uv_handle_t *) before QUEUE_REMOVE handle_queue
0x61a0000c4f98,0x61d0003e5648" ../../../../distro/src/unix/core.c:367
[2739] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [--I] signal 0x61a0000c51b0
[0x61a0000c51d0,0x61a0000c51d8]" ../../../../distro/src/unix/core.c:293
[2740] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [-AI] async 0x61a0000c5018
[0x61a0000c5038,0x61a0000c5040]" ../../../../distro/src/unix/core.c:293
[2741] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] async 0x61a0000c4e80
[0x61a0000c4ea0,0x61a0000c4ea8]" ../../../../distro/src/unix/core.c:293
[2742] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] async 0x61a0000c4f00
[0x61a0000c4f20,0x61a0000c4f28]" ../../../../distro/src/unix/core.c:293
[2743] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] timer 0x61a0000c5250
[0x61a0000c5270,0x61a0000c5278]" ../../../../distro/src/unix/core.c:293
[2744] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] tcp 0x612000030350
[0x612000030370,0x612000030378]" ../../../../distro/src/unix/core.c:293
[2745] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [---] tcp 0x61d0003e44c8
[0x61d0003e44e8,0x61d0003e44f0]" ../../../../distro/src/unix/core.c:293
[2746] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [---] timer 0x61d0003e4c28
[0x61d0003e4c48,0x61d0003e4c50]" ../../../../distro/src/unix/core.c:293
[2747] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__finish_close(uv_handle_t *) before close_cb 0x61d0003e4c28 3"
../../../../distro/src/unix/core.c:378
[2748] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
on_close_pconnection_final(uv_handle_t *) handle 0x61d0003e4c28 pc
0x61d0003e4480" distro/c/src/proactor/libuv.c:431
[2749] (2021-03-08 14:46:10) tid:0x61a0000ca880 "pconnection_free() pc
0x61d0003e4480" distro/c/src/proactor/libuv.c:364
[2750] (2021-03-08 14:46:10) tid:0x2d2310 <alloc_memory_for_dlsym> "_Bool
handle(qd_server_t *, pn_event_t *, pn_connection_t *, qd_connection_t *)
pn_conn 0x61200001ec50 ctx 0x61e0000cb510 event PN_TRANSPORT_CLOSED"
distro/src/server.c:982
[2751] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void uv_safe_close(uv_handle_t
*, uv_close_cb) handle 0x61d0003e4ec8 is_closing 0"
distro/c/src/proactor/libuv.c:440
[2752] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void uv_safe_close(uv_handle_t
*, uv_close_cb) handle 0x61d0003e4ec8 before uv_close"
distro/c/src/proactor/libuv.c:446
[2753] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void uv_close(uv_handle_t *,
uv_close_cb) handle 0x61d0003e4ec8 type 12 data 0x61d0003e4e80 is_closing 0
flags c008" ../../../../distro/src/unix/core.c:123
[2754] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void uv__tcp_close(uv_tcp_t *)
handle 0x61d0003e4ec8" ../../../../distro/src/unix/tcp.c:469
[2755] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__make_close_pending(uv_handle_t *) handle 0x61d0003e4ec8 data 0x61d0003e4e80
current 0x0" ../../../../distro/src/unix/core.c:232
[2756] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__run_closing_handles(uv_loop_t *) loop 0x61a0000c4f88"
../../../../distro/src/unix/core.c:393
[2757] (2021-03-08 14:46:10) tid:0x61a0000ca880 "p 0x61d0003e4ec8 conn
0x61d0003e4e80" ../../../../distro/src/unix/core.c:394
[2758] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__finish_close(uv_handle_t *) handle 0x61d0003e4ec8 data 0x61d0003e4e80 flags
9 type 12" ../../../../distro/src/unix/core.c:303
[2759] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__finish_close(uv_handle_t *) before QUEUE_REMOVE handle_queue
0x61d0003e5648,0x61d000410848" ../../../../distro/src/unix/core.c:367
[2760] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [--I] signal 0x61a0000c51b0
[0x61a0000c51d0,0x61a0000c51d8]" ../../../../distro/src/unix/core.c:293
[2761] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [-AI] async 0x61a0000c5018
[0x61a0000c5038,0x61a0000c5040]" ../../../../distro/src/unix/core.c:293
[2762] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] async 0x61a0000c4e80
[0x61a0000c4ea0,0x61a0000c4ea8]" ../../../../distro/src/unix/core.c:293
[2763] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] async 0x61a0000c4f00
[0x61a0000c4f20,0x61a0000c4f28]" ../../../../distro/src/unix/core.c:293
[2764] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] timer 0x61a0000c5250
[0x61a0000c5270,0x61a0000c5278]" ../../../../distro/src/unix/core.c:293
[2765] (2021-03-08 14:46:10) tid:0x61a0000ca880 "void
uv__trace_handles(uv_loop_t *) loop 0x61a0000c4f88 [RA-] tcp 0x612000030350
[0x612000030370,0x612000030378]" ../../../../distro/src/unix/core.c:293
(ugdb-x86_64-7.11-261) exit
asan report:
==9350==ERROR: AddressSanitizer: heap-use-after-free on address 0x61d0003e44d8
at pc 0x0008006b5746 bp 0x000806005bf0 sp 0x000806005be8
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#11]
[11|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#11]
READ of size 4 at 0x61d0003e44d8 thread T6
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#12]
[12|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#12]
#0 0x8006b5745 in uv__trace_handles
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:276:16
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#13]
[13|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#13]
#1 0x8006b3d6e in uv__finish_close
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:369:3
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#14]
[14|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#14]
#2 0x8006af093 in uv__run_closing_handles
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:397:5
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#15]
[15|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#15]
#3 0x8006aeb03 in uv_run
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:467:5
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#16]
[16|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#16]
#4 0x800b52d85 in leader_lead_lh
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:1085:5
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#17]
[17|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#17]
#5 0x800b52f2c in pn_proactor_wait
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:1118:15
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#18]
[18|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#18]
#6 0x8005b6c90 in thread_run
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/server.c:1086:36
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#19]
[19|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#19]
#7 0x8005bfea2 in _thread_init
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/posix/threading.c:172:12
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#20]
[20|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#20]
#8 0x800ed01d4 in thread_start
/x/eng/bbrtp2/daemon/DOT/dev/daemon_base/bsd99/bedrock/private/x86_64/bsd_libthr/lib/libthr/../../../../../../src/lib/libthr/thread/thr_create.c:299:16
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#21]
[21|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#21]
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#22]
[22|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#22]
0x61d0003e44d8 is located 88 bytes inside of 2408-byte region
[0x61d0003e4480,0x61d0003e4de8)
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#23]
[23|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#23]
freed by thread T6 here:
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#24]
[24|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#24]
#0 0x28d28d in free
/x/eng/bbrtp2/daemon/DOT/dev/daemon_base/third_party/open_source/llvm/distro/compiler-rt/lib/asan/asan_malloc_linux.cpp:123:3
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#25]
[25|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#25]
#1 0x800b57d8f in pconnection_free
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:373:3
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#26]
[26|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#26]
#2 0x800b579b4 in on_close_pconnection_final
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:433:3
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#27]
[27|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#27]
#3 0x8006b3e63 in uv__finish_close
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:379:5
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#28]
[28|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#28]
#4 0x8006af093 in uv__run_closing_handles
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:397:5
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#29]
[29|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#29]
#5 0x8006aeb03 in uv_run
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:467:5
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#30]
[30|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#30]
#6 0x800b52d85 in leader_lead_lh
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:1085:5
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#31]
[31|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#31]
#7 0x800b52f2c in pn_proactor_wait
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:1118:15
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#32]
[32|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#32]
#8 0x8005b6c90 in thread_run
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/server.c:1086:36
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#33]
[33|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#33]
#9 0x8005bfea2 in _thread_init
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/posix/threading.c:172:12
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#34]
[34|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#34]
#10 0x800ed01d4 in thread_start
/x/eng/bbrtp2/daemon/DOT/dev/daemon_base/bsd99/bedrock/private/x86_64/bsd_libthr/lib/libthr/../../../../../../src/lib/libthr/thread/thr_create.c:299:16
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#35]
[35|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#35]
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#36]
[36|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#36]
previously allocated by thread T0 here:
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#37]
[37|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#37]
#0 0x28d572 in calloc
/x/eng/bbrtp2/daemon/DOT/dev/daemon_base/third_party/open_source/llvm/distro/compiler-rt/lib/asan/asan_malloc_linux.cpp:154:3
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#38]
[38|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#38]
#1 0x800b53a79 in pconnection
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:345:39
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#39]
[39|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#39]
#2 0x800b536b3 in pn_proactor_connect2
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:1214:23
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#40]
[40|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#40]
#3 0x800b63dbd in pn_proactor_connect
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-proton/distro/c/src/proactor/proactor-internal.c:97:3
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#41]
[41|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#41]
#4 0x8005b9c66 in try_open_lh
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/server.c:1204:5
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#42]
[42|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#42]
#5 0x8005b7aee in try_open_cb
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/server.c:1313:14
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#43]
[43|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#43]
#6 0x8005c11bd in qd_timer_visit
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/timer.c:201:9
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#44]
[44|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#44]
#7 0x8005b87ba in handle
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/server.c:998:9
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#45]
[45|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#45]
#8 0x8005b6d14 in thread_run
/x/eng/bbrtp2/users/alward/qdmtrace_web_5947031_2103080834/third_party/open_source/qpid-dispatch/distro/src/server.c:1101:23
[|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#46]
[46|http://web.smoke.gdl.englab.netapp.com/gx_parser.cgi?testlog=/u/smoke/presub/logs/cit-upgrade-rtp.alward.1615226158.78546_cmode_1of1/010_cleanup/07_did_bad_happen/smoke5-vsim-ucs5b2b-asan_check.log#46]
(distro/router/src/main.c:44)
> ASAN use after free in connection close
> ---------------------------------------
>
> Key: DISPATCH-1989
> URL: https://issues.apache.org/jira/browse/DISPATCH-1989
> Project: Qpid Dispatch
> Issue Type: Bug
> Components: Router Node, Routing Engine
> Affects Versions: 1.13.0, 1.14.0
> Reporter: Alex Ward
> Priority: Minor
> Attachments: mtrace.txt, qdrouterd.txt
>
>
> While we dig into the issue below I thought it worth reaching out to see if
> this is a familiar issue or in code that has changed much since 1.13 so may
> have likely already been fixed.
> We have a freebsd product that is using qdrouterd. We have had some crashes
> during closing of connections to a broker so built a qdrouterd with asan on.
> This is hitting the use-after-free issue in uv__run_closing_handles below
> fairly reliably.
> It appears from first inspection that uv__finish_close is trying to remove a
> handle from the handle_queue at line 300 but the handle_queue has reference
> into a pconnection_t that has already been freed.
> Is this an area of code that has had issues in the past? Is this likely to
> have been fixed in the latest release? Any suggestions on where to add
> printfs etc to identify the culprit?
>
>
> {{243static void uv__finish_close(uv_handle_t* handle) {}}
> {{244 uv_signal_t* sh;}}
> {{245}}
> {{246 /* Note: while the handle is in the UV_HANDLE_CLOSING state now, it's
> still}}
> {{247 * possible for it to be active in the sense that uv__is_active()
> returns}}
> {{248 * true.}}
> {{249 *}}
> {{250 * A good example is when the user calls uv_shutdown(), immediately
> followed}}
> {{251 * by uv_close(). The handle is considered active at this point because
> the}}
> {{252 * completion of the shutdown req is still pending.}}
> {{253 */}}
> {{254 assert(handle->flags & UV_HANDLE_CLOSING);}}
> {{255 assert(!(handle->flags & UV_HANDLE_CLOSED));}}
> {{256 handle->flags |= UV_HANDLE_CLOSED;}}
> {{257}}
> {{258 switch (handle->type) {}}
> {{259 case UV_PREPARE:}}
> {{260 case UV_CHECK:}}
> {{261 case UV_IDLE:}}
> {{262 case UV_ASYNC:}}
> {{263 case UV_TIMER:}}
> {{264 case UV_PROCESS:}}
> {{265 case UV_FS_EVENT:}}
> {{266 case UV_FS_POLL:}}
> {{267 case UV_POLL:}}
> {{268 break;}}
> {{269}}
> {{270 case UV_SIGNAL:}}
> {{271 /* If there are any caught signals "trapped" in the signal pipe,}}
> {{272 * we can't call the close callback yet. Reinserting the handle}}
> {{273 * into the closing queue makes the event loop spin but that's}}
> {{274 * okay because we only need to deliver the pending events.}}
> {{275 */}}
> {{276 sh = (uv_signal_t*) handle;}}
> {{277 if (sh->caught_signals > sh->dispatched_signals) {}}
> {{278 handle->flags ^= UV_HANDLE_CLOSED;}}
> {{279 uv__make_close_pending(handle); /* Back into the queue. */}}
> {{280 return;}}
> {{281 }}}
> {{282 break;}}
> {{283}}
> {{284 case UV_NAMED_PIPE:}}
> {{285 case UV_TCP:}}
> {{286 case UV_TTY:}}
> {{287 uv__stream_destroy((uv_stream_t*)handle);}}
> {{288 break;}}
> {{289}}
> {{290 case UV_UDP:}}
> {{291 uv__udp_finish_close((uv_udp_t*)handle);}}
> {{292 break;}}
> {{293}}
> {{294 default:}}
> {{295 assert(0);}}
> {{296 break;}}
> {{297 }}}
> {{298}}
> {{299 uv__handle_unref(handle);}}
> {{300 QUEUE_REMOVE(&handle->handle_queue);}}
> {{301}}
> {{302 if (handle->close_cb) {}}
> {{303 handle->close_cb(handle);}}
> {{304 }}}
> {{305}}}
>
> Here's the asan report
> {{10 ==13358==ERROR: AddressSanitizer: heap-use-after-free on address
> 0x61d0002ec048 at pc 0x0008006a7f84 bp 0x7fffffffe8c0 sp 0x7fffffffe8b8}}
> {{11 WRITE of size 8 at 0x61d0002ec048 thread T0}}
> {{12 #0 0x8006a7f83 in uv__finish_close
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:300:3}}
> {{13 #1 0x8006a38db in uv__run_closing_handles
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:317:5}}
> {{14 #2 0x8006a3463 in uv_run
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:387:5}}
> {{15 #3 0x800b378b5 in leader_lead_lh
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:1039:5}}
> {{16 #4 0x800b37a5c in pn_proactor_wait
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:1072:15}}
> {{17 #5 0x8005b55c0 in thread_run
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-dispatch/distro/src/server.c:1051:36}}
> {{18 #6 0x8005b524b in qd_server_run
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-dispatch/distro/src/server.c:1453:5}}
> {{19 #7 0x2b8e20 in main_process
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-dispatch/distro/router/src/main.c:130:5}}
> {{20 #8 0x2b7ef2 in main
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-dispatch/distro/router/src/main.c:384:9}}
> {{21 #9 0x2b780a in _start
> /x/eng/bbrtp2/daemon/DOT/dev/daemon_base/bsd99/bedrock/private/x86_64/bsd_libcrt_files/lib/csu/amd64/../../../../../../../src/lib/csu/amd64/crt1.c:74:7}}
> {{22 #10 0x8002e4fff (<unknown module>)}}
> {{23 }}
> {{24 0x61d0002ec048 is located 1992 bytes inside of 2408-byte region
> [0x61d0002eb880,0x61d0002ec1e8)}}
> {{25 freed by thread T5 here:}}
> {{26 #0 0x28ca2d in free
> /x/eng/bbrtp2/daemon/DOT/dev/daemon_base/third_party/open_source/llvm/distro/compiler-rt/lib/asan/asan_malloc_linux.cpp:123:3}}
> {{27 #1 0x800b3aec7 in pconnection_free
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:363:3}}
> {{28 #2 0x800b3ae05 in on_close_pconnection_final
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:421:3}}
> {{29 #3 0x8006a7e28 in uv__finish_close
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:303:5}}
> {{30 #4 0x8006a38db in uv__run_closing_handles
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:317:5}}
> {{31 #5 0x8006a3463 in uv_run
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/libuv/bedrock/internal/x86_64.asan.sim/build_configure/../../../../distro/src/unix/core.c:387:5}}
> {{32 #6 0x800b378b5 in leader_lead_lh
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:1039:5}}
> {{33 #7 0x800b37a5c in pn_proactor_wait
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:1072:15}}
> {{34 #8 0x8005b55c0 in thread_run
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-dispatch/distro/src/server.c:1051:36}}
> {{35 #9 0x8005be392 in _thread_init
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-dispatch/distro/src/posix/threading.c:172:12}}
> {{36 #10 0x800eb20f4 in thread_start
> /x/eng/bbrtp2/daemon/DOT/dev/daemon_base/bsd99/bedrock/private/x86_64/bsd_libthr/lib/libthr/../../../../../../src/lib/libthr/thread/thr_create.c:300:16}}
> {{37 }}
> {{38 previously allocated by thread T5 here:}}
> {{39 #0 0x28cd12 in calloc
> /x/eng/bbrtp2/daemon/DOT/dev/daemon_base/third_party/open_source/llvm/distro/compiler-rt/lib/asan/asan_malloc_linux.cpp:154:3}}
> {{40 #1 0x800b38288 in pconnection
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:339:39}}
> {{41 #2 0x800b381e0 in pn_proactor_connect2
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-proton/distro/c/src/proactor/libuv.c:1168:23}}
> {{42 #3 0x800b4658d in pn_proactor_connect
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-proton/distro/c/src/proactor/proactor-internal.c:97:3}}
> {{43 #4 0x8005b8156 in try_open_lh
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-dispatch/distro/src/server.c:1169:5}}
> {{44 #5 0x8005b641e in try_open_cb
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-dispatch/distro/src/server.c:1278:14}}
> {{45 #6 0x8005bf6ad in qd_timer_visit
> /x/eng/bbrtp3/users/alward/resilasan_5930910_2102181129/third_party/open_source/qpid-dispatch/distro/src/timer.c:201:9}}
> {{46 #7 0x8005b6ef8 (/usr/lib/libqpid-dispatch.so
> (distro/router/src/main.c:43)}}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
