You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@qpid.apache.org by "Ganesh Murthy (Jira)" <ji...@apache.org> on 2021/11/02 16:20:00 UTC
[jira] [Resolved] (DISPATCH-1957) Leaked objects in
system_tests_delivery_abort
[ https://issues.apache.org/jira/browse/DISPATCH-1957?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Ganesh Murthy resolved DISPATCH-1957.
-------------------------------------
Resolution: Fixed
> 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
> Assignee: Ken Giusti
> Priority: Major
> Fix For: 1.18.0
>
>
> 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-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org