Ganesh Murthy created DISPATCH-1957:
---------------------------------------
Summary: Leaked objects in system_tests_delivery_abort
Key: DISPATCH-1957
URL: https://issues.apache.org/jira/browse/DISPATCH-1957
Project: Qpid Dispatch
Issue Type: Test
Affects Versions: 1.15.0
Environment: rhel 8
Reporter: Ganesh Murthy
There are several leaked objects shown in the following test output. These seem
to be router shutdown leaks. We need to come up with a strategy to
systematically take care of these kinds of leaks.
{noformat}
Stacktracetest_01_message_route_truncated_one_router
(system_tests_delivery_abort.RouterTest) ... ok
test_02_message_route_truncated_two_routers
(system_tests_delivery_abort.RouterTest) ... ok
test_03_link_route_truncated_one_router
(system_tests_delivery_abort.RouterTest) ... ok
test_04_link_route_truncated_two_routers
(system_tests_delivery_abort.RouterTest) ... ok
test_05_message_route_abort_one_router (system_tests_delivery_abort.RouterTest)
... ok
test_06_message_route_abort_two_routers
(system_tests_delivery_abort.RouterTest) ... ok
test_07_multicast_truncate_one_router (system_tests_delivery_abort.RouterTest)
... ok
Router B debug dump file:
>>>>
alloc.c: Items of type 'qd_iterator_t' remain allocated at shutdown: 10
(SUPPRESSED)
alloc.c: Items of type 'qd_timer_t' remain allocated at shutdown: 1 (SUPPRESSED)
alloc.c: Items of type 'qd_bitmask_t' remain allocated at shutdown: 1
Leak: 2021-02-11 11:17:27.438173 -0500 type: qd_bitmask_t address: 0x2c80010
/opt/qpid-dispatch-src/build/src/libqpid-dispatch.so(qd_alloc+0x20c)
[0x7f615186bf67]
/opt/qpid-dispatch-src/build/src/libqpid-dispatch.so(new_qd_bitmask_t+0x26)
[0x7f615186d58c]
/opt/qpid-dispatch-src/build/src/libqpid-dispatch.so(qd_bitmask+0x10)
[0x7f615186d66a]
/opt/qpid-dispatch-src/build/src/libqpid-dispatch.so(qd_tracemask_create+0x1e)
[0x7f61518e58c6]
/opt/qpid-dispatch-src/build/src/libqpid-dispatch.so(+0xbcbc1) [0x7f61518d8bc1]
/opt/qpid-dispatch-src/build/src/libqpid-dispatch.so(+0xbd88f) [0x7f61518d988f]
/opt/qpid-dispatch-src/build/src/libqpid-dispatch.so(+0x59763) [0x7f6151875763]
/opt/qpid-dispatch-src/build/src/libqpid-dispatch.so(qd_container_handle_event+0xd09)
[0x7f6151876f42]
/opt/qpid-dispatch-src/build/src/libqpid-dispatch.so(+0xc6296) [0x7f61518e2296]
/opt/qpid-dispatch-src/build/src/libqpid-dispatch.so(+0xc636c) [0x7f61518e236c]
alloc.c: Items of type 'qd_buffer_t' remain allocated at shutdown: 5
(SUPPRESSED)
alloc.c: Items of type 'qd_parsed_field_t' remain allocated at shutdown: 4
(SUPPRESSED)
alloc.c: Items of type 'qd_connector_t' remain allocated at shutdown: 1
(SUPPRESSED)
alloc.c: Items of type 'qd_message_t' remain allocated at shutdown: 2
(SUPPRESSED)
alloc.c: Items of type 'qd_message_content_t' remain allocated at shutdown: 1
(SUPPRESSED)
alloc.c: Items of type 'qdr_delivery_t' remain allocated at shutdown: 2
(SUPPRESSED)
alloc.c: Items of type 'qd_link_ref_t' remain allocated at shutdown: 1
(SUPPRESSED)
<<<<
Router B output file:
>>>>
ERROR: Aborted due to unexpected alloc pool leak of type 'qd_bitmask_t'
<<<<
Router B command file:
>>>>
qdrouterd -c B.conf -I /opt/qpid-dispatch-src/python
pid=12488
<<<<
Router B log file tail:
>>>>
2021-02-11 11:17:29.457738 -0500 ROUTER_CORE (debug) [C9][L38][D118] Delivery
outcome : is accepted (0x24)
(/opt/qpid-dispatch-src/src/router_core/delivery.c:395)
2021-02-11 11:17:29.457753 -0500 ROUTER_CORE (trace) Core action
'update_delivery'
(/opt/qpid-dispatch-src/src/router_core/router_core_thread.c:238)
2021-02-11 11:17:29.457762 -0500 ROUTER_CORE (debug) [C1][L16][D117] Delivery
incref: rc:4 qdr_delivery_anycast_update_CT - prevent peer from being freed
(/opt/qpid-dispatch-src/src/router_core/delivery.c:113)
2021-02-11 11:17:29.457771 -0500 ROUTER_CORE (trace) [C9][L38][D119] :in
qdr_delivery_unlink_peers_CT out: [C1][L16][D117]
(/opt/qpid-dispatch-src/src/router_core/delivery.c:542)
2021-02-11 11:17:29.457781 -0500 ROUTER_CORE (debug) [C9][L38][D119] Delivery
decref_CT: rc:2 qdr_delivery_unlink_peers_CT - unlinked from peer (delivery)
(/opt/qpid-dispatch-src/src/router_core/delivery.c:640)
2021-02-11 11:17:29.457794 -0500 ROUTER_CORE (debug) [C1][L16][D117] Delivery
decref_CT: rc:3 qdr_delivery_unlink_peers_CT - unlinked from delivery (peer)
(/opt/qpid-dispatch-src/src/router_core/delivery.c:640)
2021-02-11 11:17:29.457807 -0500 ROUTER_CORE (debug) [C1][L16][D117] Delivery
incref: rc:4 qdr_delivery_push_CT - add to updated list
(/opt/qpid-dispatch-src/src/router_core/delivery.c:113)
2021-02-11 11:17:29.457824 -0500 ROUTER_CORE (debug) [C9][L38][D119] Delivery
decref_CT: rc:1 qdr_delivery_anycast_update CT - dlv removed from unsettled
(/opt/qpid-dispatch-src/src/router_core/delivery.c:640)
2021-02-11 11:17:29.457837 -0500 ROUTER_CORE (debug) [C1][L16][D117] Delivery
decref_CT: rc:3 qdr_delivery_anycast_update_CT - peer removed from unsettled
(/opt/qpid-dispatch-src/src/router_core/delivery.c:640)
2021-02-11 11:17:29.457850 -0500 ROUTER_CORE (debug) [C1][L16][D117] Delivery
decref_CT: rc:2 qdr_delivery_anycast_update_CT - allow free of peer
(/opt/qpid-dispatch-src/src/router_core/delivery.c:640)
2021-02-11 11:17:29.457864 -0500 ROUTER_CORE (debug) [C9][L38][D119] Delivery
decref_CT: rc:0 qdr_update_delivery_CT - remove from action
(/opt/qpid-dispatch-src/src/router_core/delivery.c:640)
2021-02-11 11:17:29.457882 -0500 ROUTER_CORE (debug) [C9][L38][D119] Delivery
outcome : is accepted (0x24)
(/opt/qpid-dispatch-src/src/router_core/delivery.c:395)
2021-02-11 11:17:29.457896 -0500 ROUTER_CORE (trace) Core action 'link_detach'
(/opt/qpid-dispatch-src/src/router_core/router_core_thread.c:238)
2021-02-11 11:17:29.457911 -0500 ROUTER_MA (debug) No Longer Local Dest:
M0addr_06
(/opt/qpid-dispatch-src/src/router_core/modules/mobile_sync/mobile.c:763)
2021-02-11 11:17:29.457923 -0500 ROUTER_CORE (info) [C9][L38] Link lost: del=9
presett=0 psdrop=0 acc=9 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
(/opt/qpid-dispatch-src/src/router_core/connections.c:1054)
2021-02-11 11:17:29.457934 -0500 ROUTER_CORE (trace) Core action
'connection_closed'
(/opt/qpid-dispatch-src/src/router_core/router_core_thread.c:238)
2021-02-11 11:17:29.457943 -0500 ROUTER_CORE (info) [C9] Connection Closed
(/opt/qpid-dispatch-src/src/router_core/connections.c:1531)
2021-02-11 11:17:29.458510 -0500 ROUTER_CORE (debug) [C1][L16][D116] Delivery
decref: rc:1 removed reference from pn_delivery
(/opt/qpid-dispatch-src/src/router_core/delivery.c:147)
2021-02-11 11:17:29.458547 -0500 ROUTER_CORE (debug) [C1][L16][D116] Delivery
decref: rc:0 qdr_connection_process - remove from updated list
(/opt/qpid-dispatch-src/src/router_core/delivery.c:147)
2021-02-11 11:17:29.458570 -0500 ROUTER_CORE (debug) [C1][L16][D117] Delivery
decref: rc:1 removed reference from pn_delivery
(/opt/qpid-dispatch-src/src/router_core/delivery.c:147)
2021-02-11 11:17:29.458581 -0500 ROUTER_CORE (debug) [C1][L16][D117] Delivery
decref: rc:0 qdr_connection_process - remove from updated list
(/opt/qpid-dispatch-src/src/router_core/delivery.c:147)
2021-02-11 11:17:29.458613 -0500 PROTOCOL (trace) [C1]:FRAME: 5 ->
@disposition(21) [role=true, first=33, last=34, settled=true,
state=@accepted(36) []] (/opt/qpid-dispatch-src/src/server.c:113)
2021-02-11 11:17:29.458739 -0500 ROUTER_CORE (trace) Core action
'qdr_connection_process - remove from updated list'
(/opt/qpid-dispatch-src/src/router_core/router_core_thread.c:238)
2021-02-11 11:17:29.458779 -0500 ROUTER_CORE (debug) [C1][L16][D116] Delivery
outcome : is accepted (0x24)
(/opt/qpid-dispatch-src/src/router_core/delivery.c:395)
2021-02-11 11:17:29.458807 -0500 ROUTER_CORE (trace) Core action
'qdr_connection_process - remove from updated list'
(/opt/qpid-dispatch-src/src/router_core/router_core_thread.c:238)
2021-02-11 11:17:29.458834 -0500 ROUTER_CORE (debug) [C1][L16][D117] Delivery
outcome : is accepted (0x24)
(/opt/qpid-dispatch-src/src/router_core/delivery.c:395)
2021-02-11 11:17:29.587209 -0500 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] (/opt/qpid-dispatch-src/src/server.c:113)
2021-02-11 11:17:29.587254 -0500 PROTOCOL (trace) [C4]:FRAME: 0 <- @close(24)
[] (/opt/qpid-dispatch-src/src/server.c:113)
2021-02-11 11:17:29.587272 -0500 PROTOCOL (trace) [C4]:FRAME: <- EOS
(/opt/qpid-dispatch-src/src/server.c:113)
2021-02-11 11:17:29.587322 -0500 PROTOCOL (trace) [C4]:FRAME: 0 -> @close(24)
[] (/opt/qpid-dispatch-src/src/server.c:113)
2021-02-11 11:17:29.587360 -0500 PROTOCOL (trace) [C4]:FRAME: -> EOS
(/opt/qpid-dispatch-src/src/server.c:113)
2021-02-11 11:17:29.587461 -0500 ROUTER_CORE (trace) Core action 'link_flow'
(/opt/qpid-dispatch-src/src/router_core/router_core_thread.c:238)
2021-02-11 11:17:29.587477 -0500 ROUTER_CORE (trace) Core action 'link_detach'
(/opt/qpid-dispatch-src/src/router_core/router_core_thread.c:238)
2021-02-11 11:17:29.587491 -0500 ROUTER_CORE (info) [C4][L28] Link lost: del=2
presett=0 psdrop=0 acc=2 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
(/opt/qpid-dispatch-src/src/router_core/connections.c:1054)
2021-02-11 11:17:29.587503 -0500 ROUTER_CORE (trace) Core action 'link_detach'
(/opt/qpid-dispatch-src/src/router_core/router_core_thread.c:238)
2021-02-11 11:17:29.587515 -0500 ROUTER_CORE (info) [C4][L29] Link lost: del=2
presett=2 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
(/opt/qpid-dispatch-src/src/router_core/connections.c:1054)
2021-02-11 11:17:29.587529 -0500 ROUTER_CORE (trace) Core action
'connection_closed'
(/opt/qpid-dispatch-src/src/router_core/router_core_thread.c:238)
2021-02-11 11:17:29.587539 -0500 ROUTER_CORE (info) [C4] Connection Closed
(/opt/qpid-dispatch-src/src/router_core/connections.c:1531)
2021-02-11 11:17:29.588247 -0500 SERVER (notice) Shut Down
(/opt/qpid-dispatch-src/src/server.c:1493)
2021-02-11 11:17:29.588312 -0500 CONTAINER (trace) Default node removed
(/opt/qpid-dispatch-src/src/container.c:848)
2021-02-11 11:17:29.588340 -0500 ROUTER_CORE (info) Router Core thread exited
(/opt/qpid-dispatch-src/src/router_core/router_core_thread.c:259)
2021-02-11 11:17:29.588369 -0500 TCP_ADAPTOR (info) Shutting down TCP protocol
adaptor (/opt/qpid-dispatch-src/src/adaptors/tcp_adaptor.c:1249)
2021-02-11 11:17:29.588721 -0500 ROUTER_CORE (info) Finalizing core module:
streaming_link_scrubber
(/opt/qpid-dispatch-src/src/router_core/router_core_thread.c:138)
2021-02-11 11:17:29.588747 -0500 ROUTER_CORE (info) Finalizing core module:
mobile_sync (/opt/qpid-dispatch-src/src/router_core/router_core_thread.c:138)
2021-02-11 11:17:29.588758 -0500 ROUTER_CORE (info) Finalizing core module:
stuck_delivery_detection
(/opt/qpid-dispatch-src/src/router_core/router_core_thread.c:138)
2021-02-11 11:17:29.588767 -0500 ROUTER_CORE (info) Finalizing core module:
address_lookup_client
(/opt/qpid-dispatch-src/src/router_core/router_core_thread.c:138)
2021-02-11 11:17:29.588777 -0500 ROUTER_CORE (info) Finalizing core module:
address_lookup_server
(/opt/qpid-dispatch-src/src/router_core/router_core_thread.c:138)
2021-02-11 11:17:29.588786 -0500 ROUTER_CORE (info) Finalizing core module:
edge_addr_tracking
(/opt/qpid-dispatch-src/src/router_core/router_core_thread.c:138)
2021-02-11 11:17:29.588843 -0500 SERVER (info) [C1] Closing connection on
shutdown (/opt/qpid-dispatch-src/src/server.c:1379)
2021-02-11 11:17:29.588866 -0500 SERVER (info) [C5] Closing connection on
shutdown (/opt/qpid-dispatch-src/src/server.c:1379)
<<<<
ERROR
======================================================================
ERROR: tearDownClass (system_tests_delivery_abort.RouterTest)
----------------------------------------------------------------------
Traceback (most recent call last):
File "/opt/qpid-dispatch-src/tests/system_test.py", line 839, in tearDownClass
cls.tester.teardown()
File "/opt/qpid-dispatch-src/tests/system_test.py", line 782, in teardown
raise RuntimeError("Errors during teardown: \n\n%s" % "\n\n".join([str(e)
for e in errors]))
RuntimeError: Errors during teardown:
Process 12488 error: exit code -6, expected 0
qdrouterd -c B.conf -I /opt/qpid-dispatch-src/python
/opt/qpid-dispatch-src/build/tests/system_test.dir/system_tests_delivery_abort/RouterTest/setUpClass/B-2.cmd
>>>>
ERROR: Aborted due to unexpected alloc pool leak of type 'qd_bitmask_t'
<<<<
----------------------------------------------------------------------
Ran 7 tests in 6.040s
FAILED (errors=1)
{noformat}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@qpid.apache.org
For additional commands, e-mail: dev-h...@qpid.apache.org
