socketio / socket.io-server-java

Socket.IO Server Library for Java
Other
50 stars 9 forks source link

Deadlock SocketIoSocket.leaveAllRooms vs SocketIoMemoryAdapter.remove #8

Open paulthomson78 opened 1 year ago

paulthomson78 commented 1 year ago

I have a chat system with the back end built on socket.io-server-java. When a client disconnects, the system broadcasts a message to the room that the client was in.

This is working very nicely, thank you, except that when multiple clients leave at almost exactly the same time I hit a deadlock. The stack trace below demonstrates this.

The first thread is processing closing a connection. It holds the lock to the SocketIoSocket being closed (0x00000007b37007a8) and as part of running SocketIoSocket leaveAllRooms it is waiting on acquiring the lock to the SocketIoMemoryAdapter (0x00000007b3901978) to run its remove method.

The second thread is processing closing a connection - I assume from a different client. As part of that, on "disconnect" I have a listener registered that broadcasts a message to a room. This thread holds the lock to the SocketIoMemoryAdapter (0x00000007b3901978) because it is in the SocketIoMemoryAdapter broadcast method. Somehow that broadcast is throwing an IOException - I suspect trying to broadcast to the socket that the first thread is in the middle of closing. As part of processing that exception, it is attempting to close the problematic socket, which includes running SocketIoSocket method leaveAllRooms, and in doing so its trying to acquire the lock on that SocketIoSocket (0x00000007b37007a8). Hence the deadlock.

Is this a known limitation, or is it something you could look at fixing please? Is there any workaround?

I'm running version 4.0.1 in a a web app deployed as an EAR file in WildFly 26.1.1.

"default task-572" #2020 prio=5 os_prio=0 cpu=15.63ms elapsed=6490.38s allocated=14200B defined_classes=0 tid=0x00000203fa9c7000 nid=0x4608 waiting for monitor entry  [0x00000036229fe000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at io.socket.socketio.server.SocketIoMemoryAdapter.remove(SocketIoMemoryAdapter.java:92)
    - waiting to lock <0x00000007b3901978> (a io.socket.socketio.server.SocketIoMemoryAdapter)
    at io.socket.socketio.server.SocketIoSocket.leaveAllRooms(SocketIoSocket.java:268)
    - locked <0x00000007b37007a8> (a io.socket.socketio.server.SocketIoSocket)
    at io.socket.socketio.server.SocketIoSocket.onClose(SocketIoSocket.java:364)
    at io.socket.socketio.server.SocketIoSocket.onDisconnect(SocketIoSocket.java:357)
    at io.socket.socketio.server.SocketIoSocket.onPacket(SocketIoSocket.java:336)
    at io.socket.socketio.server.SocketIoClient.lambda$setup$1(SocketIoClient.java:163)
    at io.socket.socketio.server.SocketIoClient$$Lambda$3548/0x0000000803770440.call(Unknown Source)
    at io.socket.socketio.server.parser.IOParser$Decoder.add(IOParser.java:99)
    at io.socket.socketio.server.SocketIoClient.lambda$setup$2(SocketIoClient.java:171)
    at io.socket.socketio.server.SocketIoClient$$Lambda$3549/0x0000000803770840.call(Unknown Source)
    at io.socket.engineio.server.Emitter.emit(Emitter.java:123)
    at io.socket.engineio.server.EngineIoSocket.emit(EngineIoSocket.java:187)
    at io.socket.engineio.server.EngineIoSocket.onPacket(EngineIoSocket.java:400)
    at io.socket.engineio.server.EngineIoSocket.lambda$setTransport$10(EngineIoSocket.java:303)
    at io.socket.engineio.server.EngineIoSocket$$Lambda$3542/0x0000000803732440.call(Unknown Source)
    at io.socket.engineio.server.Emitter.emit(Emitter.java:123)
    at io.socket.engineio.server.Transport.onPacket(Transport.java:102)
    at io.socket.engineio.server.Transport.onData(Transport.java:111)
    at io.socket.engineio.server.transport.WebSocket.lambda$new$0(WebSocket.java:26)
    at io.socket.engineio.server.transport.WebSocket$$Lambda$3556/0x0000000803772440.call(Unknown Source)
    at io.socket.engineio.server.Emitter.emit(Emitter.java:123)
