maptool
maptool copied to clipboard
[Bug]: occasional NullPointerException on local WebRTC client connection
Describe the Bug
After starting a WebRTC server it failed to start properly.
18:27:52.457 (ClientHandshake.java:145) [Thread-16] INFO - skullman :send: CLIENT_INIT_MSG
Exception in thread "Thread-16" java.lang.NullPointerException: Cannot invoke "dev.onvoid.webrtc.RTCPeerConnection.getConnectionState()" because "this.peerConnection" is null
at net.rptools.clientserver.simple.client.WebRTCClientConnection.sendMessage(WebRTCClientConnection.java:185)
at net.rptools.clientserver.simple.client.WebRTCClientConnection.sendMessage(WebRTCClientConnection.java:178)
at net.rptools.clientserver.hessian.client.MethodClientDecorator.sendMessage(MethodClientDecorator.java:42)
at net.rptools.maptool.server.ClientHandshake.sendMessage(ClientHandshake.java:146)
at net.rptools.maptool.server.ClientHandshake.startHandshake(ClientHandshake.java:139)
at net.rptools.maptool.client.MapToolConnection.start(MapToolConnection.java:76)
at net.rptools.maptool.client.MapTool.createConnection(MapTool.java:1227)
at net.rptools.maptool.client.AppActions$62.lambda$executeAction$1(AppActions.java:2326)
at net.rptools.maptool.client.AppActions$ClientAction.lambda$runBackground$0(AppActions.java:3496)
at java.base/java.lang.Thread.run(Thread.java:831)
18:27:52.546 (WebRTCServerConnection.java:70) [WebSocketConnectReadThread-81] INFO - S WebSocket connected
18:27:52.762 (WebRTCClientConnection.java:136) [WebSocketConnectReadThread-84] INFO - C WebSocket connected
18:27:52.922 (WebRTCClientConnection.java:408) [WebRTCClientConnection.WebRTCThread_skullman] INFO - C PeerConnection.onRenegotiationNeeded
18:27:52.926 (WebRTCClientConnection.java:305) [WebRTCClientConnection.WebRTCThread_skullman] INFO - C PeerConnection.onSignalingChange: HAVE_LOCAL_OFFER
18:27:52.936 (WebRTCClientConnection.java:344) [WebRTCClientConnection.WebRTCThread_skullman] INFO - C PeerConnection.onIceGatheringChange GATHERING
[sentry-pool-1-thread-2] WARN io.sentry.connection.AbstractConnection.lockdown - Initiated a temporary lockdown because of exception: {"detail":"bad sentry DSN public key"}
[sentry-pool-1-thread-2] ERROR io.sentry.connection.AsyncConnection - An exception occurred while sending the event to Sentry.
io.sentry.connection.ConnectionException: {"detail":"bad sentry DSN public key"}
at io.sentry.connection.HttpConnection.doSend(HttpConnection.java:216)
at io.sentry.connection.AbstractConnection.send(AbstractConnection.java:88)
at io.sentry.connection.AsyncConnection$EventSubmitter.run(AsyncConnection.java:187)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
at java.base/java.lang.Thread.run(Thread.java:831)
Caused by: java.io.IOException: Server returned HTTP response code: 400 for URL: https://sentry.io/api/1404248/store/
at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1985)
at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1577)
at java.base/sun.net.www.protocol.https.HttpsURLConnectionImpl.getInputStream(HttpsURLConnectionImpl.java:224)
at io.sentry.connection.HttpConnection.doSend(HttpConnection.java:172)
... 5 more
18:27:53.094 (WebRTCClientConnection.java:305) [WebRTCClientConnection.WebRTCThread_skullman@Draconis] INFO - S PeerConnection.onSignalingChange: HAVE_REMOTE_OFFER
18:27:53.096 (WebRTCClientConnection.java:73) [WebRTCClientConnection.WebRTCThread_skullman@Draconis] INFO - S setRemoteDescription success.
18:27:53.098 (WebRTCClientConnection.java:305) [WebRTCClientConnection.WebRTCThread_skullman@Draconis] INFO - S PeerConnection.onSignalingChange: STABLE
18:27:53.100 (WebRTCClientConnection.java:344) [WebRTCClientConnection.WebRTCThread_skullman@Draconis] INFO - S PeerConnection.onIceGatheringChange GATHERING
18:27:53.240 (WebRTCClientConnection.java:305) [WebRTCClientConnection.WebRTCThread_skullman] INFO - C PeerConnection.onSignalingChange: STABLE
18:27:53.240 (WebRTCClientConnection.java:329) [WebRTCClientConnection.WebRTCThread_skullman] INFO - C PeerConnection.onIceConnectionChange CHECKING
18:27:53.241 (WebRTCClientConnection.java:243) [WebRTCClientConnection.WebRTCThread_skullman] INFO - C setRemoteDescription success.
18:27:53.256 (WebRTCClientConnection.java:310) [WebRTCClientConnection.WebRTCThread_skullman] INFO - C PeerConnection.onConnectionChange CONNECTING
18:27:53.256 (WebRTCClientConnection.java:310) [WebRTCClientConnection.WebRTCThread_skullman@Draconis] INFO - S PeerConnection.onConnectionChange CONNECTING
18:27:53.257 (WebRTCClientConnection.java:344) [WebRTCClientConnection.WebRTCThread_skullman] INFO - C PeerConnection.onIceGatheringChange COMPLETE
18:27:53.257 (WebRTCClientConnection.java:329) [WebRTCClientConnection.WebRTCThread_skullman@Draconis] INFO - S PeerConnection.onIceConnectionChange CHECKING
18:27:53.257 (WebRTCClientConnection.java:344) [WebRTCClientConnection.WebRTCThread_skullman@Draconis] INFO - S PeerConnection.onIceGatheringChange COMPLETE
18:27:53.258 (WebRTCClientConnection.java:310) [WebRTCClientConnection.WebRTCThread_skullman] INFO - C PeerConnection.onConnectionChange CONNECTED
18:27:53.258 (WebRTCClientConnection.java:310) [WebRTCClientConnection.WebRTCThread_skullman@Draconis] INFO - S PeerConnection.onConnectionChange CONNECTED
18:27:53.258 (WebRTCClientConnection.java:329) [WebRTCClientConnection.WebRTCThread_skullman] INFO - C PeerConnection.onIceConnectionChange CONNECTED
18:27:53.258 (WebRTCClientConnection.java:329) [WebRTCClientConnection.WebRTCThread_skullman@Draconis] INFO - S PeerConnection.onIceConnectionChange CONNECTED
18:27:53.258 (WebRTCClientConnection.java:329) [WebRTCClientConnection.WebRTCThread_skullman] INFO - C PeerConnection.onIceConnectionChange COMPLETED
18:27:53.261 (WebRTCClientConnection.java:440) [WebRTCClientConnection.WebRTCThread_skullman] INFO - C localDataChannel onStateChange OPEN
18:27:53.261 (WebRTCClientConnection.java:395) [WebRTCClientConnection.WebRTCThread_skullman@Draconis] INFO - S PeerConnection.onDataChannel
18:27:53.262 (WebRTCClientConnection.java:440) [WebRTCClientConnection.WebRTCThread_skullman@Draconis] INFO - S localDataChannel onStateChange OPEN
18:27:53.264 (ServerHandshake.java:212) [WebRTCClientConnection.WebRTCThread_skullman@Draconis] INFO - skullman@Draconis :got: CLIENT_INIT_MSG
18:27:53.266 (ServerHandshake.java:202) [WebRTCClientConnection.WebRTCThread_skullman@Draconis] INFO - skullman@Draconis :send: USE_AUTH_TYPE_MSG
18:27:53.267 (ClientHandshake.java:155) [WebRTCClientConnection.WebRTCThread_skullman] INFO - skullman :got: USE_AUTH_TYPE_MSG
18:27:53.271 (ClientHandshake.java:145) [WebRTCClientConnection.WebRTCThread_skullman] INFO - skullman :send: CLIENT_AUTH_MESSAGE
18:27:53.272 (ServerHandshake.java:212) [WebRTCClientConnection.WebRTCThread_skullman@Draconis] INFO - skullman@Draconis :got: CLIENT_AUTH_MESSAGE
18:27:53.272 (ServerHandshake.java:202) [WebRTCClientConnection.WebRTCThread_skullman@Draconis] INFO - skullman@Draconis :send: CONNECTION_SUCCESSFUL_MSG
18:27:53.277 (ClientHandshake.java:155) [WebRTCClientConnection.WebRTCThread_skullman] INFO - skullman :got: CONNECTION_SUCCESSFUL_MSG
To Reproduce
Start a WebRTC server a bunch of times and get unlucky.
Expected Behaviour
Local client is always able to send messages.
Screenshots
No response
MapTool Info
1.11.4 with WebRTC patch
Desktop
Linux[Debian]
Additional Context
No response
should also be resolved by #3331 and #3321
@fishface60 can you test this with the 1.12.0 Alpha release?
@fishface60 can you test this with the 1.12.0 Alpha release?
Sorry I didn't reply sooner. I didn't test the alpha because the beta came out before I got around to it. I've tried to reproduce this a bunch more times than it took for me to happen on its own and couldn't get it to happen, so I think this error is fixed.
While trying I got a bunch of this error though:
17:39:55.078 (WebRTCClientConnection.java:442) [WebRTCClientConnection.WebRTCThread_Mike@test] INFO - S localDataChannel onStateChange CLOSING
17:39:55.078 (WebRTCClientConnection.java:442) [WebRTCClientConnection.WebRTCThread_Mike@test] INFO - S localDataChannel onStateChange CLOSED
Exception in thread "WebRTCClientConnection.handleDisconnect" java.lang.NullPointerException: Cannot invoke "net.rptools.maptool.model.player.Player.getTransferablePlayer()" because the return value of "java.util.Map.get(Object)" is null
at net.rptools.maptool.server.MapToolServerConnection.connectionRemoved(MapToolServerConnection.java:121)
at net.rptools.clientserver.simple.server.AbstractServerConnection.fireClientDisconnect(AbstractServerConnection.java:128)
at net.rptools.clientserver.simple.server.AbstractServerConnection.handleDisconnect(AbstractServerConnection.java:137)
at net.rptools.clientserver.simple.AbstractConnection.fireDisconnect(AbstractConnection.java:113)
at net.rptools.clientserver.simple.client.WebRTCClientConnection.lambda$fireDisconnectAsync$0(WebRTCClientConnection.java:477)
at java.base/java.lang.Thread.run(Unknown Source)
I think this is handling a disconnect from a previous connection since it has happened before any clients have joined the current connection, and data channels close may happen after the client has closed, since the existing WebRTC connections aren't closed when the client times out, only when the server is taken down.
It also seems that FAILED
isn't the terminal state for a WebRTC connection, since I experimented with suspending my MapTool client to cause it to disconnect and discovered that if I resumed the process after it went into FAILED
it could return to DISCONNECTED
and then back to FAILED
which also causes that exception.
I'll open an issue after I have a better idea of what's going on.
Thanks!