Jiri Daněk created DISPATCH-2180:
------------------------------------
Summary: Data race in qd_alloc_sequence from
system_tests_policy_oversize_basic
Key: DISPATCH-2180
URL: https://issues.apache.org/jira/browse/DISPATCH-2180
Project: Qpid Dispatch
Issue Type: Bug
Affects Versions: 1.17.0
Reporter: Jiri Daněk
This is a PR build, but I think it is unlikely the build changes in PR caused
this.
https://github.com/apache/qpid-dispatch/pull/1267/checks?check_run_id=2872865196#step:25:804
{noformat}
26: Router EA1 output file:
26: >>>>
26: ==================
26: WARNING: ThreadSanitizer: data race (pid=1865)
26: Read of size 8 at 0x7b480001b600 by thread T2:
26: #0 qd_alloc_sequence
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/alloc_pool.c:525
(qdrouterd+0x44df98)
26: #1 cleanup_link
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/container.c:359
(qdrouterd+0x462da3)
26: #2 qd_link_free
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/container.c:1000
(qdrouterd+0x4632b5)
26: #3 qd_link_free
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/container.c:991
(qdrouterd+0x463392)
26: #4 AMQP_link_detach_handler
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_node.c:1142
(qdrouterd+0x4dc8f1)
26: #5 AMQP_link_detach_handler
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_node.c:1095
(qdrouterd+0x4dc8f1)
26: #6 close_links
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/container.c:336
(qdrouterd+0x463419)
26: #7 qd_container_handle_event
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/container.c:528
(qdrouterd+0x4643f3)
26: #8 handle
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/server.c:1096
(qdrouterd+0x4e1c51)
26: #9 thread_run
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/server.c:1121
(qdrouterd+0x4e3f0b)
26: #10 _thread_init
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/posix/threading.c:172
(qdrouterd+0x4868bd)
26:
26: Previous write of size 8 at 0x7b480001b600 by main thread:
26: #0 qd_dealloc
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/alloc_pool.c:477
(qdrouterd+0x44d6d6)
26: #1 free_qd_message_t
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/message.c:91
(qdrouterd+0x472a1b)
26: #2 qd_message_free
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/message.c:1091
(qdrouterd+0x472a1b)
26: #3 qdr_do_message_to_addr_free
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/router_core_thread.c:102
(qdrouterd+0x4bcfa6)
26: #4 qdr_general_handler
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/router_core.c:942
(qdrouterd+0x4b5bc3)
26: #5 qd_timer_visit
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/timer.c:316
(qdrouterd+0x4e6bb5)
26: #6 handle
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/server.c:1006
(qdrouterd+0x4e1be6)
26: #7 thread_run
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/server.c:1121
(qdrouterd+0x4e4005)
26: #8 qd_server_run
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/server.c:1501
(qdrouterd+0x4e4c11)
26: #9 main_process
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/router/src/main.c:115
(qdrouterd+0x426ccc)
26: #10 main
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/router/src/main.c:369
(qdrouterd+0x42622c)
26:
26: Location is heap block of size 384 at 0x7b480001b600 allocated by thread
T1:
26: #0 posix_memalign <null> (libtsan.so.0+0x32a23)
26: #1 qd_alloc
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/alloc_pool.c:396
(qdrouterd+0x44c6d4)
26: #2 new_qd_message_t
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/message.c:91
(qdrouterd+0x475a3d)
26: #3 qd_message_copy
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/message.c:1099
(qdrouterd+0x475a3d)
26: #4 qdr_forward_on_message_CT
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/forwarder.c:401
(qdrouterd+0x4af41b)
26: #5 qdr_forward_to_subscriber_CT
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/forwarder.c:451
(qdrouterd+0x4af6ef)
26: #6 qdr_forward_closest_CT
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/forwarder.c:644
(qdrouterd+0x4b073b)
26: #7 qdr_forward_message_CT
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/forwarder.c:1120
(qdrouterd+0x4b22a0)
26: #8 qdr_link_forward_CT
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/transfer.c:572
(qdrouterd+0x4c5a43)
26: #9 qdr_link_deliver_CT
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/transfer.c:862
(qdrouterd+0x4c6f52)
26: #10 router_core_thread
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/router_core_thread.c:239
(qdrouterd+0x4bdcc1)
26: #11 _thread_init
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/posix/threading.c:172
(qdrouterd+0x4868bd)
26:
26: Thread T2 (tid=1868, running) created by main thread at:
26: #0 pthread_create <null> (libtsan.so.0+0x5bf45)
26: #1 sys_thread
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/posix/threading.c:181
(qdrouterd+0x486d4c)
26: #2 qd_server_run
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/server.c:1499
(qdrouterd+0x4e4bec)
26: #3 main_process
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/router/src/main.c:115
(qdrouterd+0x426ccc)
26: #4 main
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/router/src/main.c:369
(qdrouterd+0x42622c)
26:
26: Thread T1 (tid=1867, running) created by main thread at:
26: #0 pthread_create <null> (libtsan.so.0+0x5bf45)
26: #1 sys_thread
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/posix/threading.c:181
(qdrouterd+0x486d4c)
26: #2 qdr_core
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/router_core.c:124
(qdrouterd+0x4b7170)
26: #3 qd_router_setup_late
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_node.c:2124
(qdrouterd+0x4dce28)
26: #4 ffi_call_unix64 <null> (libffi.so.6+0x6c03)
26: #5 main_process
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/router/src/main.c:97
(qdrouterd+0x426c6c)
26: #6 main
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/router/src/main.c:369
(qdrouterd+0x42622c)
26:
26: SUMMARY: ThreadSanitizer: data race
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/alloc_pool.c:525
in qd_alloc_sequence
26: ==================
26: ThreadSanitizer: reported 1 warnings
26:
26: <<<<
26:
26: Router EA1 command file:
26: >>>>
26: qdrouterd -c EA1.conf -I
/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/python
26: pid=1865
26:
26: <<<<
26:
26: Router EA1 log file tail:
26: >>>>
26: 2021-06-21 07:29:07.882159 +0000 PROTOCOL (trace) [C1]:FRAME: 2 ->
@disposition(21) [role=true, first=19, settled=true, state=@accepted(36) []]
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/server.c:111)
26: 2021-06-21 07:29:07.882322 +0000 PROTOCOL (trace) [C1]:FRAME: 0 ->
@detach(22) [handle=2, closed=true]
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/server.c:111)
26: 2021-06-21 07:29:07.882607 +0000 PROTOCOL (trace) [C19]:FRAME: -> EOS
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/server.c:111)
26: 2021-06-21 07:29:07.882774 +0000 POLICY (debug) [C19] Connection
'127.0.0.1:58174' closed with resources n_sessions=1, n_senders=0,
n_receivers=0, sessions_denied=0, senders_denied=0, receivers_denied=0,
max_message_size_denied:4, nConnections= 1.
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/policy.c:318)
26: 2021-06-21 07:29:07.886179 +0000 ROUTER_CORE (trace) Core action
'connection_closed'
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/router_core_thread.c:238)
26: 2021-06-21 07:29:07.886279 +0000 ROUTER_CORE (info) [C19][L40] Link closed
due to connection loss: del=10 presett=0 psdrop=0 acc=10 rej=0 rel=0 mod=0
delay1=0 delay10=0 blocked=no
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/connections.c:1082)
26: 2021-06-21 07:29:07.886346 +0000 ROUTER_CORE (info) [C19] Connection Closed
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/connections.c:1565)
26: 2021-06-21 07:29:07.895274 +0000 PROTOCOL (trace) [C1]:FRAME: 0 <-
@detach(22) [handle=2, closed=true]
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/server.c:111)
26: 2021-06-21 07:29:07.895512 +0000 ROUTER_CORE (trace) Core action
'link_detach'
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/router_core_thread.c:238)
26: 2021-06-21 07:29:07.895595 +0000 ROUTER_CORE (info) [C1][L41] Link
detached: del=0 presett=0 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0
blocked=no
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/connections.c:1082)
26: 2021-06-21 07:29:08.316474 +0000 ROUTER_CORE (trace) Core action
'process_tick'
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/router_core_thread.c:238)
26: 2021-06-21 07:29:08.328086 +0000 PROTOCOL (trace) [C4]:FRAME: 0 <-
@flow(19) [next-incoming-id=2, incoming-window=2147483647, next-outgoing-id=2,
outgoing-window=2147483647, handle=1, delivery-count=2, link-credit=1,
drain=false]
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/server.c:111)
26: 2021-06-21 07:29:08.328210 +0000 PROTOCOL (trace) [C4]:FRAME: 0 <-
@close(24) []
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/server.c:111)
26: 2021-06-21 07:29:08.328290 +0000 PROTOCOL (trace) [C4]:FRAME: <- EOS
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/server.c:111)
26: 2021-06-21 07:29:08.328520 +0000 PROTOCOL (trace) [C4]:FRAME: 0 ->
@close(24) []
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/server.c:111)
26: 2021-06-21 07:29:08.328579 +0000 ROUTER_CORE (trace) Core action
'link_flow'
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/router_core_thread.c:238)
26: 2021-06-21 07:29:08.328665 +0000 ROUTER_CORE (trace) Core action
'link_detach'
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/router_core_thread.c:238)
26: 2021-06-21 07:29:08.328749 +0000 ROUTER_CORE (info) [C4][L9] Link lost:
del=2 presett=0 psdrop=0 acc=2 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/connections.c:1082)
26: 2021-06-21 07:29:08.328813 +0000 ROUTER_CORE (trace) Core action
'link_detach'
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/router_core_thread.c:238)
26: 2021-06-21 07:29:08.328882 +0000 ROUTER_CORE (info) [C4][L10] Link lost:
del=2 presett=2 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/connections.c:1082)
26: 2021-06-21 07:29:08.329618 +0000 PROTOCOL (trace) [C4]:FRAME: -> EOS
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/server.c:111)
26: 2021-06-21 07:29:08.329770 +0000 ROUTER_CORE (trace) Core action
'connection_closed'
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/router_core_thread.c:238)
26: 2021-06-21 07:29:08.329846 +0000 POLICY (debug) [C4] Connection
'127.0.0.1:57890' closed with resources n_sessions=1, n_senders=1,
n_receivers=1, sessions_denied=0, senders_denied=0, receivers_denied=0,
max_message_size_denied:4, nConnections= 0.
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/policy.c:318)
26: 2021-06-21 07:29:08.329914 +0000 ROUTER_CORE (info) [C4] Connection Closed
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/connections.c:1565)
26: 2021-06-21 07:29:08.330881 +0000 SERVER (notice) Shut Down
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/server.c:1508)
26: 2021-06-21 07:29:08.330983 +0000 HTTP (trace) lws_context_destroy: ctx
0x7b8c00000000
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/http-libwebsockets.c:58)
26: 2021-06-21 07:29:08.331079 +0000 HTTP (trace) _lws_state_transition:
system: changed 1 'CONTEXT_CREATED' -> 13 'POLICY_INVALID'
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/http-libwebsockets.c:58)
26: 2021-06-21 07:29:08.331143 +0000 HTTP (trace) lws_destroy_event_pipe
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/http-libwebsockets.c:58)
26: 2021-06-21 07:29:08.331208 +0000 HTTP (trace) lws_pt_destroy: pt destroyed
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/http-libwebsockets.c:58)
26: 2021-06-21 07:29:08.331261 +0000 HTTP (trace) lws_context_destroy2: ctx
0x7b8c00000000
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/http-libwebsockets.c:58)
26: 2021-06-21 07:29:08.331310 +0000 HTTP (trace) 0x7f3883ade9e0: post vh listl
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/http-libwebsockets.c:58)
26: 2021-06-21 07:29:08.331358 +0000 HTTP (trace) 0x7f3883ade9e0: post pdl
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/http-libwebsockets.c:58)
26: 2021-06-21 07:29:08.334179 +0000 HTTP (trace) 0x7f3883ade9e0: baggage
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/http-libwebsockets.c:58)
26: 2021-06-21 07:29:08.334243 +0000 HTTP (trace) 0x7f3883ade9e0: post dc2
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/http-libwebsockets.c:58)
26: 2021-06-21 07:29:08.337107 +0000 HTTP (trace) lws_context_destroy3: ctx
0x7b8c00000000 freed
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/http-libwebsockets.c:58)
26: 2021-06-21 07:29:08.337321 +0000 CONTAINER (trace) Default node removed
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/container.c:852)
26: 2021-06-21 07:29:08.337509 +0000 ROUTER_CORE (info) Router Core thread
exited
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/router_core_thread.c:259)
26: 2021-06-21 07:29:08.337713 +0000 TCP_ADAPTOR (info) Shutting down TCP
protocol adaptor
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/adaptors/tcp_adaptor.c:1760)
26: 2021-06-21 07:29:08.338504 +0000 ROUTER_CORE (trace) Core client sender
detached c=0x7b4800015e10
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/core_client_api.c:581)
26: 2021-06-21 07:29:08.338573 +0000 ROUTER_CORE (trace) edge mgmt client state
change: uc=(nil) down
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/modules/edge_router/edge_mgmt.c:139)
26: 2021-06-21 07:29:08.338642 +0000 ROUTER_CORE (trace) Core client receiver
detached c=0x7b4800015e10
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/core_client_api.c:614)
26: 2021-06-21 07:29:08.338701 +0000 ROUTER_CORE (trace) Core client sender
detached c=0x7b4800015c90
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/core_client_api.c:581)
26: 2021-06-21 07:29:08.338773 +0000 ROUTER_CORE (trace) Core client receiver
detached c=0x7b4800015c90
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/core_client_api.c:614)
26: 2021-06-21 07:29:08.338859 +0000 ROUTER_CORE (info) Finalizing core module:
streaming_link_scrubber
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/router_core_thread.c:138)
26: 2021-06-21 07:29:08.338919 +0000 ROUTER_CORE (info) Finalizing core module:
stuck_delivery_detection
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/router_core_thread.c:138)
26: 2021-06-21 07:29:08.338969 +0000 ROUTER_CORE (info) Finalizing core module:
address_lookup_client
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/router_core_thread.c:138)
26: 2021-06-21 07:29:08.339032 +0000 ROUTER_CORE (trace) Core client freed
c=0x7b4800015c90
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/core_client_api.c:224)
26: 2021-06-21 07:29:08.339101 +0000 ROUTER_CORE (info) Finalizing core module:
edge_router
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/router_core_thread.c:138)
26: 2021-06-21 07:29:08.339161 +0000 ROUTER_CORE (trace) Core client freed
c=0x7b4800015e10
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/router_core/core_client_api.c:224)
26: 2021-06-21 07:29:08.339387 +0000 SERVER (info) [C1] Closing connection on
shutdown
(/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/src/server.c:1388)
26:
26: <<<<
26:
26: ::MaxMessageSizeBlockOversize::test_s32_allow_gt_signed_32bit_max ERROR
{noformat}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