[...my @OnMessage method in my @ServerEndpoint class]
"default task-558" #2006 prio=5 os_prio=0 cpu=15.63ms elapsed=6490.39s allocated=60368B defined_classes=0 tid=0x00000203f3b80000 nid=0x52a4 waiting for monitor entry  [0x00000036219fc000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at io.socket.socketio.server.SocketIoSocket.leaveAllRooms(SocketIoSocket.java:267)
    - waiting to lock <0x00000007b37007a8> (a io.socket.socketio.server.SocketIoSocket)
    at io.socket.socketio.server.SocketIoSocket.onClose(SocketIoSocket.java:364)
    at io.socket.socketio.server.SocketIoClient.onClose(SocketIoClient.java:206)
    at io.socket.socketio.server.SocketIoClient.lambda$setup$4(SocketIoClient.java:180)
    at io.socket.socketio.server.SocketIoClient$$Lambda$3551/0x0000000803771040.call(Unknown Source)
    at io.socket.engineio.server.Emitter.emit(Emitter.java:123)
    at io.socket.engineio.server.EngineIoSocket.emit(EngineIoSocket.java:187)
    at io.socket.engineio.server.EngineIoSocket.onClose(EngineIoSocket.java:369)
    at io.socket.engineio.server.EngineIoSocket.onError(EngineIoSocket.java:374)
    at io.socket.engineio.server.EngineIoSocket.lambda$setTransport$8(EngineIoSocket.java:298)
    at io.socket.engineio.server.EngineIoSocket$$Lambda$3540/0x0000000803732c40.call(Unknown Source)
    at io.socket.engineio.server.Emitter$OnceListener.call(Emitter.java:37)
    at io.socket.engineio.server.Emitter.emit(Emitter.java:123)
    at io.socket.engineio.server.Transport.onError(Transport.java:92)
    at io.socket.engineio.server.transport.WebSocket.lambda$send$3(WebSocket.java:54)
    at io.socket.engineio.server.transport.WebSocket$$Lambda$3564/0x0000000803774440.call(Unknown Source)
    at io.socket.engineio.server.parser.ParserV4.encodePacket(ParserV4.java:36)
    at io.socket.engineio.server.transport.WebSocket.send(WebSocket.java:58)
    at io.socket.engineio.server.EngineIoSocket.flush(EngineIoSocket.java:422)
    - locked <0x00000007b3700bf8> (a java.lang.Object)
    at io.socket.engineio.server.EngineIoSocket.sendPacket(EngineIoSocket.java:412)
    - locked <0x00000007b3700bf8> (a java.lang.Object)
    at io.socket.engineio.server.EngineIoSocket.send(EngineIoSocket.java:114)
    at io.socket.socketio.server.SocketIoClient.lambda$sendPacket$0(SocketIoClient.java:74)
    at io.socket.socketio.server.SocketIoClient$$Lambda$3554/0x0000000803771c40.call(Unknown Source)
    at io.socket.socketio.server.parser.IOParser$Encoder.encode(IOParser.java:37)
    at io.socket.socketio.server.SocketIoClient.sendPacket(SocketIoClient.java:68)
    at io.socket.socketio.server.SocketIoSocket.sendPacket(SocketIoSocket.java:382)
    at io.socket.socketio.server.SocketIoMemoryAdapter.broadcast(SocketIoMemoryAdapter.java:52)
    - locked <0x00000007b3901978> (a io.socket.socketio.server.SocketIoMemoryAdapter)
    at io.socket.socketio.server.SocketIoAdapter.broadcast(SocketIoAdapter.java:59)
    at io.socket.socketio.server.SocketIoNamespaceImpl.broadcast(SocketIoNamespaceImpl.java:32)
    at io.socket.socketio.server.SocketIoNamespace.broadcast(SocketIoNamespace.java:60)
[...my code that responds to a client disconnecting and broadcasts a message to the room...]
    at io.socket.engineio.server.Emitter.emit(Emitter.java:123)
    at io.socket.socketio.server.SocketIoSocket.onClose(SocketIoSocket.java:370)
    at io.socket.socketio.server.SocketIoSocket.onDisconnect(SocketIoSocket.java:357)
    at io.socket.socketio.server.SocketIoSocket.onPacket(SocketIoSocket.java:336)
    at io.socket.socketio.server.SocketIoClient.lambda$setup$1(SocketIoClient.java:163)
    at io.socket.socketio.server.SocketIoClient$$Lambda$3548/0x0000000803770440.call(Unknown Source)
    at io.socket.socketio.server.parser.IOParser$Decoder.add(IOParser.java:99)
    at io.socket.socketio.server.SocketIoClient.lambda$setup$2(SocketIoClient.java:171)
    at io.socket.socketio.server.SocketIoClient$$Lambda$3549/0x0000000803770840.call(Unknown Source)
    at io.socket.engineio.server.Emitter.emit(Emitter.java:123)
    at io.socket.engineio.server.EngineIoSocket.emit(EngineIoSocket.java:187)
    at io.socket.engineio.server.EngineIoSocket.onPacket(EngineIoSocket.java:400)
    at io.socket.engineio.server.EngineIoSocket.lambda$setTransport$10(EngineIoSocket.java:303)
    at io.socket.engineio.server.EngineIoSocket$$Lambda$3542/0x0000000803732440.call(Unknown Source)
    at io.socket.engineio.server.Emitter.emit(Emitter.java:123)
    at io.socket.engineio.server.Transport.onPacket(Transport.java:102)
    at io.socket.engineio.server.Transport.onData(Transport.java:111)
    at io.socket.engineio.server.transport.WebSocket.lambda$new$0(WebSocket.java:26)
    at io.socket.engineio.server.transport.WebSocket$$Lambda$3556/0x0000000803772440.call(Unknown Source)
    at io.socket.engineio.server.Emitter.emit(Emitter.java:123)
[...my @OnMessage method in my @ServerEndpoint class]
trinopoty commented 1 year ago

Hi, Please check out the latest version. Some more checks have been added to avoid calling synchronized method leaveAllRooms if connection is already closing.