Uploaded image for project: 'Qpid Dispatch'
  1. Qpid Dispatch
  2. DISPATCH-1954

system_tests_management fails due to qd_bitmask_t leak

    XMLWordPrintableJSON

Details

    • Test
    • Status: Closed
    • Major
    • Resolution: Fixed
    • None
    • 1.16.0
    • Tools
    • None

    Description

      Router router1 debug dump file:
      19: >>>>
      19: alloc.c: Items of type 'qd_iterator_t' remain allocated at shutdown: 9 (SUPPRESSED)
      19: alloc.c: Items of type 'qd_timer_t' remain allocated at shutdown: 1 (SUPPRESSED)
      19: alloc.c: Items of type 'qd_bitmask_t' remain allocated at shutdown: 1
      19: Leak: 2021-02-08 15:33:33.819717 +0000 type: qd_bitmask_t address: 0x611000086090
      19: /lib/x86_64-linux-gnu/libasan.so.5(+0x6cd30) [0x7f14c8ed1d30]
      19: /home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/build/src/libqpid-dispatch.so(qd_alloc+0x37b) [0x7f14c86813db]
      19: /home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/build/src/libqpid-dispatch.so(qd_bitmask+0x12) [0x7f14c8691112]
      19: /home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/build/src/libqpid-dispatch.so(qd_tracemask_create+0xaf) [0x7f14c88b00cf]
      19: /home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/build/src/libqpid-dispatch.so(+0x730542) [0x7f14c888a542]
      19: /home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/build/src/libqpid-dispatch.so(qd_container_handle_event+0x16b7) [0x7f14c86f0507]
      19: /home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/build/src/libqpid-dispatch.so(+0x7403ca) [0x7f14c889a3ca]
      19: /home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/build/src/libqpid-dispatch.so(+0x748911) [0x7f14c88a2911]
      19: /lib/x86_64-linux-gnu/libpthread.so.0(+0x9609) [0x7f14c8140609]
      19: /lib/x86_64-linux-gnu/libc.so.6(clone+0x43) [0x7f14c76fa293]
      19: 
      19: alloc.c: Items of type 'qdr_action_t' remain allocated at shutdown: 2 (SUPPRESSED)
      19: alloc.c: Items of type 'qdr_field_t' remain allocated at shutdown: 1 (SUPPRESSED)
      19: alloc.c: Items of type 'qd_buffer_t' remain allocated at shutdown: 7 (SUPPRESSED)
      19: alloc.c: Items of type 'qd_connector_t' remain allocated at shutdown: 1 (SUPPRESSED)
      19: alloc.c: Items of type 'qdr_link_work_t' remain allocated at shutdown: 1 (SUPPRESSED)
      19: alloc.c: Items of type 'qd_message_t' remain allocated at shutdown: 2 (SUPPRESSED)
      19: alloc.c: Items of type 'qd_message_content_t' remain allocated at shutdown: 2 (SUPPRESSED)
      19: alloc.c: Items of type 'qd_parsed_field_t' remain allocated at shutdown: 3 (SUPPRESSED)
      19: alloc.c: Items of type 'qdr_delivery_t' remain allocated at shutdown: 1 (SUPPRESSED)
      19: 
      19: <<<<
      17: 
      17: ----------------------------------------------------------------------
      17: Ran 15 tests in 17.318s
      17: 
      17: OK
      19: 
      19: Router router1 output file:
      19: >>>>
      19: ERROR: Aborted due to unexpected alloc pool leak of type 'qd_bitmask_t'
      19: 
      19: <<<<
      19: 
      19: Router router1 command file:
      19: >>>>
      19: qdrouterd -c router1.conf -I /home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/python
      19: pid=2431
      19: 
      19: <<<<
      19: 
      19: Router router1 log file tail:
      19: >>>>
      19: 2021-02-08 15:33:33.816853 +0000 ROUTER_CORE (trace) Core action 'link_flow' (../src/router_core/router_core_thread.c:238)
      19: 2021-02-08 15:33:33.816887 +0000 ROUTER_CORE (trace) Core action 'link_detach' (../src/router_core/router_core_thread.c:238)
      19: 2021-02-08 15:33:33.816924 +0000 ROUTER_CORE (info) [C2][L23] Link lost: del=16 presett=0 psdrop=0 acc=16 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no (../src/router_core/connections.c:1049)
      19: 2021-02-08 15:33:33.816955 +0000 ROUTER_CORE (trace) Core action 'link_detach' (../src/router_core/router_core_thread.c:238)
      19: 2021-02-08 15:33:33.816987 +0000 ROUTER_CORE (info) [C2][L24] Link lost: del=16 presett=16 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no (../src/router_core/connections.c:1049)
      19: 2021-02-08 15:33:33.817023 +0000 ROUTER_CORE (trace) Core action 'connection_closed' (../src/router_core/router_core_thread.c:238)
      19: 2021-02-08 15:33:33.817049 +0000 ROUTER_CORE (info) [C2] Connection Closed (../src/router_core/connections.c:1531)
      19: 2021-02-08 15:33:33.817133 +0000 PROTOCOL (trace) [C1]:FRAME: 0 <- @flow(19) [next-incoming-id=20, incoming-window=2147483647, next-outgoing-id=18, outgoing-window=2147483647, handle=1, delivery-count=20, link-credit=250, drain=false] (../src/server.c:113)
      19: 2021-02-08 15:33:33.817209 +0000 ROUTER_CORE (trace) Core action 'link_flow' (../src/router_core/router_core_thread.c:238)
      19: 2021-02-08 15:33:33.819245 +0000 PROTOCOL (trace) [C1]:FRAME: 0 <- @transfer(20) [handle=0, delivery-id=18, delivery-tag=b"#\x00\x00\x00\x00\x00\x00\x00", message-format=0, settled=true] (246) "\x00Sp\xd0\x00\x00\x00\x05\x00\x00\x00\x01B\x00Sr\xd1\x00\x00\x00o\x00\x00\x00\x0a\xa3\x0ex-opt-qd.trace\xd0\x00\x00\x00\x0f\x00\x00\x00\x01\xa1\x090/router0\xa3\x10x-opt-qd.ingress\xa1\x090/router0\xa3\x09x-opt-qd.\xa1\x01X\xa3\x09x-opt-qd.\xa1\x01X\xa3\x09x-opt-qd.\xa1\x01X\x00Ss\xd0\x00\x00\x00)\x00\x00\x00\x06@@\xa1\x1eamqp:/_topo/0/router1/qdrouter@@@\x00St\xd1\x00\x00\x00\x11\x00\x00\x00\x02\xa1\x06opcode\xa1\x03LSR\x00Sw\xd1\x00\x00\x00 \x00\x00\x00\x06\xa1\x02id\xa1\x07router0\xa1\x02pvT\x01\xa1\x04area\xa1\x010" (../src/server.c:113)
      19: 2021-02-08 15:33:33.819765 +0000 ROUTER_CORE (debug) [C1][L1][D132] Delivery created qdr_link_deliver_to (../src/router_core/transfer.c:97)
      19: 2021-02-08 15:33:33.819792 +0000 ROUTER_CORE (debug) [C1][L1][D132] Delivery incref:    rc:1  qdr_link_deliver_to - newly created delivery, add to action list (../src/router_core/delivery.c:112)
      19: 2021-02-08 15:33:33.819810 +0000 ROUTER_CORE (debug) [C1][L1][D132] Delivery incref:    rc:2  qdr_link_deliver_to - protect returned value (../src/router_core/delivery.c:112)
      19: 2021-02-08 15:33:33.819837 +0000 ROUTER_CORE (debug) [C1][L1][D132] Delivery incref:    rc:3  referenced by a pn_delivery (../src/router_core/delivery.c:112)
      19: 2021-02-08 15:33:33.819862 +0000 ROUTER_CORE (debug) [C1][L1][D132] Delivery decref:    rc:2  release protection of return from deliver (../src/router_core/delivery.c:146)
      19: 2021-02-08 15:33:33.819892 +0000 ROUTER_CORE (trace) Core action 'link_deliver' (../src/router_core/router_core_thread.c:238)
      19: 2021-02-08 15:33:33.819956 +0000 ROUTER_CORE (debug) [C1][L1][D132] Delivery incref:    rc:3  qdr_delivery_update_disposition - add to action list (../src/router_core/delivery.c:112)
      19: 2021-02-08 15:33:33.819995 +0000 ROUTER_CORE (debug) [C1][L1][D132] Delivery decref:    rc:3  removed reference from pn_delivery (../src/router_core/delivery.c:146)
      19: 2021-02-08 15:33:33.820024 +0000 ROUTER_CORE (debug) [C1][L1][D132] Delivery incref:    rc:4  qdr_forward_on_message_CT - adding to general work item (../src/router_core/delivery.c:112)
      19: 2021-02-08 15:33:33.820093 +0000 ROUTER_CORE (debug) [C1][L1][D132] Delivery decref_CT: rc:2 qdr_link_forward_CT - removed from action (2) (../src/router_core/delivery.c:639)
      19: 2021-02-08 15:33:33.820137 +0000 ROUTER_CORE (trace) Core action 'update_delivery' (../src/router_core/router_core_thread.c:238)
      19: 2021-02-08 15:33:33.820164 +0000 ROUTER_CORE (trace) [C1][L1][D132] Remote updated mcast delivery disp=0x0 settled=True (../src/router_core/delivery.c:791)
      19: 2021-02-08 15:33:33.820184 +0000 ROUTER_CORE (debug) [C1][L1][D132] Delivery decref_CT: rc:1 qdr_update_delivery_CT - remove from action (../src/router_core/delivery.c:639)
      19: 2021-02-08 15:33:33.820247 +0000 HTTP (trace) lws_context_destroy: ctx 0x620000013080 (../src/http-libwebsockets.c:61)
      19: 2021-02-08 15:33:33.820277 +0000 HTTP (trace) lws_destroy_event_pipe (../src/http-libwebsockets.c:61)
      19: 2021-02-08 15:33:33.820306 +0000 HTTP (trace) lws_context_destroy2: ctx 0x620000013080 (../src/http-libwebsockets.c:61)
      19: 2021-02-08 15:33:33.820321 +0000 HTTP (trace) 0x7f14c6c9b720: post vh listl (../src/http-libwebsockets.c:61)
      19: 2021-02-08 15:33:33.820334 +0000 HTTP (trace) 0x7f14c6c9b720: post pdl (../src/http-libwebsockets.c:61)
      19: 2021-02-08 15:33:33.820450 +0000 HTTP (trace) 0x7f14c6c9b720: baggage (../src/http-libwebsockets.c:61)
      19: 2021-02-08 15:33:33.820466 +0000 HTTP (trace) 0x7f14c6c9b720: post dc2 (../src/http-libwebsockets.c:61)
      19: 2021-02-08 15:33:33.820481 +0000 HTTP (trace) lws_context_destroy3 (../src/http-libwebsockets.c:61)
      19: 2021-02-08 15:33:33.820604 +0000 HTTP (trace) lws_context_destroy3: ctx 0x620000013080 freed (../src/http-libwebsockets.c:61)
      19: 2021-02-08 15:33:33.820622 +0000 SERVER (notice) Shut Down (../src/server.c:1493)
      19: 2021-02-08 15:33:33.820691 +0000 CONTAINER (trace) Default node removed (../src/container.c:848)
      19: 2021-02-08 15:33:33.820728 +0000 ROUTER_CORE (info) Router Core thread exited (../src/router_core/router_core_thread.c:259)
      19: 2021-02-08 15:33:33.820845 +0000 HTTP_ADAPTOR (trace) Shutting down HTTP2 Protocol adaptor (../src/adaptors/http2/http2_adaptor.c:2444)
      19: 2021-02-08 15:33:33.820875 +0000 TCP_ADAPTOR (info) Shutting down TCP protocol adaptor (../src/adaptors/tcp_adaptor.c:1249)
      19: 2021-02-08 15:33:33.821177 +0000 ROUTER_LS (trace) RCVD: LSR(id=router0 pv=1 area=0) (/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/python/qpid_dispatch_internal/router/engine.py:165)
      19: 2021-02-08 15:33:33.821428 +0000 ROUTER_LS (trace) SENT: LSU(id=router1 pv=1 area=0 inst=1612798405 ls_seq=3 ls=LS(id=router1 area=0 ls_seq=3 peers={'router0': 1})) (/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/python/qpid_dispatch_internal/router/link.py:73)
      19: 2021-02-08 15:33:33.821456 +0000 ROUTER_CORE (debug) [C1][L1][D132] Delivery decref:    rc:0  qdr_forward_on_message - remove from general work (../src/router_core/delivery.c:146)
      19: 2021-02-08 15:33:33.821693 +0000 ROUTER_CORE (info) Finalizing core module: streaming_link_scrubber (../src/router_core/router_core_thread.c:138)
      19: 2021-02-08 15:33:33.821721 +0000 ROUTER_CORE (info) Finalizing core module: mobile_sync (../src/router_core/router_core_thread.c:138)
      19: 2021-02-08 15:33:33.821738 +0000 ROUTER_CORE (info) Finalizing core module: stuck_delivery_detection (../src/router_core/router_core_thread.c:138)
      19: 2021-02-08 15:33:33.821752 +0000 ROUTER_CORE (info) Finalizing core module: address_lookup_client (../src/router_core/router_core_thread.c:138)
      19: 2021-02-08 15:33:33.821767 +0000 ROUTER_CORE (info) Finalizing core module: address_lookup_server (../src/router_core/router_core_thread.c:138)
      19: 2021-02-08 15:33:33.821781 +0000 ROUTER_CORE (info) Finalizing core module: edge_addr_tracking (../src/router_core/router_core_thread.c:138)
      19: 2021-02-08 15:33:33.821856 +0000 SERVER (info) [C1] Closing connection on shutdown (../src/server.c:1377)
      19: 2021-02-08 15:33:33.821883 +0000 SERVER (info) [C4] Closing connection on shutdown (../src/server.c:1377)
      19: 2021-02-08 15:33:33.821900 +0000 SERVER (info) [C6] Closing connection on shutdown (../src/server.c:1377)
      19: 2021-02-08 15:33:33.821917 +0000 SERVER (info) [C8] Closing connection on shutdown (../src/server.c:1377)
      19: 
      19: <<<<
       9/37 Test #17: system_tests_autolinks .........................   Passed   17.44 sec
      test 21
            Start 21: system_tests_handle_failover21: Test command: /usr/bin/bwrap "--bind" "/" "/" "--unshare-net" "--dev" "/dev" "--die-with-parent" "--" "/opt/hostedtoolcache/Python/3.7.9/x64/bin/python" "/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/build/tests/run.py" "-m" "unittest" "-v" "system_tests_handle_failover"
      21: Test timeout computed to be: 600
      19: ERROR
      19: 
      19: ======================================================================
      19: ERROR: tearDownClass (system_tests_management.ManagementTest)
      19: ----------------------------------------------------------------------
      19: Traceback (most recent call last):
      19:   File "/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/tests/system_test.py", line 839, in tearDownClass
      19:     cls.tester.teardown()
      19:   File "/home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/tests/system_test.py", line 782, in teardown
      19:     raise RuntimeError("Errors during teardown: \n\n%s" % "\n\n".join([str(e) for e in errors]))
      19: RuntimeError: Errors during teardown: 
      19: 
      19: Process 2431 error: exit code -6, expected 0
      19: qdrouterd -c router1.conf -I /home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/python
      19: /home/runner/work/qpid-dispatch/qpid-dispatch/qpid-dispatch/build/tests/system_test.dir/system_tests_management/ManagementTest/setUpClass/router1-3.cmd
      19: >>>>
      19: ERROR: Aborted due to unexpected alloc pool leak of type 'qd_bitmask_t'
      19: <<<<
      19: 
      19: ---------------------------------------------------------------------- 

      Attachments

        Activity

          People

            Unassigned Unassigned
            gmurthy Ganesh Murthy
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: