search

nuclearace / Socket.IO-Client-Swift

socket.io-client for Swift
Other
361 stars 53 forks source link

"Session id unknown" and reconnecting automatically #142

Closed PandaraWen closed 6 years ago

PandaraWen commented 7 years ago

If I try to emit message in callback of socket client's event .connect, in most of cases, socket client will begin reconnecting automatically, sometime it will give an error: Session id unknown.

My code looks like this:

self.socketClient?.on(clientEvent: .connect, callback: { (data, ack) in
    self.socketClient?.emit("message", "my message")
})
PandaraWen commented 7 years ago

But if I delay for 0.1s before emitting message, everything will work well

self.socketClient?.on(clientEvent: .connect, callback: { (data, ack) in
    DispatchQueue.main.asyncAfter(deadline: .now() + 0.1, execute: {
        self.socketClient?.emit("message", "my message")
    }
})
nuclearace commented 7 years ago

Do you have any logs?

PandaraWen commented 7 years ago

Yes, I initialized the client using code below:

self.socketClient = SocketIOClient(socketURL: URL(string: serverURLStr)!, config: [.log(true)])

and these are the logs I got:

2017-06-26 20:01:15.785402+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Adding handler for event: connect
2017-06-26 20:01:15.786186+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Adding handler for event: disconnect
2017-06-26 20:01:15.786388+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Adding handler for event: reconnect
2017-06-26 20:01:15.786554+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Adding handler for event: error
2017-06-26 20:01:15.786835+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Adding handler for event: message
2017-06-26 20:01:17.245521+0800 SocketIOTest[62610:8531583] Start to connect
2017-06-26 20:01:17.246859+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Handling event: statusChange with data: [SocketIO.SocketIOClientStatus]
2017-06-26 20:01:17.247234+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Adding engine
2017-06-26 20:01:17.250783+0800 SocketIOTest[62610:8531661] LOG SocketEngine: Starting engine. Server: http://test.meshtech.co
2017-06-26 20:01:17.251128+0800 SocketIOTest[62610:8531661] LOG SocketEngine: Handshaking
2017-06-26 20:01:17.253723+0800 SocketIOTest[62610:8531661] LOG SocketEnginePolling: Doing polling GET http://test.meshtech.co/socket.io/?transport=polling&b64=1
2017-06-26 20:01:17.613204+0800 SocketIOTest[62610:8532034] LOG SocketEnginePolling: Got polling response
2017-06-26 20:01:17.615228+0800 SocketIOTest[62610:8532034] LOG SocketEnginePolling: Got poll message: 97:0{"sid":"sfBOARfQ3iU552wdAAB3","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":60000}
2017-06-26 20:01:17.620050+0800 SocketIOTest[62610:8532034] LOG SocketEngine: Got message: 0{"sid":"sfBOARfQ3iU552wdAAB3","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":60000}
2017-06-26 20:01:17.636094+0800 SocketIOTest[62610:8532034] LOG SocketEngineClient: Connect
2017-06-26 20:01:17.636763+0800 SocketIOTest[62610:8532034] LOG SocketEnginePolling: Doing polling GET http://test.meshtech.co/socket.io/?transport=polling&b64=1&sid=sfBOARfQ3iU552wdAAB3
2017-06-26 20:01:17.638312+0800 SocketIOTest[62610:8532034] LOG SocketEngine: Writing poll:  has data: false
2017-06-26 20:01:17.638995+0800 SocketIOTest[62610:8532034] LOG SocketEnginePolling: Sending poll:  as type: 2
2017-06-26 20:01:17.643193+0800 SocketIOTest[62610:8532034] LOG SocketEnginePolling: Created POST string: 1:2
2017-06-26 20:01:17.646794+0800 SocketIOTest[62610:8532034] LOG SocketEnginePolling: POSTing
2017-06-26 20:01:17.647877+0800 SocketIOTest[62610:8532034] LOG SocketEnginePolling: Doing polling POST http://test.meshtech.co/socket.io/?transport=polling&b64=1&sid=sfBOARfQ3iU552wdAAB3
2017-06-26 20:01:17.734058+0800 SocketIOTest[62610:8532034] LOG SocketEnginePolling: Got polling response
2017-06-26 20:01:17.734329+0800 SocketIOTest[62610:8532034] LOG SocketEnginePolling: Got poll message: 2:40
2017-06-26 20:01:17.734608+0800 SocketIOTest[62610:8532034] LOG SocketEngine: Got message: 40
2017-06-26 20:01:17.734872+0800 SocketIOTest[62610:8532034] LOG SocketIOClient: Should parse message: 0
2017-06-26 20:01:17.735235+0800 SocketIOTest[62610:8531583] LOG SocketParser: Parsing 0
2017-06-26 20:01:17.735245+0800 SocketIOTest[62610:8532034] LOG SocketEnginePolling: Doing polling GET http://test.meshtech.co/socket.io/?transport=polling&b64=1&sid=sfBOARfQ3iU552wdAAB3
2017-06-26 20:01:17.736242+0800 SocketIOTest[62610:8531583] LOG SocketParser: Decoded packet as: SocketPacket {type: 0; data: []; id: -1; placeholders: 0; nsp: /}
2017-06-26 20:01:17.736911+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Socket connected
2017-06-26 20:01:17.737101+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Handling event: statusChange with data: [SocketIO.SocketIOClientStatus]
2017-06-26 20:01:17.737239+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Handling event: connect with data: []
2017-06-26 20:01:17.740450+0800 SocketIOTest[62610:8531583] WebSocket connected,
 data:[],
 ack:<SocketIO.SocketAckEmitter: 0x608000625660>
2017-06-26 20:01:17.745667+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Emitting: 2(my message here)
2017-06-26 20:01:17.748549+0800 SocketIOTest[62610:8531661] LOG SocketEngine: Writing poll: 2(my message here) has data: false
2017-06-26 20:01:17.748821+0800 SocketIOTest[62610:8531661] LOG SocketEnginePolling: Sending poll: 2(my message here) as type: 4
2017-06-26 20:01:17.777656+0800 SocketIOTest[62610:8532034] LOG SocketEngine: Sending ws: probe as type: 2
2017-06-26 20:01:17.879019+0800 SocketIOTest[62610:8531660] LOG SocketEnginePolling: Got polling response
2017-06-26 20:01:17.879563+0800 SocketIOTest[62610:8531660] LOG SocketEnginePolling: Got poll message: 1:3
2017-06-26 20:01:17.879863+0800 SocketIOTest[62610:8531660] LOG SocketEngine: Got message: 3
2017-06-26 20:01:17.880144+0800 SocketIOTest[62610:8531660] LOG SocketEnginePolling: Doing polling GET http://test.meshtech.co/socket.io/?transport=polling&b64=1&sid=sfBOARfQ3iU552wdAAB3
2017-06-26 20:01:17.880498+0800 SocketIOTest[62610:8531660] LOG SocketEnginePolling: Created POST string: 317:42(my message here)
2017-06-26 20:01:17.880768+0800 SocketIOTest[62610:8531660] LOG SocketEnginePolling: POSTing
2017-06-26 20:01:17.881024+0800 SocketIOTest[62610:8531660] LOG SocketEnginePolling: Doing polling POST http://test.meshtech.co/socket.io/?transport=polling&b64=1&sid=sfBOARfQ3iU552wdAAB3
2017-06-26 20:01:17.890408+0800 SocketIOTest[62610:8531661] LOG SocketEngine: Got message: 3probe
2017-06-26 20:01:17.890661+0800 SocketIOTest[62610:8531661] LOG SocketEngine: Upgrading transport to WebSockets
2017-06-26 20:01:17.891532+0800 SocketIOTest[62610:8531661] LOG SocketEnginePolling: Sending poll:  as type: 6
2017-06-26 20:01:17.982981+0800 SocketIOTest[62610:8531662] LOG SocketEnginePolling: Got polling response
2017-06-26 20:01:17.983506+0800 SocketIOTest[62610:8531662] LOG SocketEnginePolling: Got poll message: 1:1
2017-06-26 20:01:17.983688+0800 SocketIOTest[62610:8531662] LOG SocketEngine: Got message: 1
2017-06-26 20:01:17.983935+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Handling event: statusChange with data: [SocketIO.SocketIOClientStatus]
2017-06-26 20:01:17.984000+0800 SocketIOTest[62610:8531662] LOG SocketEngine: Sending ws:  as type: 5
2017-06-26 20:01:17.984120+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Starting reconnect
2017-06-26 20:01:17.984218+0800 SocketIOTest[62610:8531662] LOG SocketEngine: Flushing probe wait
2017-06-26 20:01:17.984435+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Handling event: reconnect with data: ["1"]
2017-06-26 20:01:17.984615+0800 SocketIOTest[62610:8531583] WebSocket start to reconnect, data: ["1"]
2017-06-26 20:01:17.984918+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Trying to reconnect
2017-06-26 20:01:17.985367+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Handling event: reconnectAttempt with data: [-1]
2017-06-26 20:01:17.985560+0800 SocketIOTest[62610:8531662] ERROR SocketEngine: 
2017-06-26 20:01:17.993816+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Handling event: statusChange with data: [SocketIO.SocketIOClientStatus]
2017-06-26 20:01:17.994065+0800 SocketIOTest[62610:8531583] ERROR SocketIOClient: 
2017-06-26 20:01:17.994180+0800 SocketIOTest[62610:8531662] LOG SocketEngine: Starting engine. Server: http://test.meshtech.co
2017-06-26 20:01:17.994222+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Handling event: error with data: [""]
2017-06-26 20:01:17.994315+0800 SocketIOTest[62610:8531662] LOG SocketEngine: Handshaking
2017-06-26 20:01:17.994332+0800 SocketIOTest[62610:8531583] Receive error: 
2017-06-26 20:01:17.994532+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Handling event: statusChange with data: [SocketIO.SocketIOClientStatus]
2017-06-26 20:01:17.994567+0800 SocketIOTest[62610:8531662] LOG SocketEnginePolling: Doing polling GET http://test.meshtech.co/socket.io/?transport=polling&b64=1
2017-06-26 20:01:18.103175+0800 SocketIOTest[62610:8532034] LOG SocketEnginePolling: Got polling response
2017-06-26 20:01:18.103350+0800 SocketIOTest[62610:8532034] LOG SocketEnginePolling: Got poll message: 97:0{"sid":"2Bq0GPf16VuGno2mAAB4","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":60000}
2017-06-26 20:01:18.103580+0800 SocketIOTest[62610:8532034] LOG SocketEngine: Got message: 0{"sid":"2Bq0GPf16VuGno2mAAB4","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":60000}
2017-06-26 20:01:18.106589+0800 SocketIOTest[62610:8532034] LOG SocketEngineClient: Connect
2017-06-26 20:01:18.107237+0800 SocketIOTest[62610:8532034] LOG SocketEnginePolling: Doing polling GET http://test.meshtech.co/socket.io/?transport=polling&b64=1&sid=2Bq0GPf16VuGno2mAAB4
2017-06-26 20:01:18.108289+0800 SocketIOTest[62610:8532034] LOG SocketEngine: Writing poll:  has data: false
2017-06-26 20:01:18.108695+0800 SocketIOTest[62610:8532034] LOG SocketEnginePolling: Sending poll:  as type: 2
2017-06-26 20:01:18.110097+0800 SocketIOTest[62610:8532034] LOG SocketEnginePolling: Created POST string: 1:2
2017-06-26 20:01:18.110699+0800 SocketIOTest[62610:8532034] LOG SocketEnginePolling: POSTing
2017-06-26 20:01:18.115924+0800 SocketIOTest[62610:8532034] LOG SocketEnginePolling: Doing polling POST http://test.meshtech.co/socket.io/?transport=polling&b64=1&sid=2Bq0GPf16VuGno2mAAB4
2017-06-26 20:01:18.150809+0800 SocketIOTest[62610:8531674] LOG SocketEnginePolling: Got polling response
2017-06-26 20:01:18.150957+0800 SocketIOTest[62610:8531674] LOG SocketEnginePolling: Got poll message: 2:40
2017-06-26 20:01:18.151130+0800 SocketIOTest[62610:8531674] LOG SocketEngine: Got message: 40
2017-06-26 20:01:18.151363+0800 SocketIOTest[62610:8531674] LOG SocketIOClient: Should parse message: 0
2017-06-26 20:01:18.151584+0800 SocketIOTest[62610:8531583] LOG SocketParser: Parsing 0
2017-06-26 20:01:18.151736+0800 SocketIOTest[62610:8531674] LOG SocketEnginePolling: Doing polling GET http://test.meshtech.co/socket.io/?transport=polling&b64=1&sid=2Bq0GPf16VuGno2mAAB4
2017-06-26 20:01:18.151765+0800 SocketIOTest[62610:8531583] LOG SocketParser: Decoded packet as: SocketPacket {type: 0; data: []; id: -1; placeholders: 0; nsp: /}
2017-06-26 20:01:18.151897+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Socket connected
2017-06-26 20:01:18.152019+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Handling event: statusChange with data: [SocketIO.SocketIOClientStatus]
2017-06-26 20:01:18.152138+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Handling event: connect with data: []
2017-06-26 20:01:18.152379+0800 SocketIOTest[62610:8531583] WebSocket connected,
 data:[],
 ack:<SocketIO.SocketAckEmitter: 0x608000626a00>
2017-06-26 20:01:18.152780+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Emitting: 2(my message here) as type: 4
2017-06-26 20:01:18.185702+0800 SocketIOTest[62610:8531674] LOG SocketEngine: Sending ws: probe as type: 2
2017-06-26 20:01:18.206551+0800 SocketIOTest[62610:8531662] LOG SocketEnginePolling: Got polling response
2017-06-26 20:01:18.206874+0800 SocketIOTest[62610:8531662] LOG SocketEnginePolling: Got poll message: 1:3
2017-06-26 20:01:18.207065+0800 SocketIOTest[62610:8531662] LOG SocketEngine: Got message: 3
2017-06-26 20:01:18.207537+0800 SocketIOTest[62610:8531662] LOG SocketEnginePolling: Doing polling GET http://test.meshtech.co/socket.io/?transport=polling&b64=1&sid=2Bq0GPf16VuGno2mAAB4
2017-06-26 20:01:18.207889+0800 SocketIOTest[62610:8531662] LOG SocketEnginePolling: Created POST string: 317:42(my message here)
2017-06-26 20:01:18.208334+0800 SocketIOTest[62610:8531662] LOG SocketEnginePolling: POSTing
2017-06-26 20:01:18.208516+0800 SocketIOTest[62610:8531662] LOG SocketEnginePolling: Doing polling POST http://test.meshtech.co/socket.io/?transport=polling&b64=1&sid=2Bq0GPf16VuGno2mAAB4
2017-06-26 20:01:18.211753+0800 SocketIOTest[62610:8531661] LOG SocketEngine: Got message: 3probe
2017-06-26 20:01:18.211998+0800 SocketIOTest[62610:8531661] LOG SocketEngine: Upgrading transport to WebSockets
2017-06-26 20:01:18.212344+0800 SocketIOTest[62610:8531661] LOG SocketEnginePolling: Sending poll:  as type: 6
2017-06-26 20:01:18.291799+0800 SocketIOTest[62610:8531662] LOG SocketEngine: Flushing probe wait
2017-06-26 20:01:18.292996+0800 SocketIOTest[62610:8531662] LOG SocketEnginePolling: Got polling response
2017-06-26 20:01:18.294414+0800 SocketIOTest[62610:8531662] LOG SocketEnginePolling: Got poll message: 1:1
2017-06-26 20:01:18.294778+0800 SocketIOTest[62610:8531662] LOG SocketEngine: Got message: 1
2017-06-26 20:01:18.295078+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Handling event: statusChange with data: [SocketIO.SocketIOClientStatus]
2017-06-26 20:01:18.295043+0800 SocketIOTest[62610:8531662] LOG SocketEngine: Sending ws:  as type: 5
2017-06-26 20:01:18.295196+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Starting reconnect
2017-06-26 20:01:18.295431+0800 SocketIOTest[62610:8531662] LOG SocketEngine: Flushing probe wait
2017-06-26 20:01:18.295655+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Handling event: reconnect with data: ["1"]
2017-06-26 20:01:18.296294+0800 SocketIOTest[62610:8531583] WebSocket start to reconnect, data: ["1"]
2017-06-26 20:01:18.296495+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Trying to reconnect
2017-06-26 20:01:18.296678+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Handling event: reconnectAttempt with data: [-1]
2017-06-26 20:01:18.296918+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Handling event: statusChange with data: [SocketIO.SocketIOClientStatus]
2017-06-26 20:01:18.297090+0800 SocketIOTest[62610:8531659] ERROR SocketEngine: Engine tried opening while connected. Assuming this was a reconnect
2017-06-26 20:01:18.297236+0800 SocketIOTest[62610:8531659] LOG SocketEngine: Starting engine. Server: http://test.meshtech.co
2017-06-26 20:01:18.297364+0800 SocketIOTest[62610:8531659] LOG SocketEngine: Handshaking
2017-06-26 20:01:18.297625+0800 SocketIOTest[62610:8531659] LOG SocketEnginePolling: Doing polling GET http://test.meshtech.co/socket.io/?transport=polling&b64=1
2017-06-26 20:01:18.297917+0800 SocketIOTest[62610:8531583] LOG SocketIOClient: Handling event: statusChange with data: [SocketIO.SocketIOClientStatus]
2017-06-26 20:01:18.414599+0800 SocketIOTest[62610:8531659] LOG SocketEnginePolling: Got polling response
2017-06-26 20:01:18.414792+0800 SocketIOTest[62610:8531659] LOG SocketEnginePolling: Got poll message: 97:0{"sid":"cCinAOlzEUtsCEIOAAB5","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":60000}
2017-06-26 20:01:18.415052+0800 SocketIOTest[62610:8531659] LOG SocketEngine: Got message: 0{"sid":"cCinAOlzEUtsCEIOAAB5","upgrades":["websocket"],"pingInterval":25000,"pingTimeout":60000}
2017-06-26 20:01:18.416338+0800 SocketIOTest[62610:8531659] LOG SocketEngineClient: Connect
2017-06-26 20:01:18.416777+0800 SocketIOTest[62610:8531659] LOG SocketEngine: Writing poll:  has data: false
2017-06-26 20:01:18.417170+0800 SocketIOTest[62610:8531659] LOG SocketEnginePolling: Sending poll:  as type: 2
2017-06-26 20:01:18.417632+0800 SocketIOTest[62610:8531659] LOG SocketEnginePolling: Created POST string: 1:2
2017-06-26 20:01:18.418244+0800 SocketIOTest[62610:8531659] LOG SocketEnginePolling: POSTing
2017-06-26 20:01:18.515758+0800 SocketIOTest[62610:8531660] LOG SocketEngine: Sending ws: probe as type: 2
2017-06-26 20:01:18.589876+0800 SocketIOTest[62610:8531660] LOG SocketEngine: Got message: 3probe
2017-06-26 20:01:18.590287+0800 SocketIOTest[62610:8531660] LOG SocketEngine: Upgrading transport to WebSockets
2017-06-26 20:01:18.590788+0800 SocketIOTest[62610:8531660] LOG SocketEnginePolling: Sending poll:  as type: 6
kinza88 commented 6 years ago

@PandaraWen Hey! Did you find any solution for this problem?

PandaraWen commented 6 years ago

@kinza88 I update to latest version and the problem gone.

kinza88 commented 6 years ago

Which one was that? Like.. Which version are you using?

PandaraWen commented 6 years ago

13.0.1 now

kinza88 commented 6 years ago

Alright thanks.