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

[http2] system_tests_grpc fails asan with one leaking http2 buffer

    XMLWordPrintableJSON

    Details

    • Type: Improvement
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 1.17.0
    • Component/s: None
    • Labels:
      None

      Description

      70: Test command: /usr/bin/python3.8 "/home/travis/build/apache/qpid-dispatch/build/tests/run.py" "-m" "unittest" "-v" "system_tests_grpc"
      70: Test timeout computed to be: 1200
      70: test_grpc_01_unary (system_tests_grpc.GrpcServiceMethodsTest)
      70: Validates unary request and response message ... ok
      70: test_grpc_02_bidirectional_stream (system_tests_grpc.GrpcServiceMethodsTest)
      70: Validates bidirectional streaming request and response messages ... ok
      70: test_grpc_03_server_stream (system_tests_grpc.GrpcServiceMethodsTest)
      70: Validates server streaming response messages ... ok
      70: test_grpc_04_client_stream (system_tests_grpc.GrpcServiceMethodsTest)
      70: Validates client streaming request messages ... ok
      70: 
      70: Router QDR output file:
      70: >>>>
      70: ERROR: Aborted due to unexpected alloc pool leak of type 'qd_http2_buffer_t'
      70: 
      70: <<<<
      70: 
      70: Router QDR debug dump file:
      70: >>>>
      70: alloc.c: Items of type 'qd_http2_buffer_t' remain allocated at shutdown: 1
      70: Leak: 2021-07-22 22:58:55.975361 +0000 type: qd_http2_buffer_t address: 0x6290001b3290
      70: qdrouterd(backtrace+0x5b) [0x476feb]
      70: qdrouterd(qd_alloc+0xa50) [0x5703c0]
      70: qdrouterd(qd_http2_buffer+0x24) [0x788284]
      70: qdrouterd(qd_http2_buffer_list_append+0x7c) [0x78847c]
      70: qdrouterd() [0x7bcffa]
      70: /lib/x86_64-linux-gnu/libnghttp2.so.14(nghttp2_session_send+0x49) [0x7fda91cb8c89]
      70: qdrouterd() [0x795631]
      70: qdrouterd() [0x778de3]
      70: qdrouterd() [0x7733a0]
      70: qdrouterd(qd_server_run+0x43c) [0x772d4c]
      70: 
      70: 
      70: <<<<
      70: 
      70: Router QDR output file:
      70: >>>>
      70: ERROR: Aborted due to unexpected alloc pool leak of type 'qd_http2_buffer_t'
      70: 
      70: <<<<
      70: 
      70: Router QDR command file:
      70: >>>>
      70: qdrouterd -c grpc-test-router.conf -I /home/travis/build/apache/qpid-dispatch/python
      70: pid=18491
      70: 
      70: <<<<
      70: 
      70: Router QDR log file tail:
      70: >>>>
      70: 2021-07-22 22:58:55.974624 +0000 HTTP_ADAPTOR (trace) [C1][S25] qdr_http_delivery_update, stream_data->in_dlv == dlv (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:1525)
      70: 2021-07-22 22:58:55.974637 +0000 HTTP_ADAPTOR (trace) [C1][S25] qdr_http_delivery_update, stream_data->status == QD_STREAM_FULLY_CLOSED (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:1532)
      70: 2021-07-22 22:58:55.974654 +0000 HTTP_ADAPTOR (trace) [C1][S25] qdr_http_delivery_update, send_complete=true (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:1540)
      70: 2021-07-22 22:58:55.974670 +0000 ROUTER_CORE (debug) [C1][L53][D51] Delivery decref:    rc:1  HTTP2 adaptor  - qdr_http_delivery_update (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:150)
      70: 2021-07-22 22:58:55.974684 +0000 HTTP_ADAPTOR (trace) [C1][S25] qdr_http_delivery_update, stream_data->status == QD_STREAM_FULLY_CLOSED, calling free_http2_stream_data, send_complete(dlv)=1 (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:1550)
      70: 2021-07-22 22:58:55.974704 +0000 HTTP_ADAPTOR (debug) Adding http request info o_127.0.0.1_examples (/home/travis/build/apache/qpid-dispatch/src/adaptors/http_common.c:697)
      70: 2021-07-22 22:58:55.974742 +0000 HTTP_ADAPTOR (trace) [C1][S25] Freeing stream_data in free_http2_stream_data (615000029c50) (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:353)
      70: 2021-07-22 22:58:55.974760 +0000 ROUTER_CORE (debug) [C1][L52][D50] Delivery decref:    rc:0  HTTP2 adaptor out_dlv - free_http2_stream_data (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:150)
      70: 2021-07-22 22:58:55.974780 +0000 ROUTER_CORE (debug) [C1][L53][D51] Delivery decref:    rc:0  qdr_connection_process - remove from updated list (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:150)
      70: 2021-07-22 22:58:55.974804 +0000 ROUTER_CORE (trace) Core action 'add_http_request_info' (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
      70: 2021-07-22 22:58:55.974861 +0000 HTTP_ADAPTOR (debug) Updated http request info o_127.0.0.1_examples (/home/travis/build/apache/qpid-dispatch/src/adaptors/http_common.c:621)
      70: 2021-07-22 22:58:55.975163 +0000 ROUTER_CORE (trace) Core action 'link_detach' (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
      70: 2021-07-22 22:58:55.975185 +0000 HTTP_ADAPTOR (trace) [C3] PN_RAW_CONNECTION_WAKE Wake-up (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:2426)
      70: 2021-07-22 22:58:55.975207 +0000 ROUTER_CORE (trace) Core action 'link_detach' (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
      70: 2021-07-22 22:58:55.975236 +0000 ROUTER_CORE (trace) Core action 'HTTP2 adaptor out_dlv - free_http2_stream_data' (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
      70: 2021-07-22 22:58:55.975256 +0000 HTTP_ADAPTOR (debug) [C1] handle_incoming_http - Calling nghttp2_session_mem_recv qd_http2_buffer of size 17  (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:2022)
      70: 2021-07-22 22:58:55.975276 +0000 ROUTER_CORE (debug) [C1][L52][D50] Delivery outcome : is accepted (0x24) (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:394)
      70: 2021-07-22 22:58:55.975295 +0000 PROTOCOL (trace) [C1][S0] HTTP2 PING frame received (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:965)
      70: 2021-07-22 22:58:55.975326 +0000 ROUTER_CORE (trace) Core action 'qdr_connection_process - remove from updated list' (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
      70: 2021-07-22 22:58:55.975339 +0000 HTTP_ADAPTOR (trace) [C1] Calling pn_raw_connection_give_read_buffers in grant_read_buffers (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:1388)
      70: 2021-07-22 22:58:55.975357 +0000 ROUTER_CORE (debug) [C1][L53][D51] Delivery outcome : is accepted (0x24) (/home/travis/build/apache/qpid-dispatch/src/router_core/delivery.c:394)
      70: 2021-07-22 22:58:55.975369 +0000 PROTOCOL (trace) [C1] HTTP2 send_callback data length 17 (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:641)
      70: 2021-07-22 22:58:55.975386 +0000 HTTP_ADAPTOR (trace) [C1] Activation triggered, calling pn_raw_connection_wake() (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:1625)
      70: 2021-07-22 22:58:55.975403 +0000 PROTOCOL (trace) [C1] write_buffers pn_raw_connection_write_buffers_capacity=16 (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:277)
      70: 2021-07-22 22:58:55.975420 +0000 ROUTER_CORE (trace) Core action 'link_detach_sent' (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
      70: 2021-07-22 22:58:55.975437 +0000 HTTP_ADAPTOR (trace) [C1] Written 1 buffer(s) and 17 bytes in write_buffers() using pn_raw_connection_write_buffers() (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:311)
      70: 2021-07-22 22:58:55.975455 +0000 ROUTER_CORE (info) [C3][L50] Link detached: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:1087)
      70: 2021-07-22 22:58:55.975475 +0000 HTTP_ADAPTOR (trace) [C1] PN_RAW_CONNECTION_READ Read 17 bytes (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:2432)
      70: 2021-07-22 22:58:55.975492 +0000 ROUTER_CORE (trace) Core action 'link_detach_sent' (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
      70: 2021-07-22 22:58:55.975508 +0000 HTTP_ADAPTOR (trace) [C1] PN_RAW_CONNECTION_WAKE Wake-up (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:2426)
      70: 2021-07-22 22:58:55.975526 +0000 ROUTER_CORE (info) [C3][L51] Link detached: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:1087)
      70: 2021-07-22 22:58:55.975544 +0000 ROUTER_CORE (trace) Core action 'link_detach_sent' (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
      70: 2021-07-22 22:58:55.975557 +0000 ROUTER_CORE (info) [C1][L53] Link detached: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:1087)
      70: 2021-07-22 22:58:55.975595 +0000 SERVER (notice) Shut Down (/home/travis/build/apache/qpid-dispatch/src/server.c:1531)
      70: 2021-07-22 22:58:55.975622 +0000 ROUTER_CORE (trace) Core action 'link_detach_sent' (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:238)
      70: 2021-07-22 22:58:55.975655 +0000 ROUTER_CORE (info) [C1][L52] Link detached: del=1 presett=0 psdrop=0 acc=1 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no (/home/travis/build/apache/qpid-dispatch/src/router_core/connections.c:1087)
      70: 2021-07-22 22:58:55.975703 +0000 CONTAINER (trace) Default node removed (/home/travis/build/apache/qpid-dispatch/src/container.c:853)
      70: 2021-07-22 22:58:55.975748 +0000 ROUTER_CORE (info) Router Core thread exited (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:259)
      70: 2021-07-22 22:58:55.976089 +0000 HTTP_ADAPTOR (trace) Shutting down HTTP2 Protocol adaptor (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:2564)
      70: 2021-07-22 22:58:55.976122 +0000 HTTP_ADAPTOR (info) [C1] Freeing stream_data (stream_dispatcher, qdr_http2_adaptor_final) (61500000b9d0) (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:2572)
      70: 2021-07-22 22:58:55.976149 +0000 HTTP_ADAPTOR (info) [C1] Freeing http2 connection (calling free_qdr_http2_connection) (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:2576)
      70: 2021-07-22 22:58:55.976205 +0000 HTTP_ADAPTOR (trace) [C1] Freeing http2 connection in free_qdr_http2_connection (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:417)
      70: 2021-07-22 22:58:55.976222 +0000 HTTP_ADAPTOR (info) [C3] Freeing http2 connection (calling free_qdr_http2_connection) (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:2576)
      70: 2021-07-22 22:58:55.976258 +0000 HTTP_ADAPTOR (trace) [C3] Freeing http2 connection in free_qdr_http2_connection (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:417)
      70: 2021-07-22 22:58:55.976278 +0000 HTTP_ADAPTOR (info) Deleted HttpListener for examples, 127.0.0.1:21275 (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:2526)
      70: 2021-07-22 22:58:55.976310 +0000 HTTP_ADAPTOR (info) Deleted HttpConnector for examples, 127.0.0.1:21274 (/home/travis/build/apache/qpid-dispatch/src/adaptors/http2/http2_adaptor.c:2498)
      70: 2021-07-22 22:58:55.976352 +0000 TCP_ADAPTOR (info) Shutting down TCP protocol adaptor (/home/travis/build/apache/qpid-dispatch/src/adaptors/tcp_adaptor.c:1770)
      70: 2021-07-22 22:58:55.976511 +0000 ROUTER_CORE (info) Finalizing core module: streaming_link_scrubber (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:138)
      70: 2021-07-22 22:58:55.976535 +0000 ROUTER_CORE (info) Finalizing core module: stuck_delivery_detection (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:138)
      70: 2021-07-22 22:58:55.976546 +0000 ROUTER_CORE (info) Finalizing core module: address_lookup_client (/home/travis/build/apache/qpid-dispatch/src/router_core/router_core_thread.c:138)
      70: 
      70: <<<<
      70: ERROR
      70: 
      70: ======================================================================
      70: ERROR: tearDownClass (system_tests_grpc.GrpcServiceMethodsTest)
      70: ----------------------------------------------------------------------
      70: Traceback (most recent call last):
      70:   File "/home/travis/build/apache/qpid-dispatch/tests/system_tests_grpc.py", line 124, in tearDownClass
      70:     super(GrpcServiceMethodsTest, cls).tearDownClass()
      70:   File "/home/travis/build/apache/qpid-dispatch/tests/system_test.py", line 818, in tearDownClass
      70:     cls.tester.teardown()
      70:   File "/home/travis/build/apache/qpid-dispatch/tests/system_test.py", line 761, in teardown
      70:     raise RuntimeError("Errors during teardown: \n\n%s" % "\n\n".join([str(e) for e in errors]))
      70: RuntimeError: Errors during teardown: 
      70: 
      70: Process 18491 error: exit code -6, expected 0
      70: qdrouterd -c grpc-test-router.conf -I /home/travis/build/apache/qpid-dispatch/python
      70: /home/travis/build/apache/qpid-dispatch/build/tests/system_test.dir/system_tests_grpc/GrpcServiceMethodsTest/setUpClass/grpc-test-router-1.cmd
      70: >>>>
      70: ERROR: Aborted due to unexpected alloc pool leak of type 'qd_http2_buffer_t'
      70: <<<<
      70: 
      70: ----------------------------------------------------------------------
      70: Ran 4 tests in 0.258s 

        Attachments

          Activity

            People

            • Assignee:
              gmurthy Ganesh Murthy
              Reporter:
              gmurthy Ganesh Murthy
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: