[DISPATCH-1868] New system test system_tests_grpc is failing on Fedora 33

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 2.0.0
• Fix Version/s: 1.15.0
• Assignee: Ganesh Murthy
• Reporter: Fernando Giorgetti
• Created: 03/Dec/20 19:47
• Updated: 11/Feb/21 17:55
• Resolved: 05/Dec/20 03:33

Description

The new system test sends a few unary gRPC requests.
I am observing that the 2 first requests are working, but the 3rd one is hung.

When it hangs, I see that the 3 requests are flowing through the router logs, but
the 3rd response is not reaching the client application. The router logs shows this:

 

2020-12-03 16:44:08.607380 -0300 HTTP_ADAPTOR (debug) [C3] qdr_http_deliver - call handle_outgoing_http
2020-12-03 16:44:08.607391 -0300 PROTOCOL (trace) [C3] Starting to handle_outgoing_http, the thread id = 498546240
2020-12-03 16:44:08.607401 -0300 PROTOCOL (trace) [C3] Header not sent yet
2020-12-03 16:44:08.607602 -0300 HTTP_ADAPTOR (trace) [C3] Initial SETTINGS frame sent
2020-12-03 16:44:08.607631 -0300 PROTOCOL (trace) [C3][S5] HTTP2 HEADER Outgoing [:status=200]
2020-12-03 16:44:08.607643 -0300 PROTOCOL (trace) [C3][S5] HTTP2 HEADER Outgoing [content-type=application/grpc]
2020-12-03 16:44:08.607652 -0300 PROTOCOL (trace) [C3][S5] HTTP2 HEADER Outgoing [grpc-accept-encoding=identity,deflate,gzip]
2020-12-03 16:44:08.607662 -0300 PROTOCOL (trace) [C3][S5] HTTP2 HEADER Outgoing [accept-encoding=identity,gzip]
2020-12-03 16:44:08.607679 -0300 PROTOCOL (trace) [C3] HTTP2 send_callback data length 27
2020-12-03 16:44:08.607689 -0300 PROTOCOL (trace) [C3] write_buffers pn_raw_connection_write_buffers_capacity=16
2020-12-03 16:44:08.607705 -0300 HTTP_ADAPTOR (trace) [C3] Written 1 buffer(s) and 27 bytes in write_buffers() using pn_raw_connection_write_buffers()
2020-12-03 16:44:08.607718 -0300 PROTOCOL (trace) [C3][S5] Headers submitted
2020-12-03 16:44:08.607732 -0300 PROTOCOL (trace) [C3][S5] Processing message body
2020-12-03 16:44:08.607743 -0300 PROTOCOL (error) [C3][S5] Error submitting data rv=-510
2020-12-03 16:44:08.607753 -0300 PROTOCOL (trace) [C3][S5] Message has no footer
2020-12-03 16:44:08.607763 -0300 PROTOCOL (trace) [C3] Finished handle_outgoing_http, the thread id = 498546240
2020-12-03 16:44:08.607773 -0300 ROUTER_CORE (debug) Delivery decref: dlv:21e7e90 rc:3 link:11 qdr_link_process_deliveries - release local reference - not send_complete
2020-12-03 16:44:08.607843 -0300 HTTP_ADAPTOR (trace) [C3] PN_RAW_CONNECTION_WRITTEN Wrote 27 bytes, DEQ_SIZE(session_data->buffs) = 0
2020-12-03 16:44:08.607862 -0300 HTTP_ADAPTOR (trace) [C3][S5] In restart_streams swapped head and tail streams
2020-12-03 16:44:08.607873 -0300 PROTOCOL (trace) [C3][S5] Restarting stream in restart_streams()
2020-12-03 16:44:08.607882 -0300 PROTOCOL (trace) [C3] Starting to handle_outgoing_http, the thread id = 748737216
2020-12-03 16:44:08.607892 -0300 PROTOCOL (trace) [C3][S5] Headers already submitted, Proceeding with the body
2020-12-03 16:44:08.607902 -0300 PROTOCOL (trace) [C3][S5] Stream was paused, resuming now
2020-12-03 16:44:08.607914 -0300 PROTOCOL (trace) [C3][S5] nghttp2_session_send - write_buffers done for resumed stream
2020-12-03 16:44:08.607924 -0300 PROTOCOL (trace) [C3][S5] Message has no footer
2020-12-03 16:44:08.607934 -0300 PROTOCOL (trace) [C3] Finished handle_outgoing_http, the thread id = 748737216
2020-12-03 16:44:08.607945 -0300 HTTP_ADAPTOR (trace) [C3] PN_RAW_CONNECTION_NEED_WRITE_BUFFERS Need write buffers