Unity WebGL - Abnormal disconnection (sfs 2.13.0)

Post here your questions about the Unity / .Net / Mono / Windows 8 / Windows Phone 8 API for SFS2X

Moderators: Lapo, Bax

mtudor
Posts: 4
Joined: 24 May 2017, 19:36

Unity WebGL - Abnormal disconnection (sfs 2.13.0)

Postby mtudor » 25 May 2017, 09:51

Hi,

I encounter a problem regarding disconnection of all Unity webgl users at random points. (WSS protocol)
[SFS - ERROR] [WebSocketLayer] Communication error: Abnormal disconnection.


Error Flow:
1) Unity webgl and android are playing in the same time. (communication between SFS <-> android is done through binary, communication between SFS <-> webgl is done through JSON)
2) Webgl has no problem in receiving messages like: login, join lobby, join room, start game, etc
3) At some random point, no matter what server message sent to the clients, all Webgl users are disconnected with the following message:
[SFS - ERROR] [WebSocketLayer] Communication error: Abnormal disconnection.
Android (mainly binary users) are ok, they don't receive the disconnect.

I thought it might be because of the JSON objects not being transformed correctly and therefore SFSLite to crash the request, but it's clearly a disconnection from the server. Having in mind that the binary clients don't receive disconnections at all, i enabled the Jetty logs.
Can you please help me reading the logs from the moment of the disconnection ? (i've attached the log from the exact moment of the message sent by the server to the webgl client).

Code: Select all

25 May 2017 | 12:11:54,421 | INFO  | pool-1-thread-8 | Extensions |     | {Rummymeld}: MAIN LOOP 
25 May 2017 | 12:11:54,424 | INFO  | pool-1-thread-8 | Extensions |     | {Rummymeld}: MSG_GAME_CANCEL msgToUser start |putWrappedClass start |putWrappedClass end |main.send start |main.send end |msgToUser - end|
25 May 2017 | 12:11:54,426 | DEBUG | pool-1-thread-8 | websocket.common.WebSocketSession_OPEN |     | [SERVER] WebSocketSession.getRemote()
25 May 2017 | 12:11:54,426 | DEBUG | pool-1-thread-8 | websocket.common.WebSocketRemoteEndpoint |     | sendStringByFuture with HeapByteBuffer@1d0b0096[p=0,l=105,c=105,r=105]={<<<{"p":{"p":{"data"...},"a":13,"c":1}>>>}
25 May 2017 | 12:11:54,427 | DEBUG | pool-1-thread-8 | common.extensions.ExtensionStack |     | Queuing TEXT[len=105,fin=true,rsv=...,masked=false]
25 May 2017 | 12:11:54,427 | DEBUG | pool-1-thread-8 | common.extensions.ExtensionStack |     | Processing TEXT[len=105,fin=true,rsv=...,masked=false]
25 May 2017 | 12:11:54,427 | DEBUG | pool-1-thread-8 | extensions.compress.CompressExtension |     | Queuing TEXT[len=105,fin=true,rsv=...,masked=false]
25 May 2017 | 12:11:54,427 | DEBUG | pool-1-thread-8 | extensions.compress.CompressExtension |     | Processing TEXT[len=105,fin=true,rsv=...,masked=false]
25 May 2017 | 12:11:54,427 | DEBUG | pool-1-thread-8 | extensions.compress.CompressExtension |     | Compressing TEXT[len=105,fin=true,rsv=...,masked=false]: 105 bytes in 256 bytes chunk
25 May 2017 | 12:11:54,427 | DEBUG | pool-1-thread-8 | extensions.compress.CompressExtension |     | Supplied 105 input bytes: Deflater[finished=false,read=17590,written=3125,in=17590,out=3125]
25 May 2017 | 12:11:54,427 | DEBUG | pool-1-thread-8 | extensions.compress.CompressExtension |     | Wrote 45 bytes to output buffer
25 May 2017 | 12:11:54,427 | DEBUG | pool-1-thread-8 | extensions.compress.CompressExtension |     | compressed bytes[] = HeapByteBuffer@60730d04[p=0,l=45,c=45,r=45]={<<<\xC2\xBa\x95\x1b\xD4(\xAd\x8c/\xC9/I\x84D\x14\xBc\xE6...\x03\\\xE2\x83\xFc\xFd}\xD1\x1d\x0f\x00\x00\x00\xFf\xFf>>>}
25 May 2017 | 12:11:54,427 | DEBUG | pool-1-thread-8 | extensions.compress.CompressExtension |     | payload (TAIL_DROP_FIN_ONLY) = HeapByteBuffer@60730d04[p=0,l=41,c=45,r=41]={<<<\xC2\xBa\x95\x1b\xD4(\xAd\x8c/\xC9/I\x84D\x14\xBc\xE6...\x0f0\x0cC\x03\\\xE2\x83\xFc\xFd}\xD1\x1d\x0f\x00>>>\x00\x00\xFf\xFf}
25 May 2017 | 12:11:54,428 | DEBUG | pool-1-thread-8 | extensions.compress.CompressExtension |     | Compressed TEXT[len=0,fin=true,rsv=...,masked=false]: input:256 -> payload:41
25 May 2017 | 12:11:54,428 | DEBUG | pool-1-thread-8 | extensions.compress.PerMessageDeflateExtension |     | nextOutgoingFrame(TEXT[len=41,fin=true,rsv=1..,masked=false])
25 May 2017 | 12:11:54,428 | DEBUG | pool-1-thread-8 | common.io.AbstractWebSocketConnection |     | outgoingFrame(TEXT[len=41,fin=true,rsv=1..,masked=false], org.eclipse.jetty.websocket.common.extensions.compress.CompressExtension$Flusher@3d29cdf1[PROCESSING])
25 May 2017 | 12:11:54,428 | DEBUG | pool-1-thread-8 | common.io.FrameFlusher |     | Flusher[queueSize=1,aggregateSize=0,failure=null] queued FrameEntry[TEXT[len=41,fin=true,rsv=1..,masked=false],org.eclipse.jetty.websocket.common.extensions.compress.CompressExtension$Flusher@3d29cdf1[PROCESSING],AUTO,null]
25 May 2017 | 12:11:54,428 | DEBUG | pool-1-thread-8 | common.io.FrameFlusher |     | Flusher[queueSize=0,aggregateSize=0,failure=null] processing 1 entries: [FrameEntry[TEXT[len=41,fin=true,rsv=1..,masked=false],org.eclipse.jetty.websocket.common.extensions.compress.CompressExtension$Flusher@3d29cdf1[PROCESSING],AUTO,null]]
25 May 2017 | 12:11:54,428 | DEBUG | pool-1-thread-8 | common.io.FrameFlusher |     | Flusher[queueSize=0,aggregateSize=0,failure=null] acquired aggregate buffer java.nio.DirectByteBuffer[pos=0 lim=0 cap=32768]
25 May 2017 | 12:11:54,428 | DEBUG | pool-1-thread-8 | common.io.FrameFlusher |     | Flusher[queueSize=0,aggregateSize=0,failure=null] aggregated 1 frames: [FrameEntry[TEXT[len=0,fin=true,rsv=1..,masked=false],org.eclipse.jetty.websocket.common.extensions.compress.CompressExtension$Flusher@3d29cdf1[PROCESSING],AUTO,null]]
25 May 2017 | 12:11:54,429 | DEBUG | pool-1-thread-8 | common.io.FutureWriteCallback |     | .writeSuccess
25 May 2017 | 12:11:54,429 | DEBUG | pool-1-thread-8 | common.io.FrameFlusher |     | Flusher[queueSize=0,aggregateSize=0,failure=null] processing 0 entries: []
25 May 2017 | 12:11:54,429 | DEBUG | pool-1-thread-8 | common.io.FrameFlusher |     | Flusher[queueSize=0,aggregateSize=0,failure=null] auto flushing
25 May 2017 | 12:11:54,429 | DEBUG | pool-1-thread-8 | common.io.FrameFlusher |     | Flusher[queueSize=0,aggregateSize=0,failure=null] flushing aggregate java.nio.DirectByteBuffer[pos=0 lim=43 cap=32768]
25 May 2017 | 12:11:54,429 | DEBUG | pool-1-thread-8 | common.io.FrameFlusher |     | Flusher[queueSize=0,aggregateSize=0,failure=null] flushing 0 frames: []
25 May 2017 | 12:11:54,429 | DEBUG | pool-1-thread-8 | jetty.io.WriteFlusher |     | write: WriteFlusher@52aeb1f0{IDLE} [DirectByteBuffer@542099a4[p=0,l=43,c=32768,r=43]={<<<\xC1)\xC2\xBa\x95\x1b\xD4(\xAd\x8c/\xC9/I\x84D\x14...\x0f0\x0cC\x03\\\xE2\x83\xFc\xFd}\xD1\x1d\x0f\x00>>>v-\x80]\x15`\x9e\x07z\x18\xD8\x17\x02&mK\xC3...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}]
25 May 2017 | 12:11:54,429 | DEBUG | pool-1-thread-8 | jetty.io.WriteFlusher |     | update WriteFlusher@52aeb1f0{WRITING}:IDLE-->WRITING
25 May 2017 | 12:11:54,430 | DEBUG | pool-1-thread-8 | io.ssl.SslConnection |     | SslConnection@7dbbaee9{NOT_HANDSHAKING,eio=-1/-1,di=-1} -> WebSocketServerConnection@3B266F1B{endp=DecryptedEndPoint@6081fd2a{/5.2.132.98:51262<->8443,Open,in,out,FI,W,2800/300000,WebSocketServerConnection@3b266f1b}->SelectChannelEndPoint@427092f8{/5.2.132.98:51262<->8443,Open,in,out,FI,-,2797/300000,SslConnection@7dbbaee9}{io=1/1,kio=1,kro=1},ios=IOState@34d93677[OPEN,in,out],f=Flusher[queueSize=0,aggregateSize=0,failure=null],g=Generator[SERVER,validating,+rsv1],p=Parser@31d42e75[ExtensionStack,s=START,c=0,len=4,f=null]} flush b[43]=C129C2BA951BD428AD8C2FC92F49844414BCE687CD0DEA40D5...FCFD7DD11D0F00
25 May 2017 | 12:11:54,430 | DEBUG | pool-1-thread-8 | io.ssl.SslConnection |     | SslConnection@7dbbaee9{NOT_HANDSHAKING,eio=-1/72,di=-1} -> WebSocketServerConnection@3B266F1B{endp=DecryptedEndPoint@6081fd2a{/5.2.132.98:51262<->8443,Open,in,out,FI,W,2800/300000,WebSocketServerConnection@3b266f1b}->SelectChannelEndPoint@427092f8{/5.2.132.98:51262<->8443,Open,in,out,FI,-,2797/300000,SslConnection@7dbbaee9}{io=1/1,kio=1,kro=1},ios=IOState@34d93677[OPEN,in,out],f=Flusher[queueSize=0,aggregateSize=43,failure=null],g=Generator[SERVER,validating,+rsv1],p=Parser@31d42e75[ExtensionStack,s=START,c=0,len=4,f=null]} wrap Status = OK HandshakeStatus = NOT_HANDSHAKING bytesConsumed = 43 bytesProduced = 72
25 May 2017 | 12:11:54,430 | DEBUG | pool-1-thread-8 | io.ssl.SslConnection |     | SslConnection@7dbbaee9{NOT_HANDSHAKING,eio=-1/72,di=-1} -> WebSocketServerConnection@3B266F1B{endp=DecryptedEndPoint@6081fd2a{/5.2.132.98:51262<->8443,Open,in,out,FI,W,2800/300000,WebSocketServerConnection@3b266f1b}->SelectChannelEndPoint@427092f8{/5.2.132.98:51262<->8443,Open,in,out,FI,-,2797/300000,SslConnection@7dbbaee9}{io=1/1,kio=1,kro=1},ios=IOState@34d93677[OPEN,in,out],f=Flusher[queueSize=0,aggregateSize=43,failure=null],g=Generator[SERVER,validating,+rsv1],p=Parser@31d42e75[ExtensionStack,s=START,c=0,len=4,f=null]} wrap OK b[72]=1703030043000000000000001FEEF69E12D12D5314EC2E3CB7...769D1FC90A517C
25 May 2017 | 12:11:54,433 | DEBUG | pool-1-thread-8 | io.ssl.SslConnection |     | SslConnection@7dbbaee9{NOT_HANDSHAKING,eio=-1/72,di=-1} -> WebSocketServerConnection@3B266F1B{endp=DecryptedEndPoint@6081fd2a{/5.2.132.98:51262<->8443,Open,in,OSHUT,FI,W,2802/300000,WebSocketServerConnection@3b266f1b}->SelectChannelEndPoint@427092f8{/5.2.132.98:51262<->8443,Open,ISHUT,OSHUT,FI,-,2799/300000,SslConnection@7dbbaee9}{io=1/1,kio=-1,kro=-1},ios=IOState@34d93677[OPEN,in,out],f=Flusher[queueSize=0,aggregateSize=43,failure=null],g=Generator[SERVER,validating,+rsv1],p=Parser@31d42e75[ExtensionStack,s=START,c=0,len=4,f=null]} shutdownOutput: oshut=true, ishut=false
25 May 2017 | 12:11:54,433 | DEBUG | pool-1-thread-8 | jetty.io.WriteFlusher |     | ignored: WriteFlusher@46b0e99b{IDLE} java.nio.channels.ClosedChannelException
25 May 2017 | 12:11:54,434 | DEBUG | pool-1-thread-8 | jetty.io.AbstractConnection |     | WebSocketServerConnection@3B266F1B{endp=DecryptedEndPoint@6081fd2a{/5.2.132.98:51262<->8443,CLOSED,in,OSHUT,-,W,2803/300000,WebSocketServerConnection@3b266f1b}->SelectChannelEndPoint@427092f8{/5.2.132.98:51262<->8443,CLOSED,ISHUT,OSHUT,-,-,2801/300000,SslConnection@7dbbaee9}{io=1/1,kio=-1,kro=-1},ios=IOState@34d93677[OPEN,in,out],f=Flusher[queueSize=0,aggregateSize=43,failure=null],g=Generator[SERVER,validating,+rsv1],p=Parser@31d42e75[ExtensionStack,s=START,c=0,len=4,f=null]} onFillInterestedFailed java.nio.channels.ClosedChannelException
25 May 2017 | 12:11:54,434 | DEBUG | pool-1-thread-8 | jetty.io.ChannelEndPoint |     | close SelectChannelEndPoint@427092f8{/5.2.132.98:51262<->8443,CLOSED,ISHUT,OSHUT,-,-,2801/300000,SslConnection@7dbbaee9}{io=1/1,kio=-1,kro=-1}
25 May 2017 | 12:11:54,435 | DEBUG | pool-1-thread-8 | jetty.io.ManagedSelector |     | Queued change org.eclipse.jetty.io.ManagedSelector$2@34a27405 on org.eclipse.jetty.io.ManagedSelector@9746157 id=0 keys=1 selected=0
25 May 2017 | 12:11:54,435 | DEBUG | pool-1-thread-8 | jetty.io.WriteFlusher |     | failed: WriteFlusher@52aeb1f0{WRITING} org.eclipse.jetty.io.EofException
25 May 2017 | 12:11:54,436 | DEBUG | pool-1-thread-8 | jetty.io.WriteFlusher |     | update WriteFlusher@52aeb1f0{FAILED}:WRITING-->FAILED
25 May 2017 | 12:11:54,436 | DEBUG | qtp295304806-42 | jetty.io.ManagedSelector |     | Selector loop woken up from select, 0/0 selected
25 May 2017 | 12:11:54,436 | DEBUG | qtp295304806-42 | thread.strategy.ExecuteProduceConsume |     | EPC Prod/org.eclipse.jetty.io.ManagedSelector$SelectorProducer@167714fb produced org.eclipse.jetty.io.ManagedSelector$2@34a27405
25 May 2017 | 12:11:54,436 | DEBUG | qtp295304806-42 | thread.strategy.ExecuteProduceConsume |     | EPC Pend/org.eclipse.jetty.io.ManagedSelector$SelectorProducer@167714fb dispatch
25 May 2017 | 12:11:54,436 | DEBUG | qtp295304806-42 | util.thread.QueuedThreadPool |     | queue EPC Pend/org.eclipse.jetty.io.ManagedSelector$SelectorProducer@167714fb
25 May 2017 | 12:11:54,436 | DEBUG | qtp295304806-42 | thread.strategy.ExecuteProduceConsume |     | EPC Pend/org.eclipse.jetty.io.ManagedSelector$SelectorProducer@167714fb run org.eclipse.jetty.io.ManagedSelector$2@34a27405
25 May 2017 | 12:11:54,436 | DEBUG | qtp295304806-43 | util.thread.QueuedThreadPool |     | run EPC Pend/org.eclipse.jetty.io.ManagedSelector$SelectorProducer@167714fb
25 May 2017 | 12:11:54,436 | DEBUG | qtp295304806-43 | thread.strategy.ExecuteProduceConsume |     | EPC Pend/org.eclipse.jetty.io.ManagedSelector$SelectorProducer@167714fb run
25 May 2017 | 12:11:54,436 | DEBUG | qtp295304806-42 | jetty.io.ManagedSelector |     | Destroyed SelectChannelEndPoint@427092f8{/5.2.132.98:51262<->8443,CLOSED,ISHUT,OSHUT,-,-,2803/300000,SslConnection@7dbbaee9}{io=1/1,kio=-1,kro=-1}
25 May 2017 | 12:11:54,436 | DEBUG | qtp295304806-43 | thread.strategy.ExecuteProduceConsume |     | EPC Prod/org.eclipse.jetty.io.ManagedSelector$SelectorProducer@167714fb produce enter
25 May 2017 | 12:11:54,437 | DEBUG | qtp295304806-42 | common.io.AbstractWebSocketConnection |     | SERVER onClose()
25 May 2017 | 12:11:54,437 | DEBUG | qtp295304806-43 | thread.strategy.ExecuteProduceConsume |     | EPC Prod/org.eclipse.jetty.io.ManagedSelector$SelectorProducer@167714fb producing
25 May 2017 | 12:11:54,437 | DEBUG | qtp295304806-43 | jetty.io.ManagedSelector |     | Selector loop waiting on select
25 May 2017 | 12:11:54,437 | DEBUG | qtp295304806-42 | jetty.io.AbstractConnection |     | onClose WebSocketServerConnection@3B266F1B{endp=DecryptedEndPoint@6081fd2a{/5.2.132.98:51262<->8443,CLOSED,in,OSHUT,-,F,2807/300000,WebSocketServerConnection@3b266f1b}->SelectChannelEndPoint@427092f8{/5.2.132.98:51262<->8443,CLOSED,ISHUT,OSHUT,-,-,2804/300000,SslConnection@7dbbaee9}{io=1/1,kio=-1,kro=-1},ios=IOState@34d93677[OPEN,in,out],f=Flusher[queueSize=0,aggregateSize=43,failure=null],g=Generator[SERVER,validating,+rsv1],p=Parser@31d42e75[ExtensionStack,s=START,c=0,len=4,f=null]}
25 May 2017 | 12:11:54,439 | DEBUG | qtp295304806-42 | common.io.IOState |     | Notify State Listeners: CLOSED
25 May 2017 | 12:11:54,439 | DEBUG | pool-1-thread-8 | jetty.io.WriteFlusher |     | write exception
org.eclipse.jetty.io.EofException
   at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:197)
   at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.flush(SslConnection.java:840)
   at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:420)
   at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:313)
   at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:140)
   at org.eclipse.jetty.websocket.common.io.FrameFlusher$Flusher.flush(FrameFlusher.java:153)
   at org.eclipse.jetty.websocket.common.io.FrameFlusher$Flusher.process(FrameFlusher.java:212)
   at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241)
   at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:224)
   at org.eclipse.jetty.websocket.common.io.FrameFlusher.enqueue(FrameFlusher.java:382)
   at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.outgoingFrame(AbstractWebSocketConnection.java:614)
   at org.eclipse.jetty.websocket.common.extensions.AbstractExtension.nextOutgoingFrame(AbstractExtension.java:182)
   at org.eclipse.jetty.websocket.common.extensions.compress.PerMessageDeflateExtension.nextOutgoingFrame(PerMessageDeflateExtension.java:116)
   at org.eclipse.jetty.websocket.common.extensions.compress.CompressExtension.access$1000(CompressExtension.java:42)
   at org.eclipse.jetty.websocket.common.extensions.compress.CompressExtension$Flusher.compress(CompressExtension.java:534)
   at org.eclipse.jetty.websocket.common.extensions.compress.CompressExtension$Flusher.deflate(CompressExtension.java:435)
   at org.eclipse.jetty.websocket.common.extensions.compress.CompressExtension$Flusher.process(CompressExtension.java:415)
   at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241)
   at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:224)
   at org.eclipse.jetty.websocket.common.extensions.compress.CompressExtension.outgoingFrame(CompressExtension.java:218)
   at org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher.process(ExtensionStack.java:395)
   at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241)
   at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:224)
   at org.eclipse.jetty.websocket.common.extensions.ExtensionStack.outgoingFrame(ExtensionStack.java:296)
   at org.eclipse.jetty.websocket.common.WebSocketRemoteEndpoint.uncheckedSendFrame(WebSocketRemoteEndpoint.java:310)
   at org.eclipse.jetty.websocket.common.WebSocketRemoteEndpoint.sendAsyncFrame(WebSocketRemoteEndpoint.java:240)
   at org.eclipse.jetty.websocket.common.WebSocketRemoteEndpoint.sendStringByFuture(WebSocketRemoteEndpoint.java:412)
   at sfs2x.websocket.SFS2XWSService$WSChannelListener.write(SFS2XWSService.java:369)
   at com.smartfoxserver.bitswarm.websocket.jetty.WebSocketTextProtocolCodec.onPacketWrite(WebSocketTextProtocolCodec.java:106)
   at com.smartfoxserver.bitswarm.core.BitSwarmEngine.writeToWebSocket(BitSwarmEngine.java:417)
   at com.smartfoxserver.bitswarm.core.BitSwarmEngine.write(BitSwarmEngine.java:398)
   at com.smartfoxserver.bitswarm.io.Response.write(Response.java:71)
   at com.smartfoxserver.v2.api.response.SFSResponseApi.sendExtResponse(SFSResponseApi.java:91)
   at com.smartfoxserver.v2.api.SFSApi.sendExtensionResponse(SFSApi.java:1515)
   at com.smartfoxserver.v2.extensions.BaseSFSExtension.send(BaseSFSExtension.java:487)
   at com.smartfoxserver.v2.extensions.BaseSFSExtension.send(BaseSFSExtension.java:462)
   at com.thewizards.goxlib.messages.QComponentMessenger.msgToUser(QComponentMessenger.java:94)
   at com.thewizards.goxlib.messages.QComponentMessenger.msgToRoom(QComponentMessenger.java:105)
   at com.thewizards.goxrummymeld.roomlist.CRoom.gameTerminate(CRoom.java:941)
   at com.thewizards.goxrummymeld.roomlist.CRoom.opMainLoop(CRoom.java:748)
   at com.thewizards.goxrummymeld.roomlist.CRoom.opCustom(CRoom.java:327)
   at com.thewizards.goxlib.extension.QRoom.syncRoom(QRoom.java:26)
   at com.thewizards.goxrummymeld.game.CSchedulerTaskRoomLoop.run(CSchedulerTaskRoomLoop.java:22)
   at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
   at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
   at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   at java.lang.Thread.run(Thread.java:745)
Caused by: java.nio.channels.ClosedByInterruptException
   at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:202)
   at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:478)
   at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:175)
   ... 49 more
25 May 2017 | 12:11:54,439 | DEBUG | qtp295304806-42 | common.io.IOState |     | WebSocketServerConnection.onConnectionStateChange(CLOSED)
25 May 2017 | 12:11:54,442 | DEBUG | pool-1-thread-8 | jetty.io.WriteFlusher |     | update WriteFlusher@52aeb1f0{FAILED}:WRITING!->IDLE
25 May 2017 | 12:11:54,442 | DEBUG | qtp295304806-42 | common.io.AbstractWebSocketConnection_CLOSE |     | SERVER Connection State Change: CLOSED
25 May 2017 | 12:11:54,443 | DEBUG | qtp295304806-42 | common.io.AbstractWebSocketConnection_CLOSE |     | CLOSED - wasAbnormalClose: true
25 May 2017 | 12:11:54,443 | DEBUG | pool-1-thread-8 | jetty.io.WriteFlusher |     | update WriteFlusher@52aeb1f0{IDLE}:FAILED-->IDLE
25 May 2017 | 12:11:54,443 | DEBUG | pool-1-thread-8 | extensions.compress.CompressExtension |     | Processing null
25 May 2017 | 12:11:54,443 | DEBUG | pool-1-thread-8 | common.extensions.ExtensionStack |     | Entering IDLE


Disconnect happens with the following ecosystem:
Unity: 5.6.1f1
Client API: 1.7.2
Websocket: WSS (public certificate setup)
SFS Version: 2.13.0

But it doesn't happen at all with this ecosystem:
Unity: 5.6.1f1
Client API: 1.7.2
Websocket: WSS (public certificate setup)
SFS Version: 2.12.0
User avatar
Lapo
Site Admin
Posts: 23008
Joined: 21 Mar 2005, 09:50
Location: Italy

Re: Unity WebGL - Abnormal disconnection (sfs 2.13.0)

Postby Lapo » 25 May 2017, 14:40

Hi,
well the logs only indicate a generic "EofException", which says that the connection was terminated but doesn't say why.

A similar topic, related to Jetty, was discussed here:
https://stackoverflow.com/questions/350 ... large-file
and the response is similarly a little vague because there could be all sorts of reasons why the connection was shut down.

The fact that the other Android clients didn't have any problems doesn't surprise me, as those are two different protocols.
SFS2X binary uses raw TCP, while websocket is part of HTTP.

Before switching to Jetty we have done a significant amount of stress testing and didn't find any particular issues related to connection stability, so I wouldn't be immediately inclined to blame Jetty.

I would like to understand better. Is there a way to reproduce this?
Does it depend on traffic? Or maybe are there specific triggers in the game that cause the problem more frequently?

Also you said this doesn't happen if clients talk to SFS2X 2.12... but are those the same clients? With the same traffic and CCU?
How did you exclude simple a coincidence or a temporary bad network?
Can you share the details of your tests?

If you prefer to share such data privately, send us an email to support@... with a reference to this discussion.

Thanks
Lapo
--
gotoAndPlay()
...addicted to flash games
mtudor
Posts: 4
Joined: 24 May 2017, 19:36

Re: Unity WebGL - Abnormal disconnection (sfs 2.13.0)

Postby mtudor » 25 May 2017, 15:40

Thanks for your answer, Lapo.

I would like to understand better. Is there a way to reproduce this?

Yes, at the beginning i thought there might be a problem with the data between server and client, but getting back to the 2.12 with everything working killed this hypothesis.

Does it depend on traffic?

It's not about the traffic, it's on a test server with good connectivity and a max of 5 clients being in the test (4 webgls with the same connection different computers, and one android on byte on 4G)

Or maybe are there specific triggers in the game that cause the problem more frequently?

Randomly, but most often after a game in a room is starting again. Might be because something changed in the of a data type (ex: PutLong, putSfsArray, etc) that works fine inside sfs 2.12 but is broken in 2.13 ? (the weirdest problem is that WebGLs are getting disconnected no matter if they are in the lobby or if they are in a room playing a game).


Also you said this doesn't happen if clients talk to SFS2X 2.12... but are those the same clients? With the same traffic and CCU?

Exactly same clients exactly same connections, exactly same traffic and CCU.

How did you exclude simple a coincidence or a temporary bad network?

on 2.12 works with not a single disconnect, on 2.13 all WebGLs are kicked (looks like sfs doesn't wants to keep it's WEBSOCKETS with any of the webgl clients)
User avatar
Lapo
Site Admin
Posts: 23008
Joined: 21 Mar 2005, 09:50
Location: Italy

Re: Unity WebGL - Abnormal disconnection (sfs 2.13.0)

Postby Lapo » 25 May 2017, 16:48

Thanks for the details.
mtudor wrote:
Or maybe are there specific triggers in the game that cause the problem more frequently?

Randomly, but most often after a game in a room is starting again. Might be because something changed in the of a data type (ex: PutLong, putSfsArray, etc) that works fine inside sfs 2.12 but is broken in 2.13 ? (the weirdest problem is that WebGLs are getting disconnected no matter if they are in the lobby or if they are in a room playing a game).

No, we can exclude that. Any type conversion would not cause a disconnection, but rather an server-side error. Plus you would see evidence of such issues in the logs.

Additionally the only thing that has really changed in 2.13 is Jetty handling the websocket traffic. The JSON codec is exactly the same as was before. Of course, you can now turn on the binary codec as well for websockets, but currently this is not supported yet in Unity/WebGL. Only Javascript/HTML5.

on 2.12 works with not a single disconnect, on 2.13 all WebGLs are kicked (looks like sfs doesn't wants to keep it's WEBSOCKETS with any of the webgl clients)

Okay, can you add more details?
For instance, how long does it take before a client is kicked out? Is it approximately the same time for every one?

Can you reproduce it with a single client connected to the server? If so I will ask you to turn on the DEBUG logs on the server side and capture the entire client/server exchange so we can take a look.

Even better I would do the above 3 times, to see how long does it take on every instance.

Thanks
Lapo

--

gotoAndPlay()

...addicted to flash games
freeman126
Posts: 1
Joined: 01 Jun 2017, 01:58

Re: Unity WebGL - Abnormal disconnection (sfs 2.13.0)

Postby freeman126 » 01 Jun 2017, 02:18

Of course, you can now turn on the binary codec as well for websockets, but currently this is not supported yet in Unity/WebGL. Only Javascript/HTML5.

Do you have any plan for implementing binary protocol for Unity/WebGL?
User avatar
Lapo
Site Admin
Posts: 23008
Joined: 21 Mar 2005, 09:50
Location: Italy

Re: Unity WebGL - Abnormal disconnection (sfs 2.13.0)

Postby Lapo » 01 Jun 2017, 07:40

freeman126 wrote:
Of course, you can now turn on the binary codec as well for websockets, but currently this is not supported yet in Unity/WebGL. Only Javascript/HTML5.

Do you have any plan for implementing binary protocol for Unity/WebGL?

Yes, we're currently working on it. Should be out pretty soon.

Cheers
Lapo

--

gotoAndPlay()

...addicted to flash games
mtudor
Posts: 4
Joined: 24 May 2017, 19:36

Re: Unity WebGL - Abnormal disconnection (sfs 2.13.0)

Postby mtudor » 06 Jun 2017, 06:29

Hi Lapo,
After a kazillion of tests i came to the conclusion that this issue i encounter is happening when i send an update message to the lobby users.
What's weird is that i'm sending the same message in other circumstances also, but in those cases the webgl users are not kicked out. Instead they are kicked out only after a game has started and one user gets out of the room before a game starts (though the exit to lobby happens normally).
I think that there's something in my code that triggers that websocket death, something that in 2.13 is not passing, but it passed in 2.12.

i'm going to run on 2.12 until you guys do update the unity/webgl api to run on binary protocol.
User avatar
Bax
Site Admin
Posts: 4609
Joined: 29 Mar 2005, 09:50
Location: Italy
Contact:

Re: Unity WebGL - Abnormal disconnection (sfs 2.13.0)

Postby Bax » 06 Jun 2017, 07:21

The updated API is now available here: http://www.smartfoxserver.com/download/sfs2x#p=client (v1.7.3)
(we still have to announce it officially because we are also updating the examples pack)
Let us know if this changes the behavior you are seeing. Otherwise we will possibly need a basic proof of concept we can test to reproduce the issue.
Paolo Bax
The SmartFoxServer Team
mtudor
Posts: 4
Joined: 24 May 2017, 19:36

Re: Unity WebGL - Abnormal disconnection (sfs 2.13.0)

Postby mtudor » 07 Jun 2017, 10:09

Thanks Bax,
Just a quick question to be sure: 1.7.3 supports binary for unity webgl ?

Later edit: Dumb question. i wrote the question without looking at the 1.7.3's Release notes -> http://www.smartfoxserver.com/download/releaseNotes/SFS2X_API_CSharp.txt :)

Will do the tests and get back to you with news.
User avatar
Bax
Site Admin
Posts: 4609
Joined: 29 Mar 2005, 09:50
Location: Italy
Contact:

Re: Unity WebGL - Abnormal disconnection (sfs 2.13.0)

Postby Bax » 07 Jun 2017, 10:14

Yes, as listed in the release notes. You will need to pass UseWebSockets.WS_BIN to the SmartFox constructor.
Paolo Bax
The SmartFoxServer Team

Return to “SFS2X C# API”

Who is online

Users browsing this forum: No registered users and 33 guests