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
Improvement
Major
DISPATCH-2292 [http2] system_tests_grpc failed with qd_http2_buffer_t leak