Platform: Mini-PC Celeron amd-64 architecture, Ubuntu 18 and OH 2.3.0 Stable
4 Gb RAM, 110 GB SSD.
java version “1.8.0_191”
Java™ SE Runtime Environment (build 1.8.0_191-b12)
Java HotSpot™ 64-Bit Server VM (build 25.191-b12, mixed mode)
For the last couple of days, this has turned into a real issue.
In the middle of the night the logg is flooded with messages like these:
2018-12-06 08:11:59.049 [WARN ] [io.openhabcloud.internal.CloudClient] - Jetty request 5905460 failed: null
2018-12-06 08:11:59.231 [WARN ] [io.openhabcloud.internal.CloudClient] - Jetty request 5905461 failed: null
2018-12-06 08:12:21.557 [WARN ] [io.openhabcloud.internal.CloudClient] - Jetty request 5905510 failed: null
2018-12-06 08:12:21.809 [WARN ] [io.openhabcloud.internal.CloudClient] - Jetty request 5905511 failed: null
2018-12-06 08:12:28.856 [WARN ] [io.openhabcloud.internal.CloudClient] - Jetty request 5905529 failed: null
This causes OH2 to be completely absorbed by this error. No rules get activated. Still processor load is not over the top. Java process is about 25%, which is very high. The system responds to SSH login and I can restart OH2 via systemctl.
But de-facto OH2 is dead to the outside world. No data gets logged in influxdb, no rules work. I first experienced this a week ago but now it has happened again.
I’ll remove them and let you know in a couple of days how it goes.
Last night this started at 06:05 and continued until restart at 08:15. At that time 06:05 I did not access any UI. Previous time was three days ago when it started at 07:55 There are no rules or anything that fire at these times.
Normally I access the Classic UI locally from my iPhone. I also access Basic UI via the Cloud connector and Chrome web browser. I do not get any error messages when doing this but it happens spontaneously.
There are some 50 Items in my configuration. All visible to the cloud connector.
Are all of them exposed?
Note: You don’t need to expose ANY Item in the Cloud connector configuration if you simply want remote access and notifications.
Exposing Items is for integration purposes to 3rd party applications like IFTTT, Alexa, Google Assistant, etc.
Exposing Items increases the load both on your OH2 instance as well as on the myopenhab.org Cloud instance. Try to avoid it if you don’t really need this functionality
Maybe some more light on the subject:
This is the events.log right before the “crash”:
2018-12-06 06:01:25.481 [vent.ItemStateChangedEvent] - SENSORLillaFRrDet_ActualTemperature changed from 8.3 ℃ to 8.4 ℃
2018-12-06 06:05:17.266 [hingStatusInfoChangedEvent] - 'tellstick:telldus-live:d49721f1' changed from OFFLINE (COMMUNICATION_ERROR) to ONLINE
2018-12-06 06:05:17.267 [hingStatusInfoChangedEvent] - 'tellstick:switch:d49721f1:129866' changed from OFFLINE (COMMUNICATION_ERROR) to ONLINE
2018-12-06 06:05:17.269 [me.event.ThingUpdatedEvent] - Thing 'tellstick:switch:d49721f1:129866' has been updated.
2018-12-06 06:05:17.270 [hingStatusInfoChangedEvent] - 'tellstick:switch:d49721f1:291127' changed from OFFLINE (COMMUNICATION_ERROR) to ONLINE
Then things went off the rails.
I am running a Tellstick Net remotely at another location and I have a Thing “Telldus Live gateway” to connect and read the status of some sensors and switches.
This binding has caused similar problems (lockup) before but then the error messages have been:
2018-11-30 07:00:51.730 [WARN ] [nal.live.TelldusLiveDeviceController] - TimeoutException error in get
at org.asynchttpclient.netty.NettyResponseFuture.get(NettyResponseFuture.java:169) ~[?:?]
at org.openhab.binding.tellstick.internal.live.TelldusLiveDeviceController.innerCallRest(TelldusLiveDeviceController.java:308) ~[?:?]
at org.openhab.binding.tellstick.internal.live.TelldusLiveDeviceController.callRestMethod(TelldusLiveDeviceController.java:282) ~[?:?]
at org.openhab.binding.tellstick.internal.live.TelldusLiveBridgeHandler.updateDevices(TelldusLiveBridgeHandler.java:127) ~[?:?]
at org.openhab.binding.tellstick.internal.live.TelldusLiveBridgeHandler.refreshDeviceList(TelldusLiveBridgeHandler.java:114) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:?]
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) [?:?]
Could there be any connection? If so, I could remove this binding and associated Items
Or… the internal client in the openhabcloud addon is calling your Jetty Web Server to get info from the REST API about the state of your Items and the calls fail for some reason… (system overload caused by another root-cause or miss-configuration of something?)
Thanks for the tip!
I am on a fiber connection and the OH2 is connected over cable but it is worth checking. If a bad internet connection is the case, then maybe there should be some timeout settable in the service configuration?
I think that the problem is local (see my “improved” assumption )
From the warning message, I understand that: io.openhabcloud.internal.CloudClient sends requests to Jetty and gets null responses
Maybe you can put the io.openhabcloud addon in TRACE log level to see what the heck is the io.openhabcloud.internal.CloudClient asking from Jetty during the failure?
They appear when I launch the android application or update the data in it.
This has been happening for a long time, I do not remember on which assembly I noticed, it was exactly on 1445, now it was updated on 1451, warnings are still present.
This time it happened on the local connection.
One theory about why it happened at night might be connected to how iPhone handles apps, which I know almost nothing about…
When you close an app I wonder if it really is stopped or if it continues to be connected in the background? It might be, that it stayed active in the background until iOS decided to unload it and a pipe was broken. But this is just a theory from my side. In iOS it is easy to go back to an app you have used. You double-click the button and all apps line up until you swipe them off the screen but until you do that, it seems they are somehow at least partly active.
But I might be barking up the wrong tree.
I think that you may be right here (I also don’t know how iOS handles internally the apps)
Personally, I use both Android (heavy use since it’s mine) and iOS (small use from my wife)
I have the openHAB Cloud connector running and I have never seen this in my logs
but… I don’t use myopenhab.org to access remotely my local OH2 instance from the mobile phones.
I have setup a reverse proxy with encryption (https) and authentication and I connect directly from remote.
I was avoiding myopenhab.org for months/years until recently (big fanboy of Intranet of Things concept ) , but then I decided that I want to play with Google Assistant (GA), so it was a “forced” decision I could setup my own openHAB Cloud instance but I consider it too much for my scenario (happy with the reverse proxy and satisfied with the response time of GA over myopenhab.org)
Soon we will have auth embedded in OH2 so the use of myopenhab.org should be reduced and the focus would be integrations (Alexa, IFTTT, Google, etc)