Ganesh Murthy created DISPATCH-2211:
---------------------------------------
Summary: [http2] system_tests_grpc fails asan with one leaking
http2 buffer
Key: DISPATCH-2211
URL: https://issues.apache.org/jira/browse/DISPATCH-2211
Project: Qpid Dispatch
Issue Type: Improvement
Reporter: Ganesh Murthy
Assignee: Ganesh Murthy
{noformat}
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 {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
