transport close - ping has not timeout #3191

tady21cn · 2018-03-06T11:04:04Z

Note: for support questions, please use one of these channels: stackoverflow or slack

You want to:

report a bug
request a feature

Current behaviour

socket.io will occur "transport close" when i use the internet proxy software.
I want to know the root cause, so open DEBUG model on client and server sides, still no answer after check the log.

remark : the option of client reconnect is closed.

I guessed that:

The part of data packets are lossing
Heartbeat is timeout(i have tried increase the timeout of by the options "pingTimeout" and "pingInterval", but it seems that the effect is not obvious)

server log:
Tue, 06 Mar 2018 10:00:39 GMT socket.io:socket got packet {"type":2,"nsp":"/","data":["message",{"message_id":"msg_sync_mouse_1520330439192","client_id":"p-VZ_JZeeBABWZwYAAAB","type":"sync_mouse","initiator":"5a379898f329915fd2470d72","data":{"user_id":"5a379898f329915fd2470d72","meeting_id":"5a72ba31f329910992b98de0","x":402,"y":-13,"cursor":"default"}}]} Tue, 06 Mar 2018 10:00:39 GMT socket.io:socket emitting event ["message",{"message_id":"msg_sync_mouse_1520330439192","client_id":"p-VZ_JZeeBABWZwYAAAB","type":"sync_mouse","initiator":"5a379898f329915fd2470d72","data":{"user_id":"5a379898f329915fd2470d72","meeting_id":"5a72ba31f329910992b98de0","x":402,"y":-13,"cursor":"default"}}] Tue, 06 Mar 2018 10:00:39 GMT socket.io:socket dispatching an event ["message",{"message_id":"msg_sync_mouse_1520330439192","client_id":"p-VZ_JZeeBABWZwYAAAB","type":"sync_mouse","initiator":"5a379898f329915fd2470d72","data":{"user_id":"5a379898f329915fd2470d72","meeting_id":"5a72ba31f329910992b98de0","x":402,"y":-13,"cursor":"default"}}] Tue, 06 Mar 2018 10:00:39 GMT socket.io:client client close with reason transport close Tue, 06 Mar 2018 10:00:39 GMT socket.io:socket closing socket - reason transport close Tue, 06 Mar 2018 10:00:39 GMT socket.io:socket leave room 5a72ba31f329910992b98de0 Tue, 06 Mar 2018 10:00:39 GMT socket.io:socket left room 5a72ba31f329910992b98de0

client log:
browser.js:133 engine.io-client:socket flushing 1 packets in socket +15ms 18:00:39.425 browser.js:123 socket.io-client:manager writing packet {"type":2,"data":["message",{"message_id":"msg_sync_mouse_1520330439426","client_id":"p-VZ_JZeeBABWZwYAAAB","type":"sync_mouse","initiator":"5a379898f329915fd2470d72","data":{"user_id":"5a379898f329915fd2470d72","meeting_id":"5a72ba31f329910992b98de0","x":439,"y":62,"cursor":"default"}}],"options":{"compress":true},"nsp":"/"} +18ms 18:00:39.425 browser.js:133 socket.io-parser encoding packet {"type":2,"data":["message",{"message_id":"msg_sync_mouse_1520330439426","client_id":"p-VZ_JZeeBABWZwYAAAB","type":"sync_mouse","initiator":"5a379898f329915fd2470d72","data":{"user_id":"5a379898f329915fd2470d72","meeting_id":"5a72ba31f329910992b98de0","x":439,"y":62,"cursor":"default"}}],"options":{"compress":true},"nsp":"/"} +17ms 18:00:39.426 browser.js:133 socket.io-parser encoded {"type":2,"data":["message",{"message_id":"msg_sync_mouse_1520330439426","client_id":"p-VZ_JZeeBABWZwYAAAB","type":"sync_mouse","initiator":"5a379898f329915fd2470d72","data":{"user_id":"5a379898f329915fd2470d72","meeting_id":"5a72ba31f329910992b98de0","x":439,"y":62,"cursor":"default"}}],"options":{"compress":true},"nsp":"/"} as 2["message",{"message_id":"msg_sync_mouse_1520330439426","client_id":"p-VZ_JZeeBABWZwYAAAB","type":"sync_mouse","initiator":"5a379898f329915fd2470d72","data":{"user_id":"5a379898f329915fd2470d72","meeting_id":"5a72ba31f329910992b98de0","x":439,"y":62,"cursor":"default"}}] +0ms 18:00:39.426 browser.js:133 engine.io-client:socket flushing 1 packets in socket +17ms 18:00:39.429 browser.js:133 engine.io-client:socket socket close with reason: "transport close" +3ms 18:00:39.429 browser.js:123 socket.io-client:manager onclose +4ms 18:00:39.430 browser.js:123 socket.io-client:manager cleanup +0ms 18:00:39.430 browser.js:123 socket.io-client:socket close (transport close) +1ms

