Java Websocket client disconnecting
BobClaerhout opened this issue · 12 comments
As discussed on gitter, I'm getting following exception when using the java websocket connection to ditto:
2020-04-22 11:05:58,389 DEBUG [org.ecl.dit.cli.mes.int.WebSocketMessagingProvider] (ditto-client-c4e0b023-00c1-439d-a1da-a4c6efbcce00-104) Client <ditto:68ca9e13-63df-4fe3-a43d-59a1b8c9bb10>: Got TWIN ThingErrorResponse: <GatewayWebsocketSessionExpiredException: The websocket session expired because the JWT used for authentication has expired. - You need to periodically refresh your websocket session with a new JWT.>
2020-04-22 11:05:58,389 TRACE [org.ecl.dit.cli.int.ResponseForwarder] (ditto-client-c4e0b023-00c1-439d-a1da-a4c6efbcce00-104) Received response for correlation-id <e44741df-a847-4f45-989d-67f6ef376d22>.
2020-04-22 11:05:58,389 DEBUG [org.ecl.dit.cli.int.ResponseForwarder] (ditto-client-c4e0b023-00c1-439d-a1da-a4c6efbcce00-104) No promise found for response with correlation-id <e44741df-a847-4f45-989d-67f6ef376d22>!
2020-04-22 11:05:58,387 INFO [org.ecl.dit.cli.mes.int.WebSocketMessagingProvider] (ditto-client-c4e0b023-00c1-439d-a1da-a4c6efbcce00-106) Client <ditto:68ca9e13-63df-4fe3-a43d-59a1b8c9bb10>: WebSocket connection to endpoint <ws://ditto-nginx:8081/ws/2> was closed by Server with code <1000> and reason <null>.
2020-04-22 11:05:58,389 INFO [org.ecl.dit.cli.mes.int.WebSocketMessagingProvider] (ditto-client-c4e0b023-00c1-439d-a1da-a4c6efbcce00-106) Client <ditto:68ca9e13-63df-4fe3-a43d-59a1b8c9bb10>: Reconnection is enabled. Reconnecting in <5> seconds ...
We are using the following snippet to setup the connection:
final AuthenticationProvider authenticationProvider =
AuthenticationProviders.clientCredentials(ClientCredentialsAuthenticationConfiguration.newBuilder()
.clientId(dittoConfiguration.keycloakClientId())
.clientSecret(dittoConfiguration.keycloakClientSecret())
.scopes(Collections.singleton("*"))
.tokenEndpoint(dittoConfiguration.keycloakEndpoint())
.build());
The ditto SDK client version we are using, is version 1.0.0. We tested this with both Ditto 1.0.0 and 1.1.0 and are encoutering the same issues.
Could be related to TakahikoKawasaki/nv-websocket-client#196.
Hi @BobClaerhout have you tried Ditto and SDK 1.1.0? I had reproduced your issue with Ditto 1.0.0, but it seemed to be fixed with 1.1.0 for me.
Hi @jokraehe didn't try with SDK 1.1.0 yet. Will try that.
Installed this SDK 1.1.0 and the issue still remains.
Ok. We'll have to reproduce it o our end and let you know when we fixed the issue.
Hi @BobClaerhout sorry this one was in limbo for so long. Did you also upgrade Ditto >=1.1.0? Or only the SDK? There was a bug in the backend which led to this behaviour, but was fixed with 1.1.0 and we can't reproduce the faulty behaviour.
Hi @BobClaerhout,
do you still encounter this bug? I tried to reproduce this with Ditto 1.1.1 and Ditto Client 1.1.1. The refresh seems to be working from my side.
Maybe you can try to increase the expiry grace period in ClientCredentialsAuthenticationConfiguration#216. It configures the timespan between expected expiration and getting a new one. You can also set a breakpoint in AbstractTokenAuthenticationProvider#117 and check if a valid token will be sent to Ditto when the refresh happens.
@jokraehe, @ffendt, we deployed this morning ditto version 1.1.1 and are using the Java SDK 1.1.1 and are still encountering issues with it. See following logs:
2020-06-29 08:46:21,024 INFO [org.ecl.dit.cli.mes.int.WebSocketMessagingProvider] (ditto-client-6d0f339e-ba3b-4151-96d0-368377b4f5bf-8) Client <ditto:1cf60dd3-bfe5-4a79-93c7-a5a03781882b>: WebSocket connection to endpoint <ws://ditto-nginx:8081/ws/2> was closed by Server with code <1000> and reason <null>.
2020-06-29 08:46:21,025 INFO [org.ecl.dit.cli.mes.int.WebSocketMessagingProvider] (ditto-client-6d0f339e-ba3b-4151-96d0-368377b4f5bf-8) Client <ditto:1cf60dd3-bfe5-4a79-93c7-a5a03781882b>: Reconnection is enabled. Reconnecting in <5> seconds ...
June 29th 2020, 10:36:11.9702020-06-29 08:36:11,970 ERROR [org.ecl.dit.cli.mes.int.WebSocketMessagingProvider] (vert.x-eventloop-thread-0) Client <ditto:1cf60dd3-bfe5-4a79-93c7-a5a03781882b>: WebSocket is not connected - going to discard message '{"topic":"aloxy/463438340047002A/things/twin/commands/modify","headers":{"content-type":"application/vnd.eclipse.ditto+json","version":2,"response-required":true,"correlation-id":"93a8b88c-5755-4602-878d-14f562390f60"},"path":"/features/test","value":{"__schemaVersion":2,"properties":{"test":0.0, "timestamp":"2020-06-29 08:36:11.949"}}}'
June 29th 2020, 10:37:11.9712020-06-29 08:37:11,971 ERROR [io.alo.mes] (ditto-client--adaptable-bus-be344b73-4b3f-4579-975c-01c1849b9a91-3) Error updating feature on ditto: java.util.concurrent.CompletionException: java.util.concurrent.TimeoutException: Timed out after PT1M
June 29th 2020, 10:37:11.9722020-06-29 08:37:11,972 ERROR [io.alo.mes] (ditto-client--adaptable-bus-be344b73-4b3f-4579-975c-01c1849b9a91-3) Exception during message handling: java.util.concurrent.CompletionException: java.util.concurrent.TimeoutException: Timed out after PT1M
2020-06-29 08:37:11,972 ERROR [io.alo.mes] (ditto-client--adaptable-bus-be344b73-4b3f-4579-975c-01c1849b9a91-3) Error handling message: java.util.concurrent.CompletionException: java.util.concurrent.TimeoutException: Timed out after PT1M
Besides the error, it also seems that the SDK is not returning then exception when it happens. Almost exactly 1 minute after the exception is logged (saying it is discarding the message) we get a timeout exception saying the completionStage did not complete within 1 minute.
Did you also set a breakpoint at the line I explained and checked if your code answers with a valid token?
Will close this inactive issue for now, please add another issue if you encounter this again and can provide a reproducer.
This could be caused by eclipse-ditto/ditto#922 (so by the Ditto backend).
If you still encounter this bug, consider watching that PR which should be released as part of a Ditto bugfix release 1.5.1 soon 👀