Connection succeeds, even after timeout triggered

[jonathanellis]

Using v15.2.0, even if the connection attempt times out, the socket still ends up connecting.

Example log output (using Network Link Conditioner to simulate poor network conditions, and setting timeout to 1 second to timeout quickly):

2021-02-19 14:31:09.799845+0000 MyApp[1381:531544] LOG SocketIOClient{/example_nsp}: Handling event: statusChange with data: [connecting, 2]
2021-02-19 14:31:09.803316+0000 MyApp[1381:531544] LOG SocketIOClient{/example_nsp}: Joining namespace /example_nsp
2021-02-19 14:31:09.803533+0000 MyApp[1381:531544] LOG SocketManager: Tried connecting socket when engine isn't open. Connecting
2021-02-19 14:31:09.803600+0000 MyApp[1381:531544] LOG SocketManager: Adding engine
2021-02-19 14:31:09.804369+0000 MyApp[1381:531724] LOG SocketEngine: Starting engine. Server: https://example.com
2021-02-19 14:31:09.804470+0000 MyApp[1381:531724] LOG SocketEngine: Handshaking
2021-02-19 14:31:10.875885+0000 MyApp[1381:531544] LOG SocketIOClient{/example_nsp}: Handling event: statusChange with data: [disconnected, 1]

!! at this point, the socket has timed out (1 second) and is disconnected !!

2021-02-19 14:31:11.182737+0000 MyApp[1381:531544] LOG SocketIOClient{/example_nsp}: Handling event: websocketUpgrade with data: [["upgrade": "websocket", "date": "Fri, 19 Feb 2021 14", "sec-websocket-accept": "sGjmeQN8fLmRLNhCNF/IcRqd6Ew=", "sec-websocket-extensions": "permessage-deflate; server_max_window_bits=15", "strict-transport-security": "max-age=15724800; includeSubDomains", "connection": "upgrade", "x-frame-options": "deny"]]
2021-02-19 14:31:11.184991+0000 MyApp[1381:531724] LOG SocketEngine: Got message: 0{"sid":"kxXdF__cmK9_Wd6uABgA","upgrades":[],"pingInterval":25000,"pingTimeout":60000}
2021-02-19 14:31:11.185569+0000 MyApp[1381:531544] LOG SocketIOClient{/example_nsp}: Handling event: ping with data: []
2021-02-19 14:31:11.185578+0000 MyApp[1381:531724] LOG SocketEngine: Got message: 40
2021-02-19 14:31:11.185753+0000 MyApp[1381:531724] LOG SocketEngine: Writing ws:  has data: false
2021-02-19 14:31:11.185852+0000 MyApp[1381:531724] LOG SocketEngineWebSocket: Sending ws:  as type: 2
2021-02-19 14:31:11.187034+0000 MyApp[1381:531544] LOG SocketManager: Engine opened Connect
2021-02-19 14:31:11.187229+0000 MyApp[1381:531544] LOG SocketParser: Parsing 0
2021-02-19 14:31:11.187549+0000 MyApp[1381:531544] LOG SocketParser: Decoded packet as: SocketPacket {type: 0; data: []; id: -1; placeholders: 0; nsp: /}
2021-02-19 14:31:11.418174+0000 MyApp[1381:531699] LOG SocketEngine: Got message: 3
2021-02-19 14:31:11.418726+0000 MyApp[1381:531544] LOG SocketIOClient{/example_nsp}: Handling event: pong with data: []
2021-02-19 14:31:38.643431+0000 MyApp[1381:531544] LOG SocketIOClient{/example_nsp}: Handling event: ping with data: []
2021-02-19 14:31:38.643462+0000 MyApp[1381:531726] LOG SocketEngine: Writing ws:  has data: false
2021-02-19 14:31:38.644005+0000 MyApp[1381:531726] LOG SocketEngineWebSocket: Sending ws:  as type: 2
2021-02-19 14:31:38.878632+0000 MyApp[1381:531726] LOG SocketEngine: Got message: 3
2021-02-19 14:31:38.879325+0000 MyApp[1381:531544] LOG SocketIOClient{/example_nsp}: Handling event: pong with data: []
2021-02-19 14:32:05.160906+0000 MyApp[1381:531544] LOG SocketIOClient{/example_nsp}: Handling event: ping with data: []
2021-02-19 14:32:05.160933+0000 MyApp[1381:531872] LOG SocketEngine: Writing ws:  has data: false
2021-02-19 14:32:05.161143+0000 MyApp[1381:531872] LOG SocketEngineWebSocket: Sending ws:  as type: 2
2021-02-19 14:32:05.393473+0000 MyApp[1381:531872] LOG SocketEngine: Got message: 3
2021-02-19 14:32:05.394313+0000 MyApp[1381:531544] LOG SocketIOClient{/example_nsp}: Handling event: pong with data: []
2021-02-19 14:32:32.640603+0000 MyApp[1381:531544] LOG SocketIOClient{/example_nsp}: Handling event: ping with data: []
2021-02-19 14:32:32.640672+0000 MyApp[1381:531872] LOG SocketEngine: Writing ws:  has data: false
2021-02-19 14:32:32.641154+0000 MyApp[1381:531872] LOG SocketEngineWebSocket: Sending ws:  as type: 2
2021-02-19 14:32:32.881857+0000 MyApp[1381:531872] LOG SocketEngine: Got message: 3
2021-02-19 14:32:32.882675+0000 MyApp[1381:531544] LOG SocketIOClient{/example_nsp}: Handling event: pong with data: []
2021-02-19 14:33:00.023185+0000 MyApp[1381:531544] LOG SocketIOClient{/example_nsp}: Handling event: ping with data: []
2021-02-19 14:33:00.025142+0000 MyApp[1381:531872] LOG SocketEngine: Writing ws:  has data: false
2021-02-19 14:33:00.025391+0000 MyApp[1381:531872] LOG SocketEngineWebSocket: Sending ws:  as type: 2

...and so on, forever...

Surely, once the socket times out, the connection should be aborted? This seems to me like a race condition somewhere...