Steps to reproduce (if the current behaviour is a bug)

Note: the best way to get a quick answer is to provide a failing test case, by forking the following fiddle for example.

Expected behaviour

to find out the reason, avoid "transport close"

Setup

OS:mac ox
browser:chorme
socket.io version:2.0.4

Other information (e.g. stacktraces, related issues, suggestions how to fix)

The text was updated successfully, but these errors were encountered:

tady21cn · 2018-03-06T11:45:57Z

add client log again.
transport close but ping has not timeout.

darrachequesne · 2018-05-02T11:22:31Z

@tady21cn it seems the ping has failed. What is the status of the request in the Network panel?

RachunCh · 2018-08-07T03:38:43Z

I'm having same issue. Did you solve this problem, please?

ViniciusPaldes · 2019-04-02T09:48:19Z

Someone has any updates on this issue?

FaizanZahid · 2019-05-23T12:27:23Z

still facing same issue on "socket.io": "2.2.0",
"socket.io-client": "2.2.0",

socket.io-client:socket close (ping timeout) +22s

vinaymuley96 · 2019-12-09T13:36:02Z

Still facing issue on "socket.io": "2.3.0"
"socket.io-client":"2.3.0"

Client randomly disconnects with reason transport close and reason on server is ping timeout.
disconnect event is triggered only when client is receiving data continuously. I have tried changing ping interval and ping timeout on both client and server.

The socket is stable and ping/pong events are triggered as expected.

I didn't faced any issues on both client and server on version 2.0.3. I have tried degrading the version to 2.0.3 and everything worked without any disconnect event

HZSamir · 2019-12-16T08:37:00Z

I second @vinaymuley96
Socket.io 2.3.0 would throw transport error after a few seconds of inactivity on React-native Android (with the app closed and the socket being inside a headless script). Downgrading to 2.0.3 seems to have fixed this.

CuteShaun · 2020-08-31T21:38:38Z

@vinaymuley96 @Unforgiven-wanda
The same problem, downgrading from 2.3.0 to 2.0.3 seems to have fixed this, thanks guys, you saved my time 👍

kevinwaelkens · 2020-09-24T10:19:00Z

Downgrading to 2.0.3 did not solve this for me. Still running into this issue, created a Stackoverflow question for this. Sometimes it works, sometimes it doesn't. The most recent update I have is the difference in the logging of socket.io when it works vs when it doesn't

Left is the case where it doesn't work, right is the case where it does work. Can we track down issues from these logs?

darrachequesne · 2020-10-05T10:39:49Z

OK, let's try to find the needle...

transport close is emitted here: https://github.com/socketio/engine.io-client/blob/3.4.4/lib/socket.js#L283-L285 and reemitted here: https://github.com/socketio/engine.io-client/blob/3.4.4/lib/socket.js#L725

The close event is emitted here: https://github.com/socketio/engine.io-client/blob/3.4.4/lib/transport.js#L158-L161

The Transport#onClose method is called:

for the WebSocket transport: https://github.com/socketio/engine.io-client/blob/3.4.4/lib/transports/websocket.js#L156-L158

