Disconnected from the openHAB Cloud service

[marcolino7 (marcolino)]

Hi all,
openhab 3.3.0 and cloud connector configured.
Sometime, in the past very often, now a couple of time a week, i got cloud connector not working.
Here is the last log collected. This morning around 10:29 connector stop to work:

2023-01-12 10:29:37.388	INFO 	io.openhabcloud.internal.CloudClient	Disconnected from the openHAB Cloud service (UUID = XXXXXXXXXXXXXXXXXXXXXXXXXXXXX, base URL = http://localhost:8080)
2023-01-12 10:29:38.889	DEBUG	io.openhabcloud.internal.CloudClient	Socket.IO re-connecting (attempt 1)
2023-01-12 10:29:49.013	DEBUG	io.openhabcloud.internal.CloudClient	Error connecting to the openHAB Cloud instance: EngineIOException xhr poll error. Should reconnect automatically.
2023-01-12 10:29:49.014	DEBUG	io.openhabcloud.internal.CloudClient	Socket.IO re-connect attempt error: SocketIOException Connection error
2023-01-12 10:29:50.566	DEBUG	io.openhabcloud.internal.CloudClient	Socket.IO re-connecting (attempt 2)
2023-01-12 10:29:57.590	DEBUG	io.openhabcloud.internal.CloudClient	Socket.IO re-connected successfully (attempt 2)
2023-01-12 10:30:07.597	ERROR	io.openhabcloud.internal.CloudClient	Error connecting to the openHAB Cloud instance: EngineIOException xhr poll error. Reconnecting after 1064 ms.
2023-01-12 10:30:08.664	DEBUG	io.openhabcloud.internal.CloudClient	Socket.IO connecting
2023-01-12 10:30:17.816	DEBUG	io.openhabcloud.internal.CloudClient	Socket.IO connected
2023-01-12 10:30:17.816	INFO 	io.openhabcloud.internal.CloudClient	Connected to the openHAB Cloud service (UUID = XXXXXXXXXXXXXXXXXXXXXXXXXXXXX, base URL = http://localhost:8080)

Even if log say Connected, connector does not work. Google Home says me “Openhab is not available” and on https://myopenhab.org/ i see that is offline.
To restore the situation I have to access to Interface->System Service->OpenHab Cloud and Do Save

At this point all go back work again and I got this into logs:

2023-01-12 12:04:41.973	DEBUG	o.openhabcloud.internal.CloudService	bundle org.openhab.io.openhabcloud:3.3.0 (297)[org.openhab.io.openhabcloud.internal.CloudService(332)] : ConfigurableComponentHolder configuration updated for pid org.openhab.openhabcloud with change count 7
2023-01-12 12:04:41.974	DEBUG	o.openhabcloud.internal.CloudService	bundle org.openhab.io.openhabcloud:3.3.0 (297)[org.openhab.io.openhabcloud.internal.CloudService(332)] : Querying state active
2023-01-12 12:04:41.975	DEBUG	o.openhabcloud.internal.CloudService	bundle org.openhab.io.openhabcloud:3.3.0 (297)[org.openhab.io.openhabcloud.internal.CloudService(332)] : Querying state active
2023-01-12 12:04:41.976	DEBUG	o.openhabcloud.internal.CloudService	bundle org.openhab.io.openhabcloud:3.3.0 (297)[org.openhab.io.openhabcloud.internal.CloudService(332)] : getting modified: modified
2023-01-12 12:04:41.976	DEBUG	o.openhabcloud.internal.CloudService	bundle org.openhab.io.openhabcloud:3.3.0 (297)[org.openhab.io.openhabcloud.internal.CloudService(332)] : Locating method modified in class org.openhab.io.openhabcloud.internal.CloudService
2023-01-12 12:04:41.976	DEBUG	o.openhabcloud.internal.CloudService	bundle org.openhab.io.openhabcloud:3.3.0 (297)[org.openhab.io.openhabcloud.internal.CloudService(332)] : Declared Method org.openhab.io.openhabcloud.internal.CloudService.modified([interface org.osgi.service.component.ComponentContext]) not found
2023-01-12 12:04:41.976	DEBUG	o.openhabcloud.internal.CloudService	bundle org.openhab.io.openhabcloud:3.3.0 (297)[org.openhab.io.openhabcloud.internal.CloudService(332)] : Found modified method: protected void org.openhab.io.openhabcloud.internal.CloudService.modified(java.util.Map)
2023-01-12 12:04:41.976	DEBUG	o.openhabcloud.internal.CloudService	bundle org.openhab.io.openhabcloud:3.3.0 (297)[org.openhab.io.openhabcloud.internal.CloudService(332)] : invoking modified: modified: parameters [org.apache.felix.scr.impl.helper.ReadOnlyDictionary]
2023-01-12 12:04:41.976	DEBUG	o.openhabcloud.internal.CloudService	remoteAccessEnabled is not set, keeping value 'true'
2023-01-12 12:04:41.977	DEBUG	o.openhabcloud.internal.CloudService	Using secret at '/openhab/userdata/openhabcloud/secret' with content 'XXXXXXXXXXXXXXXXXXXXXXXXXXXXX'
2023-01-12 12:04:41.977	DEBUG	o.openhabcloud.internal.CloudService	UUID = XXXXXXXXXXXXXXXXXXXXXXXXXXXXX, secret = XXXXXXXXXXXXXXXXXXXXXXXXXXXXX
2023-01-12 12:04:41.978	INFO 	io.openhabcloud.internal.CloudClient	Shutting down openHAB Cloud service connection
2023-01-12 12:04:41.978	DEBUG	o.openhabcloud.internal.CloudService	Using secret at '/openhab/userdata/openhabcloud/secret' with content 'XXXXXXXXXXXXXXXXXXXXXXXXXXXXX'
2023-01-12 12:04:41.978	DEBUG	o.openhabcloud.internal.CloudService	bundle org.openhab.io.openhabcloud:3.3.0 (297)[org.openhab.io.openhabcloud.internal.CloudService(332)] : invoked modified: modified
2023-01-12 12:04:41.978	DEBUG	o.openhabcloud.internal.CloudService	bundle org.openhab.io.openhabcloud:3.3.0 (297)[org.openhab.io.openhabcloud.internal.CloudService(332)] : No change in target property for dependency $000: currently registered: true
2023-01-12 12:04:41.978	DEBUG	o.openhabcloud.internal.CloudService	bundle org.openhab.io.openhabcloud:3.3.0 (297)[org.openhab.io.openhabcloud.internal.CloudService(332)] : No change in target property for dependency $001: currently registered: true
2023-01-12 12:04:41.978	DEBUG	o.openhabcloud.internal.CloudService	bundle org.openhab.io.openhabcloud:3.3.0 (297)[org.openhab.io.openhabcloud.internal.CloudService(332)] : No change in target property for dependency $002: currently registered: true
2023-01-12 12:04:41.978	DEBUG	o.openhabcloud.internal.CloudService	bundle org.openhab.io.openhabcloud:3.3.0 (297)[org.openhab.io.openhabcloud.internal.CloudService(332)] : Querying state active
2023-01-12 12:04:41.979	DEBUG	io.openhabcloud.internal.CloudClient	Socket.IO disconnected: io client disconnect
2023-01-12 12:04:41.979	INFO 	io.openhabcloud.internal.CloudClient	Disconnected from the openHAB Cloud service (UUID = XXXXXXXXXXXXXXXXXXXXXXXXXXXXX, base URL = http://localhost:8080)
2023-01-12 12:04:41.983	DEBUG	ons.NotificationModuleHandlerFactory	bundle org.openhab.io.openhabcloud:3.3.0 (297)[org.openhab.io.openhabcloud.internal.actions.NotificationModuleHandlerFactory(334)] : dm $000 tracking 2 SingleStatic modified {org.openhab.io.openhabcloud.internal.CloudService, org.openhab.core.events.EventSubscriber, org.openhab.core.model.script.engine.action.ActionService}={service.config.factory=false, service.id=572, service.bundleid=297, service.scope=bundle, service.config.category=io, service.pid=[org.openhab.openhabcloud, org.openhab.openhabcloud], service.config.label=openHAB Cloud, component.name=org.openhab.io.openhabcloud.internal.CloudService, service.config.description.uri=io:openhabcloud, component.id=332} (enter)
2023-01-12 12:04:41.983	DEBUG	ons.NotificationModuleHandlerFactory	bundle org.openhab.io.openhabcloud:3.3.0 (297)[org.openhab.io.openhabcloud.internal.actions.NotificationModuleHandlerFactory(334)] : dm $000 tracking 2 SingleStatic modified {org.openhab.io.openhabcloud.internal.CloudService, org.openhab.core.events.EventSubscriber, org.openhab.core.model.script.engine.action.ActionService}={service.config.factory=false, service.id=572, service.bundleid=297, service.scope=bundle, service.config.category=io, service.pid=[org.openhab.openhabcloud, org.openhab.openhabcloud], service.config.label=openHAB Cloud, component.name=org.openhab.io.openhabcloud.internal.CloudService, service.config.description.uri=io:openhabcloud, component.id=332} (exit)
2023-01-12 12:04:41.983	DEBUG	o.openhabcloud.internal.CloudService	bundle org.openhab.io.openhabcloud:3.3.0 (297)[org.openhab.io.openhabcloud.internal.CloudService(332)] : ImmediateComponentHolder Finished configuring the dependency managers for component for pid org.openhab.openhabcloud 
2023-01-12 12:04:41.983	DEBUG	io.openhabcloud.internal.CloudClient	Socket.IO connecting
2023-01-12 12:04:41.983	DEBUG	o.openhabcloud.internal.CloudService	bundle org.openhab.io.openhabcloud:3.3.0 (297)[org.openhab.io.openhabcloud.internal.CloudService(332)] : ImmediateComponentHolder Will not enable component for pid org.openhab.openhabcloud: holder enabled state: true, metadata enabled: true 
2023-01-12 12:04:42.277	DEBUG	io.openhabcloud.internal.CloudClient	Socket.IO connected
2023-01-12 12:04:42.277	INFO 	io.openhabcloud.internal.CloudClient	Connected to the openHAB Cloud service (UUID = XXXXXXXXXXXXXXXXXXXXXXXXXXXXX, base URL = http://localhost:8080)

Thanks in advance for looking into this.

Marco

[MilesT (Miles Taylor)]

Hi @marcolino7,

It failed for me too 09:30 UK time. Are you in Europe, it would be the same time?

Did you see the ping time increase?

2023-01-12 09:28:12.765 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO ping
2023-01-12 09:28:12.789 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO pong: 24 ms
2023-01-12 09:28:37.790 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO ping
2023-01-12 09:28:37.816 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO pong: 26 ms
2023-01-12 09:29:02.819 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO ping
2023-01-12 09:29:03.342 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO pong: 522 ms
2023-01-12 09:29:28.344 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO ping
2023-01-12 09:29:29.872 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO pong: 1529 ms
2023-01-12 09:29:54.874 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO ping
2023-01-12 09:29:56.085 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO pong: 1212 ms
2023-01-12 09:30:21.091 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO ping
2023-01-12 09:30:26.095 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO CLOSE: ping timeout
2023-01-12 09:30:26.097 [WARN ] [io.openhabcloud.internal.CloudClient] - Socket.IO disconnected: ping timeout
2023-01-12 09:30:26.098 [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = 36…5d, base URL = http://localhost:8080)
2023-01-12 09:30:27.161 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO re-connecting (attempt 1)

[marcolino7 (marcolino)]

Hi @MilesT,
I am in Italy so actualy I am an hour ahead of you, so timing is correct. I have not ping increasing time, because my log is different from yours, but timing is the same

Marco

[niklas87 (Niklas)]

It’s an example for my OH instance losing the connection to the cloud frequently. I would rather expect OH not losing the connection to the cloud at all. At least not that often.

[MilesT (Miles Taylor)]

I’m not sure that it connected again properly, although it said it had. A few hours later was the next time I asked alexa to turn a light on and it failed as the cloud connector was offline. There were no further issues in the log, just the ping pongs.
I see the ping timeout is 5 seconds, which is quite long time for a ping response. Can anyone see the server to check if it is getting maxed out at busy times?

[the-ninth (Robert)]

I also have this issue - the connection to myopenhab seems to fail from time to time, in most cases it reconnects automatically, but sometimes it does not and I have to go into the cloud connector settings page and press save, after which the connection seems to be re-established.

Today it happened again, I noticed at 17:00 CET, however it might have been happening anytime during the day. Actually it seems the connection failed multipe times during the day, but in the previous instances it reconnected automatically.

Is there anything I can do as user to contribute to the resolution of this issue?

[MilesT (Miles Taylor)]

For me it failed this morning around 06:00 UK time. Locally the log says it has reconnected, but it hadn’t as it didn’t work at 06:10 and there was nothing else other than ping pongs. It seems local says it has reconnected, but cloud still says it is offline.
It did the same 2023-01-15 and 22:00.

2023-01-16 05:59:42.641 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO ping
2023-01-16 05:59:42.665 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO pong: 24 ms
2023-01-16 06:00:07.668 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO ping
2023-01-16 06:00:12.671 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO CLOSE: ping timeout
2023-01-16 06:00:12.674 [WARN ] [io.openhabcloud.internal.CloudClient] - Socket.IO disconnected: ping timeout
2023-01-16 06:00:12.676 [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = 36...5d, base URL = http://localhost:8080)
2023-01-16 06:00:13.934 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO re-connecting (attempt 1)
2023-01-16 06:00:13.937 [TRACE] [io.openhabcloud.internal.CloudClient] - Manager.EVENT_TRANSPORT
2023-01-16 06:00:13.939 [TRACE] [io.openhabcloud.internal.CloudClient] - Transport.EVENT_REQUEST_HEADERS
2023-01-16 06:00:24.080 [DEBUG] [io.openhabcloud.internal.CloudClient] - Error connecting to the openHAB Cloud instance: EngineIOException xhr poll error. Should reconnect automatically.
2023-01-16 06:00:24.087 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO re-connect attempt error: SocketIOException Connection error
2023-01-16 06:00:26.216 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO re-connecting (attempt 2)
2023-01-16 06:00:26.230 [TRACE] [io.openhabcloud.internal.CloudClient] - Manager.EVENT_TRANSPORT
2023-01-16 06:00:26.232 [TRACE] [io.openhabcloud.internal.CloudClient] - Transport.EVENT_REQUEST_HEADERS
2023-01-16 06:00:33.270 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO OPEN
2023-01-16 06:00:33.272 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO re-connected successfully (attempt 2)
2023-01-16 06:00:33.274 [TRACE] [io.openhabcloud.internal.CloudClient] - Manager.EVENT_TRANSPORT
2023-01-16 06:00:33.275 [TRACE] [io.openhabcloud.internal.CloudClient] - Transport.EVENT_REQUEST_HEADERS
2023-01-16 06:00:33.278 [TRACE] [io.openhabcloud.internal.CloudClient] - Transport.EVENT_REQUEST_HEADERS
2023-01-16 06:00:43.303 [WARN ] [io.openhabcloud.internal.CloudClient] - Error connecting to the openHAB Cloud instance: EngineIOException xhr poll error. Reconnecting after 1358 ms.
2023-01-16 06:00:43.307 [TRACE] [io.openhabcloud.internal.CloudClient] - Transport.EVENT_REQUEST_HEADERS
2023-01-16 06:00:43.310 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO CLOSE: forced close
2023-01-16 06:00:44.676 [TRACE] [io.openhabcloud.internal.CloudClient] - Manager.EVENT_TRANSPORT
2023-01-16 06:00:44.677 [TRACE] [io.openhabcloud.internal.CloudClient] - Transport.EVENT_REQUEST_HEADERS
2023-01-16 06:00:44.680 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO connecting
2023-01-16 06:00:54.822 [DEBUG] [io.openhabcloud.internal.CloudClient] - Error connecting to the openHAB Cloud instance: EngineIOException xhr poll error. Should reconnect automatically.
2023-01-16 06:00:56.180 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO re-connecting (attempt 1)
2023-01-16 06:00:56.183 [TRACE] [io.openhabcloud.internal.CloudClient] - Manager.EVENT_TRANSPORT
2023-01-16 06:00:56.185 [TRACE] [io.openhabcloud.internal.CloudClient] - Transport.EVENT_REQUEST_HEADERS
2023-01-16 06:01:06.326 [DEBUG] [io.openhabcloud.internal.CloudClient] - Error connecting to the openHAB Cloud instance: EngineIOException xhr poll error. Should reconnect automatically.
2023-01-16 06:01:06.333 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO re-connect attempt error: SocketIOException Connection error
2023-01-16 06:01:07.472 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO re-connecting (attempt 2)
.
.
.
2023-01-16 06:02:37.682 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO re-connecting (attempt 8)
2023-01-16 06:02:37.685 [TRACE] [io.openhabcloud.internal.CloudClient] - Manager.EVENT_TRANSPORT
2023-01-16 06:02:37.687 [TRACE] [io.openhabcloud.internal.CloudClient] - Transport.EVENT_REQUEST_HEADERS
2023-01-16 06:02:37.841 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO OPEN
2023-01-16 06:02:37.844 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO re-connected successfully (attempt 8)
2023-01-16 06:02:37.845 [TRACE] [io.openhabcloud.internal.CloudClient] - Manager.EVENT_TRANSPORT
2023-01-16 06:02:37.847 [TRACE] [io.openhabcloud.internal.CloudClient] - Transport.EVENT_REQUEST_HEADERS
2023-01-16 06:02:37.851 [TRACE] [io.openhabcloud.internal.CloudClient] - Transport.EVENT_REQUEST_HEADERS
2023-01-16 06:02:37.932 [TRACE] [io.openhabcloud.internal.CloudClient] - Socket.IO Packet: CONNECT (0)
2023-01-16 06:02:37.934 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO connected
2023-01-16 06:02:37.936 [INFO ] [io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = 36...5d, base URL = http://localhost:8080)
2023-01-16 06:02:37.939 [TRACE] [io.openhabcloud.internal.CloudClient] - Transport.EVENT_REQUEST_HEADERS
2023-01-16 06:03:02.852 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO ping
2023-01-16 06:03:02.875 [DEBUG] [io.openhabcloud.internal.CloudClient] - Socket.IO pong: 23 ms

[scha (Andreas Schmid)]

Had the same issue a few days ago, but in my case I also had this Shelly Binding - #3020 by Ranzkarl AND since I did a (physical) power off/on the issue is gone.
Maybe by accident, maybe the problem is network- and/or hardware-related…

Give it a try, but really disconnect the power. A “soft” reboot did NOT help!

[Josh_Schachat]

Hey Guys, I was victim to this a while ago (couple of months ago), installed the debug cloud connector binding that was created and was tracing ping and pongs etc… in the front tail. everything seemed to be working so great that I recently moved back to info debugging. I unfortunately have also come home to a disconnect and reconnect on my debug info (my trace is off) but Offline on my cloud connector with no functionality. I’m running OH3.3. Any more debugging steps I can take to assist I’m ready to take on but seems to be the same issue as before and a server side issue that is well known to the devs. hope we get to the bottom of it. Good Luck and thank you for everyone who is constantly contributing to this amazing platform.

[rpwong (Russ)]

Has anyone else entered a stable period, or is it just me? I haven’t had any disconnection events in four days. Which is slightly annoying, because I made some edits to my reconnection rule and was waiting for it to be triggered organically.

For anyone who thinks I’m tempting fate, don’t worry…it’ll almost certainly happen again. We already know that it seems to happen in waves; we just don’t know what causes the instability.

My current theory is that there’s a correlation between myopenHAB disconnections, Tesla’s stock prices, and phases of the moon. And maybe something to do with cryptocurrency, since everything seems to come back to that these days.

[massi (Massimo)]

Yes I can share your experience that it happens in waves: for 10 days or so it happened to me 1-3 times per day, than very recently it stopped for 3-4 days, then now yesterday happened again 2 times.

[momo90 (Chris)]

My connection just crashed
Last disconnection was about 3 or 4 days ago

[Flole]

This is most likely an issue on the server side which needs to be solved there. Someone needs to find a way to reproduce it though.

[rpwong (Russ)]

myopenHAB Maintenance Jan 29 @ 5pm GMT (DONE)

Hi, I am planning to deploy an updated build of myopenHAB tomorrow. This will cause openHAB connections to reconnect as our containers restart. The cloud service may be slow or unusable for 20-30 mins after this.

[Pedro_Liberal]

Crosses fingers!

[SHUred]

Hi there,
instead of opening a new topic im writing here.

Since 2 days it feels like my openHAB cloud is permanently disconnected
Its not possible to use it via Google Assistant

I tried to re-connect my google home account manually several times → “Could not reach openHAB”
I pressed the “Save” button on the openHAB Cloud Add-On
I rebooted my homeserver running openHAB via Docker container

Did i miss anything else to try?
Am i the only one?

[Mohamed_Negm (Negm)]

I have the same issue, but interesting enough, only with one deployment (i have two instances in two different locations).

Only one is going down regularly and never back up again without a full system reboot!