Hi,
after upgrading my openhab instance to the latest 2.5.0 snapshot docker image (it also happened with earlier snapshots) the connection to my self-hosted openHAB Cloud instance no longer works. The connection is actually established but is reset after 10s due to some timeout event, repeatedly and reproducably.
Connections to myopenhab.org are fine, though, so I wonder what’s wrong with my instance which is running the latest code and which works fine with 2.4. Any hints on how to debug this would be much appreciated.
The log on the client side looks like this:
2019-06-03 21:08:54.714 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO connected
2019-06-03 21:08:54.714 [INFO ] [io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = b74c886c-7c89-407d-b594-3207ede5bfab, base URL = http://localhost:8080)
2019-06-03 21:09:04.718 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO error: {}
io.socket.engineio.client.EngineIOException: xhr poll error
at io.socket.engineio.client.Transport.onError(Transport.java:63) [219:io.socket.engine.io-client:1.0.0]
at io.socket.engineio.client.transports.PollingXHR.access$100(PollingXHR.java:26) [219:io.socket.engine.io-client:1.0.0]
at io.socket.engineio.client.transports.PollingXHR$6$1.run(PollingXHR.java:140) [219:io.socket.engine.io-client:1.0.0]
at io.socket.thread.EventThread$2.run(EventThread.java:80) [219:io.socket.engine.io-client:1.0.0]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.net.SocketTimeoutException: timeout
at okio.Okio$4.newTimeoutException(Okio.java:232) ~[?:?]
at okio.AsyncTimeout.exit(AsyncTimeout.java:285) ~[?:?]
at okio.AsyncTimeout$2.read(AsyncTimeout.java:241) ~[?:?]
at okio.RealBufferedSource.indexOf(RealBufferedSource.java:354) ~[?:?]
at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:226) ~[?:?]
at okhttp3.internal.http1.Http1Codec.readHeaderLine(Http1Codec.java:215) ~[?:?]
at okhttp3.internal.http1.Http1Codec.readResponseHeaders(Http1Codec.java:189) ~[?:?]
at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.java:88) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147) ~[?:?]
at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:45) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121) ~[?:?]
at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:93) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121) ~[?:?]
at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147) ~[?:?]
at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:126) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121) ~[?:?]
at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:254) ~[?:?]
at okhttp3.RealCall$AsyncCall.execute(RealCall.java:200) ~[?:?]
at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32) ~[?:?]
... 3 more
Caused by: java.net.SocketException: Socket closed
at java.net.SocketInputStream.read(SocketInputStream.java:204) ~[?:?]
at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[?:?]
at sun.security.ssl.InputRecord.readFully(InputRecord.java:465) ~[?:?]
at sun.security.ssl.InputRecord.read(InputRecord.java:503) ~[?:?]
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:975) ~[?:?]
at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:933) ~[?:?]
at sun.security.ssl.AppInputStream.read(AppInputStream.java:105) ~[?:?]
at okio.Okio$2.read(Okio.java:140) ~[?:?]
at okio.AsyncTimeout$2.read(AsyncTimeout.java:237) ~[?:?]
at okio.RealBufferedSource.indexOf(RealBufferedSource.java:354) ~[?:?]
at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.java:226) ~[?:?]
at okhttp3.internal.http1.Http1Codec.readHeaderLine(Http1Codec.java:215) ~[?:?]
at okhttp3.internal.http1.Http1Codec.readResponseHeaders(Http1Codec.java:189) ~[?:?]
at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.java:88) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147) ~[?:?]
at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:45) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121) ~[?:?]
at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:93) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121) ~[?:?]
at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121) ~[?:?]
at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147) ~[?:?]
at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:126) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147) ~[?:?]
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121) ~[?:?]
at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:254) ~[?:?]
at okhttp3.RealCall$AsyncCall.execute(RealCall.java:200) ~[?:?]
at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32) ~[?:?]
... 3 more
2019-06-03 21:09:04.749 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO disconnected
2019-06-03 21:09:04.749 [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = b74c886c-7c89-407d-b594-3207ede5bfab, base URL = http://localhost:8080)
2019-06-03 21:09:06.203 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO connected
2019-06-03 21:09:06.204 [INFO ] [io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = b74c886c-7c89-407d-b594-3207ede5bfab, base URL = http://localhost:8080)
The according log on the server side:
2019-06-03 21:08:54:5454 info: openHAB-cloud: Authorizing incoming openHAB connection
2019-06-03 21:08:54:5454 info: openHAB-cloud: Incoming openHAB connection for uuid b74c886c-7c89-407d-b594-3207ede5bfab
2019-06-03 21:08:54:5454 info: openHAB-cloud: Connected openHAB with b74c886c-7c89-407d-b594-3207ede5bfab successfully
2019-06-03 21:08:54:5454 info: openHAB-cloud: uuid b74c886c-7c89-407d-b594-3207ede5bfab server address undefined:undefined my address undefined:undefined
2019-06-03 21:09:04:044 info: openHAB-cloud: Disconnected b74c886c-7c89-407d-b594-3207ede5bfab
2019-06-03 21:09:06:066 info: openHAB-cloud: Authorizing incoming openHAB connection
Cheers!