Which would mean that either the WebSocket connection is severed (the client looses connection) or the server forcefully closes the connection (here).

for the HTTP long-polling transport: https://github.com/socketio/engine.io-client/blob/3.4.4/lib/transports/polling.js#L138-L141

In that case, the server also forcefully closes the connection by sending a 'close' packet (here).

Which brings us to Socket.clearTransport and finally Socket.onClose on the server side.

Several possibilities here:

parse error: a parsing error
ping timeout: a ping timeout (the server did not receive the ping packet in time)
transport error: something bad happened to the connection (HTTP long-polling or WebSocket)
forced close: the server is stopping
transport close: the transport was closed cleanly (which can only happen with WebSocket)

It would be interesting to have the Engine.IO server logs, to understand why the server closes the connection.

If it's a ping timeout, it could be a case of delayed timer on the client. Which is why the heartbeat mechanism will be reverted (server sends a ping, and client responds with a pong) in Socket.IO v3.

kevinwaelkens · 2020-10-05T14:30:02Z

@darrachequesne Can I be of help to figure out those Engine.IO server logs? Not exactly sure right now if I can still provide some helpful info.

I have been able to get my chat working without noticing the POST instead of GET difference (from my screenshot earlier). I thought that was a crucial part for it to work. However, I also have an example where the polling uses POST instead of GET.

This is a diffcheck between two working examples.

If I can still be of help figuring this out, or help providing info, let me know! Thanks for putting your attention on this :)

darrachequesne · 2020-10-06T20:29:45Z

POST requests are used to send data when in polling mode (more information here), so they are expected.

@kevinwaelkens are you able to reproduce the issue? under which conditions?

Note: could you please provide the logs as plain text instead of an image? Thanks!

sebastianfelipe · 2020-12-14T18:30:12Z

Is still happening

kevinwaelkens · 2021-06-14T22:46:27Z

@darrachequesne

