[Home]

Summary:ASTERISK-30099: test_aeap_transport: transport_connect_fail sporadically causes failure
Reporter:Kevin Harwell (kharwell)Labels:
Date Opened:2022-06-07 15:51:29Date Closed:2022-07-11 04:10:25
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Resources/res_http_websocket Tests/General
Versions:18.12.0 19.4.0 Frequency of
Occurrence
Occasional
Related
Issues:
Environment:Attachments:
Description:Unit tests in _test_aeap_transport.c_ that follow the {{transport_connect_fail}}  test occasionally fail:
{noformat}
06:03:03  START  /res/aeap/transport/ - transport_create_invalid
06:03:03  END    /res/aeap/transport/ - transport_create_invalid Time: <1ms Result: PASS
06:03:03  START  /res/aeap/transport/ - transport_create
06:03:03  END    /res/aeap/transport/ - transport_create Time: <1ms Result: PASS
06:03:03  START  /res/aeap/transport/ - transport_connect
06:03:03  [Jun  7 11:03:03] ERROR[29881]: res_aeap/transport.c:36 aeap_transport_create: AEAP transport: failed to create for type 'invalid'
06:03:03  END    /res/aeap/transport/ - transport_connect Time: 1ms Result: PASS
06:03:03  START  /res/aeap/transport/ - transport_connect_fail
06:03:03  [Jun  7 11:03:03] ERROR[29881]: res_http_websocket.c:1290 websocket_client_handle_response_code: Received response 404 - Request URL not found - from 127.0.0.1:8088
06:03:03  [Jun  7 11:03:03] ERROR[29881]: res_aeap/transport_websocket.c:51 websocket_connect: AEAP websocket (0x45f36e0): connect failure (8)
06:03:03  [Jun  7 11:03:03] WARNING[30633]: res_http_websocket.c:866 __ast_websocket_uri_cb: WebSocket connection from '127.0.0.1:60612' could not be accepted - no protocols out of 'invalid' supported
06:03:03  [Jun  7 11:03:03] ERROR[29881]: res_http_websocket.c:1286 websocket_client_handle_response_code: Received response 400 - Bad Request - from 127.0.0.1:8088
06:03:03  END    /res/aeap/transport/ - transport_connect_fail Time: 1ms Result: PASS
06:03:03  START  /res/aeap/transport/ - transport_binary
06:03:03  [Jun  7 11:03:03] ERROR[29881]: res_aeap/transport_websocket.c:51 websocket_connect: AEAP websocket (0x46d0630): connect failure (7)
06:03:03  [Jun  7 11:03:03] ERROR[29881]: res_http_websocket.c:1312 websocket_client_handshake_get_response: Unable to retrieve HTTP status line.
06:03:03  [test_aeap_transport.c:transport_binary:169]: Condition failed: (transport = aeap_transport_create_and_connect( TRANSPORT_URL, TRANSPORT_URL, TRANSPORT_PROTOCOL, TRANSPORT_TIMEOUT))
06:03:03  END    /res/aeap/transport/ - transport_binary Time: <1ms Result: FAIL
06:03:03  START  /res/aeap/transport/ - transport_string
06:03:03  [Jun  7 11:03:03] ERROR[29881]: res_aeap/transport_websocket.c:51 websocket_connect: AEAP websocket (0x4702f60): connect failure (5)
06:03:03  [Jun  7 11:03:03] WARNING[30634]: res_http_websocket.c:559 ws_safe_read: Web socket closed abruptly
06:03:03  [Jun  7 11:03:03] WARNING[30634]: res_http_websocket.c:1025 websocket_echo_callback: Read failure during WebSocket echo loop
{noformat}
This was caught on Jenkins, but unfortunately I am no longer able to replicate the problem on my local machine.

I _think_ it has something to do with the {{transport_connect_fail}} test sometimes not cleaning things up fast enough upon a "bad request". A subsequent test attempting to connect then fails.

To test this theory I've commented out the potentially offending code in the test. If that ends up being the cause hopefully it'll help point in a direction to go for a real fix.
Comments:By: Friendly Automation (friendly-automation) 2022-07-11 04:10:26.528-0500

Change 18720 merged by Joshua Colp:
websocket / aeap: Handle poll() interruptions better.

[https://gerrit.asterisk.org/c/asterisk/+/18720|https://gerrit.asterisk.org/c/asterisk/+/18720]

By: Friendly Automation (friendly-automation) 2022-07-11 04:10:44.960-0500

Change 18693 merged by Joshua Colp:
websocket / aeap: Handle poll() interruptions better.

[https://gerrit.asterisk.org/c/asterisk/+/18693|https://gerrit.asterisk.org/c/asterisk/+/18693]

By: Friendly Automation (friendly-automation) 2022-07-11 04:10:55.476-0500

Change 18719 merged by Joshua Colp:
websocket / aeap: Handle poll() interruptions better.

[https://gerrit.asterisk.org/c/asterisk/+/18719|https://gerrit.asterisk.org/c/asterisk/+/18719]