These were the logs of a not-working environment (couldn't pin point what exactly made the difference)

  socket.io:server initializing namespace / +0ms
  socket.io-parser encoding packet {"type":0,"nsp":"/"} +0ms
  socket.io-parser encoded {"type":0,"nsp":"/"} as 0 +0ms
  socket.io:server creating engine.io instance with opts {"path":"/socket.io","initialPacket":["0"]} +1ms
  socket.io:server attaching client serving req handler +39ms
  engine intercepting request for path "/socket.io/" +0ms
  engine handling "GET" http request "/socket.io/?EIO=3&transport=polling&t=NIeBUJ9" +0ms
  engine handshaking client "4H-IpKU9ByLaXFZkAAAA" +3ms
  engine:socket sending packet "open" ({"sid":"4H-IpKU9ByLaXFZkAAAA","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":60000}) +0ms
  engine:socket sending packet "message" ([ '0' ]) +0ms
  engine:polling setting request +0ms
  engine:socket flushing buffer to transport +2ms
  engine:polling writing "97:0{"sid":"4H-IpKU9ByLaXFZkAAAA","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":60000}2:40" +1ms
  engine:socket executing batch send callback +6ms
  socket.io:server incoming connection with id 4H-IpKU9ByLaXFZkAAAA +10s
  socket.io:client connecting to namespace / +1ms
  socket.io:namespace adding socket to nsp / +0ms
  socket.io:socket socket connected - writing packet +2ms
  socket.io:socket joining room 4H-IpKU9ByLaXFZkAAAA +1ms
  socket.io:socket packet already sent in initial handshake +0ms
Connected: 4H-IpKU9ByLaXFZkAAAA
  socket.io:socket joined room [ '4H-IpKU9ByLaXFZkAAAA' ] +1ms
  engine intercepting request for path "/socket.io/" +21s
  engine handling "GET" http request "/socket.io/?EIO=3&transport=polling&t=NIeBZUT" +0ms
  engine handshaking client "M3PZY977msXP-JreAAAB" +1ms
  engine:socket sending packet "open" ({"sid":"M3PZY977msXP-JreAAAB","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":60000}) +21s
  engine:socket sending packet "message" ([ '0' ]) +0ms
  engine:polling setting request +21s
  engine:socket flushing buffer to transport +0ms
  engine:polling writing "97:0{"sid":"M3PZY977msXP-JreAAAB","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":60000}2:40" +1ms
  engine:socket executing batch send callback +1ms
  socket.io:server incoming connection with id M3PZY977msXP-JreAAAB +21s
  socket.io:client connecting to namespace / +0ms
  socket.io:namespace adding socket to nsp / +0ms
  socket.io:socket socket connected - writing packet +0ms
  socket.io:socket joining room M3PZY977msXP-JreAAAB +0ms
  socket.io:socket packet already sent in initial handshake +0ms
Connected: M3PZY977msXP-JreAAAB
  socket.io:socket joined room [ 'M3PZY977msXP-JreAAAB' ] +1ms
  engine intercepting request for path "/socket.io/" +21s
  engine handling "GET" http request "/socket.io/?EIO=3&transport=polling&t=NIeBef7" +0ms
  engine handshaking client "48q2S3j64VNsGsPVAAAC" +0ms
  engine:socket sending packet "open" ({"sid":"48q2S3j64VNsGsPVAAAC","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":60000}) +21s
  engine:socket sending packet "message" ([ '0' ]) +0ms
  engine:polling setting request +21s
  engine:socket flushing buffer to transport +1ms
  engine:polling writing "97:0{"sid":"48q2S3j64VNsGsPVAAAC","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":60000}2:40" +0ms
  engine:socket executing batch send callback +0ms
  socket.io:server incoming connection with id 48q2S3j64VNsGsPVAAAC +21s
  socket.io:client connecting to namespace / +0ms
  socket.io:namespace adding socket to nsp / +0ms
  socket.io:socket socket connected - writing packet +0ms
  socket.io:socket joining room 48q2S3j64VNsGsPVAAAC +0ms
  socket.io:socket packet already sent in initial handshake +0ms
Connected: 48q2S3j64VNsGsPVAAAC
  socket.io:socket joined room [ '48q2S3j64VNsGsPVAAAC' ] +1ms

These were two logs when it did work

nodemon watch is complete +20ms
  socket.io:server initializing namespace / +0ms
  socket.io-parser encoding packet {"type":0,"nsp":"/"} +0ms
  socket.io-parser encoded {"type":0,"nsp":"/"} as 0 +0ms
  socket.io:server creating engine.io instance with opts {"path":"/socket.io","initialPacket":["0"]} +2ms
  socket.io:server attaching client serving req handler +58ms
  engine intercepting request for path "/socket.io/" +0ms
  engine handling "GET" http request "/socket.io/?EIO=3&transport=polling&t=NIyVoAa" +0ms
  engine handshaking client "QPv3VvIuFHr9ckOKAAAA" +3ms
  engine:socket sending packet "open" ({"sid":"QPv3VvIuFHr9ckOKAAAA","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":60000}) +0ms
  engine:socket sending packet "message" ([ '0' ]) +0ms
  engine:polling setting request +0ms
  engine:socket flushing buffer to transport +1ms
  engine:polling writing "97:0{"sid":"QPv3VvIuFHr9ckOKAAAA","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":60000}2:40" +1ms
  engine:socket executing batch send callback +17ms
  socket.io:server incoming connection with id QPv3VvIuFHr9ckOKAAAA +32s
  socket.io:client connecting to namespace / +0ms
  socket.io:namespace adding socket to nsp / +1ms
  socket.io:socket socket connected - writing packet +3ms
  socket.io:socket joining room QPv3VvIuFHr9ckOKAAAA +0ms
  socket.io:socket packet already sent in initial handshake +0ms
Connected: QPv3VvIuFHr9ckOKAAAA
  socket.io:socket joined room [ 'QPv3VvIuFHr9ckOKAAAA' ] +1ms
  engine intercepting request for path "/socket.io/" +34ms
  engine handling "POST" http request "/socket.io/?EIO=3&transport=polling&t=NIyVoBQ&sid=QPv3VvIuFHr9ckOKAAAA" +0ms
  engine setting new request for existing client +1ms
  engine:polling received "10:42["join"]" +35ms
  engine:socket packet +19ms
  socket.io-parser decoded 2["join"] as {"type":2,"nsp":"/","data":["join"]} +33s
  socket.io:socket got packet {"type":2,"nsp":"/","data":["join"]} +16ms
  socket.io:socket emitting event ["join"] +0ms
  socket.io:socket dispatching an event ["join"] +0ms
Socket QPv3VvIuFHr9ckOKAAAA joining
  socket.io:socket joining room undefined +1ms
  socket.io:socket joined room [ undefined ] +0ms
  engine intercepting request for path "/socket.io/" +8ms
  engine handling "GET" http request "/socket.io/?EIO=3&transport=polling&t=NIyVoBR&sid=QPv3VvIuFHr9ckOKAAAA" +0ms
  engine setting new request for existing client +0ms
  engine:polling setting request +5ms
  engine upgrading existing transport +4ms
  engine:socket might upgrade socket transport from "polling" to "websocket" +9ms
  engine:ws received "2probe" +0ms
  engine:ws writing "3probe" +1ms
  engine:socket writing a noop packet to polling for fast upgrade +125ms
  engine:polling writing "1:6" +130ms
  engine:ws received "5" +109ms
  engine:socket got upgrade packet - upgrading +6ms
  engine:polling closing +5ms
  engine:polling transport discarded - closing right away +0ms
  engine:ws received "42["chatMessage",{"message":"Weer"}]" +8s
  engine:socket packet +8s
  socket.io-parser decoded 2["chatMessage",{"message":"Weer"}] as {"type":2,"nsp":"/","data":["chatMessage",{"message":"Weer"}]} +8s
  socket.io:socket got packet {"type":2,"nsp":"/","data":["chatMessage",{"message":"Weer"}]} +8s
  socket.io:socket emitting event ["chatMessage",{"message":"Weer"}] +0ms
  socket.io:socket dispatching an event ["chatMessage",{"message":"Weer"}] +0ms
  socket.io-parser encoding packet {"type":2,"data":["chatMessage","Weer"],"nsp":"/"} +0ms
  socket.io-parser encoded {"type":2,"data":["chatMessage","Weer"],"nsp":"/"} as 2["chatMessage","Weer"] +0ms
  socket.io:client writing packet ["2[\"chatMessage\",\"Weer\"]"] +1ms
  engine:socket sending packet "message" (2["chatMessage","Weer"]) +1ms
  engine:socket flushing buffer to transport +0ms
  engine:ws writing "42["chatMessage","Weer"]" +2ms
  engine:ws received "42["chatMessage",{"message":"Ewrwe"}]" +951ms
  engine:socket packet +951ms
  socket.io-parser decoded 2["chatMessage",{"message":"Ewrwe"}] as {"type":2,"nsp":"/","data":["chatMessage",{"message":"Ewrwe"}]} +952ms
  socket.io:socket got packet {"type":2,"nsp":"/","data":["chatMessage",{"message":"Ewrwe"}]} +952ms
  socket.io:socket emitting event ["chatMessage",{"message":"Ewrwe"}] +0ms
  socket.io:socket dispatching an event ["chatMessage",{"message":"Ewrwe"}] +0ms
  socket.io-parser encoding packet {"type":2,"data":["chatMessage","Ewrwe"],"nsp":"/"} +1ms
  socket.io-parser encoded {"type":2,"data":["chatMessage","Ewrwe"],"nsp":"/"} as 2["chatMessage","Ewrwe"] +0ms
  socket.io:client writing packet ["2[\"chatMessage\",\"Ewrwe\"]"] +0ms
  engine:socket sending packet "message" (2["chatMessage","Ewrwe"]) +1ms
  engine:socket flushing buffer to transport +0ms
  engine:ws writing "42["chatMessage","Ewrwe"]" +1ms
  engine:ws received "2" +16s
  engine:socket packet +16s
  engine:socket got ping +1ms
  engine:socket sending packet "pong" (undefined) +0ms
  engine:socket flushing buffer to transport +0ms
  engine:ws writing "3" +1ms
  engine:ws received "2" +25s
  engine:socket packet +25s
  engine:socket got ping +0ms
  engine:socket sending packet "pong" (undefined) +0ms
  engine:socket flushing buffer to transport +0ms

socket.io:server initializing namespace / +0ms
  socket.io-parser encoding packet {"type":0,"nsp":"/"} +0ms
  socket.io-parser encoded {"type":0,"nsp":"/"} as 0 +0ms
  socket.io:server creating engine.io instance with opts {"path":"/socket.io","initialPacket":["0"]} +2ms
  socket.io:server attaching client serving req handler +37ms
  engine intercepting request for path "/socket.io/" +0ms
  engine handling "GET" http request "/socket.io/?EIO=3&transport=polling&t=NJRGzDQ" +0ms
  engine handshaking client "MbD37-DcEnmcfNnNAAAA" +3ms
  engine:socket sending packet "open" ({"sid":"MbD37-DcEnmcfNnNAAAA","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":60000}) +0ms
  engine:socket sending packet "message" ([ '0' ]) +0ms
  engine:polling setting request +0ms
  engine:socket flushing buffer to transport +1ms
  engine:polling writing "97:0{"sid":"MbD37-DcEnmcfNnNAAAA","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":60000}2:40" +1ms
  engine:socket executing batch send callback +6ms
  socket.io:server incoming connection with id MbD37-DcEnmcfNnNAAAA +358ms
  socket.io:client connecting to namespace / +0ms
  socket.io:namespace adding socket to nsp / +0ms
  socket.io:socket socket connected - writing packet +2ms
  socket.io:socket joining room MbD37-DcEnmcfNnNAAAA +0ms
  socket.io:socket packet already sent in initial handshake +0ms
Connected: MbD37-DcEnmcfNnNAAAA
  socket.io:socket joined room [ 'MbD37-DcEnmcfNnNAAAA' ] +1ms
  engine intercepting request for path "/socket.io/" +13ms
  engine handling "GET" http request "/socket.io/?EIO=3&transport=polling&t=NJRGzDm&sid=MbD37-DcEnmcfNnNAAAA" +0ms
  engine setting new request for existing client +1ms
  engine:polling setting request +11ms
  engine upgrading existing transport +5ms
  engine:socket might upgrade socket transport from "polling" to "websocket" +11ms
  engine:ws received "2probe" +0ms
  engine:ws writing "3probe" +1ms
  engine:socket writing a noop packet to polling for fast upgrade +104ms
  engine:polling writing "1:6" +109ms
  engine:ws received "5" +105ms
  engine:socket got upgrade packet - upgrading +3ms
  engine:polling closing +4ms
  engine:polling transport discarded - closing right away +0ms
  engine:ws received "42["chatMessage",{"message":"Efeg"}]" +8s
  engine:socket packet +8s
  socket.io-parser decoded 2["chatMessage",{"message":"Efeg"}] as {"type":2,"nsp":"/","data":["chatMessage",{"message":"Efeg"}]} +8s
  socket.io:socket got packet {"type":2,"nsp":"/","data":["chatMessage",{"message":"Efeg"}]} +8s
  socket.io:socket emitting event ["chatMessage",{"message":"Efeg"}] +0ms
  socket.io:socket dispatching an event ["chatMessage",{"message":"Efeg"}] +0ms
  socket.io-parser encoding packet {"type":2,"data":["chatMessage","Efeg"],"nsp":"/"} +0ms
  socket.io-parser encoded {"type":2,"data":["chatMessage","Efeg"],"nsp":"/"} as 2["chatMessage","Efeg"] +1ms
  socket.io:client writing packet ["2[\"chatMessage\",\"Efeg\"]"] +1ms
  engine:socket sending packet "message" (2["chatMessage","Efeg"]) +2ms
  engine:socket flushing buffer to transport +0ms
  engine:ws writing "42["chatMessage","Efeg"]" +2ms

However, I can't seem to connect anymore. I tried everything both on version 2.3.0, but I can't join a room anymore apparently... It seems like it keeps reconnecting, but gets disconnected within 2s.

These are my latest logs

Disconnected: hsPbSotZdcw0wWqOAAAA
  engine:polling closing +6s
  engine:polling transport not writable - buffering orderly close +0ms
  socket.io:client client close with reason ping timeout +6s
  socket.io:socket closing socket - reason ping timeout +6s
Disconnected: zvWowZulz867tGc_AAAB
  engine intercepting request for path "/socket.io/" +23s
  engine handling "GET" http request "/socket.io/?EIO=3&transport=polling&t=NeCie3R" +0ms
  engine handshaking client "oZP2XT9YLKROZ7LCAAAD" +0ms
  engine:socket sending packet "open" ({"sid":"oZP2XT9YLKROZ7LCAAAD","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":5000}) +23s
  engine:socket sending packet "message" ([ '0' ]) +0ms
  engine:polling setting request +14s
  engine:socket flushing buffer to transport +1ms
  engine:polling writing "96:0{"sid":"oZP2XT9YLKROZ7LCAAAD","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":5000}2:40" +0ms
  engine:socket executing batch send callback +0ms
  socket.io:server incoming connection with id oZP2XT9YLKROZ7LCAAAD +23s
  socket.io:client connecting to namespace / +14s
  socket.io:namespace adding socket to nsp / +23s
  socket.io:socket socket connected - writing packet +14s
  socket.io:socket joining room oZP2XT9YLKROZ7LCAAAD +0ms
  socket.io:socket packet already sent in initial handshake +0ms
Connected: oZP2XT9YLKROZ7LCAAAD
  socket.io:socket joined room [ 'oZP2XT9YLKROZ7LCAAAD' ] +0ms
  engine:polling closing +7s
  engine:polling transport not writable - buffering orderly close +0ms
  socket.io:client client close with reason ping timeout +7s
  socket.io:socket closing socket - reason ping timeout +7s
Disconnected: 80SAmClo56hYe2YCAAAC
  engine intercepting request for path "/socket.io/" +25s
  engine handling "GET" http request "/socket.io/?EIO=3&transport=polling&t=NeCikA5" +0ms
  engine handshaking client "Oc_yDIZiRg7wgg_9AAAE" +0ms
  engine:socket sending packet "open" ({"sid":"Oc_yDIZiRg7wgg_9AAAE","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":5000}) +25s
  engine:socket sending packet "message" ([ '0' ]) +0ms
  engine:polling setting request +18s
  engine:socket flushing buffer to transport +0ms
  engine:polling writing "96:0{"sid":"Oc_yDIZiRg7wgg_9AAAE","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":5000}2:40" +0ms
  engine:socket executing batch send callback +1ms
  socket.io:server incoming connection with id Oc_yDIZiRg7wgg_9AAAE +25s
  socket.io:client connecting to namespace / +18s
  socket.io:namespace adding socket to nsp / +25s
  socket.io:socket socket connected - writing packet +18s
  socket.io:socket joining room Oc_yDIZiRg7wgg_9AAAE +0ms
  socket.io:socket packet already sent in initial handshake +0ms
Connected: Oc_yDIZiRg7wgg_9AAAE
  socket.io:socket joined room [ 'Oc_yDIZiRg7wgg_9AAAE' ] +1ms
  engine:polling closing +5s
  engine:polling transport not writable - buffering orderly close +0ms
  socket.io:client client close with reason ping timeout +5s
  socket.io:socket closing socket - reason ping timeout +5s
Disconnected: oZP2XT9YLKROZ7LCAAAD

Without the debug mode, it's a little more clear that there's always alternating between 1 and 2 connections...

> [email protected] start
> nodemon -r esm

[nodemon] 2.0.7
[nodemon] to restart at any time, enter `rs`
[nodemon] watching path(s): *.*
[nodemon] watching extensions: ts,json
[nodemon] starting `ts-node -r esm index.ts`
Connected: W56CHa6IMbSPQHR8AAAA
Connected: DCxAVDPg0E0CwgzPAAAB
Disconnected: W56CHa6IMbSPQHR8AAAA
Connected: EUHPoegr5Rgb0VRuAAAC
Disconnected: DCxAVDPg0E0CwgzPAAAB
Connected: KtO5L8Ya01I8tAAxAAAD
Disconnected: EUHPoegr5Rgb0VRuAAAC
Connected: n01BIj4UYdUj6gk2AAAE
Disconnected: KtO5L8Ya01I8tAAxAAAD

kevinwaelkens · 2021-06-15T22:41:40Z

I created a repository in which you should be able to reproduce this issue. Please let me know if you need any more help setting this up or if I can just provide more information

pbadenski · 2022-01-06T16:17:10Z

Experiencing similar issue, although haven't quite investigated thoroughly. Have anyone been experiencing this or similar issue with socket.io 3.x or 4.x?

darrachequesne · 2022-03-02T05:31:31Z

I'm going to close this issue, as it should be fixed in Socket.IO v3.

See also: https://socket.io/docs/v4/troubleshooting-connection-issues/

Please reopen if needed.

saurabh-iotric · 2024-05-28T06:23:46Z

Stll issue is there in 4.7.5

tady21cn changed the title ~~transport close on using Internet proxy software~~ transport close - ping has not timeout Mar 6, 2018

darrachequesne added the unable to reproduce We were unable to reproduce the issue label Oct 5, 2020

darrachequesne closed this as completed Mar 2, 2022

patrykcieszkowski mentioned this issue May 13, 2022

Probes disconnect too often jsdelivr/globalping#124

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

transport close - ping has not timeout #3191

transport close - ping has not timeout #3191

tady21cn commented Mar 6, 2018

tady21cn commented Mar 6, 2018 •

edited

Loading

darrachequesne commented May 2, 2018

RachunCh commented Aug 7, 2018

ViniciusPaldes commented Apr 2, 2019

FaizanZahid commented May 23, 2019

vinaymuley96 commented Dec 9, 2019

HZSamir commented Dec 16, 2019

CuteShaun commented Aug 31, 2020

kevinwaelkens commented Sep 24, 2020

darrachequesne commented Oct 5, 2020

kevinwaelkens commented Oct 5, 2020

darrachequesne commented Oct 6, 2020

sebastianfelipe commented Dec 14, 2020

kevinwaelkens commented Jun 14, 2021 •

edited

Loading

kevinwaelkens commented Jun 15, 2021

pbadenski commented Jan 6, 2022

darrachequesne commented Mar 2, 2022

saurabh-iotric commented May 28, 2024

transport close - ping has not timeout #3191

transport close - ping has not timeout #3191

Comments

tady21cn commented Mar 6, 2018

You want to:

Current behaviour

Steps to reproduce (if the current behaviour is a bug)

Expected behaviour

Setup

Other information (e.g. stacktraces, related issues, suggestions how to fix)

tady21cn commented Mar 6, 2018 • edited Loading

darrachequesne commented May 2, 2018

RachunCh commented Aug 7, 2018

ViniciusPaldes commented Apr 2, 2019

FaizanZahid commented May 23, 2019

vinaymuley96 commented Dec 9, 2019

HZSamir commented Dec 16, 2019

CuteShaun commented Aug 31, 2020

kevinwaelkens commented Sep 24, 2020

darrachequesne commented Oct 5, 2020

kevinwaelkens commented Oct 5, 2020

darrachequesne commented Oct 6, 2020

sebastianfelipe commented Dec 14, 2020

kevinwaelkens commented Jun 14, 2021 • edited Loading

kevinwaelkens commented Jun 15, 2021

pbadenski commented Jan 6, 2022

darrachequesne commented Mar 2, 2022

saurabh-iotric commented May 28, 2024

tady21cn commented Mar 6, 2018 •

edited

Loading

kevinwaelkens commented Jun 14, 2021 •

edited

Loading