OH2 stable just stopped working (events.log frozen)

Good Morning,

today my (almost perfectly stable) OH2 setup (stable based on openhabian) just stopped working.

It was somehow triggered by my alarmclock this morning.
The events.log juste stopped after it was activated:

2017-06-24 06:30:01.129 [ItemCommandEvent          ] - Item 'Weckalarm' received command ON
2017-06-24 06:30:01.132 [ItemStateChangedEvent     ] - Weckalarm changed from OFF to ON

In my openhab.log I see a lot of Warnings right after that:

2017-06-24 06:30:01.081 [INFO ] [arthome.model.script.heating.rules: ] - Alarmclock: Hot Water -> ON
2017-06-24 06:30:01.105 [INFO ] [marthome.model.script.strega.rules: ] - Alarmclock: Strega ON
2017-06-24 06:30:01.156 [INFO ] [smarthome.model.script.weather.rules] - Alarmclock: Forecast today: Regen
15.80 °C (gef. 19.61°C) - Top: 18°C
Regen: 7mm @ 80 %
2017-06-24 06:30:03.051 [INFO ] [marthome.model.script.wecker.rules: ] - Alarmclock initiated. State: -> ON
2017-06-24 06:30:06.156 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1d6db1c' takes more than 5000ms.
2017-06-24 06:30:06.158 [WARN ] [ome.core.thing.internal.ThingManager] - Handler for thing 'km200:dhwCircuit:dhw1' takes more than 5000ms for processing event
2017-06-24 06:30:06.158 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1d6db1c' takes more than 5000ms.
2017-06-24 06:30:11.158 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.io.monitor.internal.EventLogger@119c802' takes more than 5000ms.
2017-06-24 06:30:11.160 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.io.monitor.internal.EventLogger@119c802' takes more than 5000ms.
2017-06-24 06:30:11.198 [INFO ] [smarthome.model.script.heating.rules] - Warm Water -> OFF / Warm Water-Timer cancelled
2017-06-24 06:30:16.161 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@58e7e7' takes more than 5000ms.
2017-06-24 06:30:16.162 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@58e7e7' takes more than 5000ms.
2017-06-24 06:30:21.164 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.autoupdate.internal.AutoUpdateBinding@191ae15' takes more than 5000ms.
2017-06-24 06:30:21.165 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.autoupdate.internal.AutoUpdateBinding@191ae15' takes more than 5000ms.
2017-06-24 06:30:25.328 [INFO ] [.smarthome.model.script.abus.rules: ] - NO new picture from Dome on Roof
2017-06-24 06:30:26.167 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.openhab.core.events.internal.EventBridge@7135e7' takes more than 5000ms.
2017-06-24 06:30:26.167 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.openhab.core.events.internal.EventBridge@7135e7' takes more than 5000ms.
2017-06-24 06:30:31.169 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.io.rest.sse.internal.listeners.SseEventSubscriber@9d10ab' takes more than 5000ms.
2017-06-24 06:30:31.169 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.io.rest.sse.internal.listeners.SseEventSubscriber@9d10ab' takes more than 5000ms.
2017-06-24 06:30:32.024 [INFO ] [.smarthome.model.script.abus.rules: ] - Abus Status sync done.
2017-06-24 06:30:32.100 [INFO ] [.smarthome.model.script.system.rules] - Uptime updated to 1 Tage / 19 Std. / 36 Min.
2017-06-24 06:30:36.171 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.model.rule.runtime.internal.engine.RuleEngineImpl@56aa3e' takes more than 5000ms.
2017-06-24 06:30:36.177 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.model.rule.runtime.internal.engine.RuleEngineImpl@56aa3e' takes more than 5000ms.
2017-06-24 06:30:41.174 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1d6db1c' takes more than 5000ms.
2017-06-24 06:30:41.179 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1d6db1c' takes more than 5000ms.
2017-06-24 06:30:46.177 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.io.monitor.internal.EventLogger@119c802' takes more than 5000ms.

After this the openhab.log is flooded with these timeout messages. Every now and then there is an entry from other rules.

So my questions:

  1. How do I identify the Things like the @56aa3e with the timeout issue?
  2. Why does the openhab still logs something whereas the events.log is obviously frozen at 6:30 (The actual OH system clock is still 6:29 even if its almost 8 am)

The only thing I changed recently is the persistence (to jdbc mySQL).

Any idea / suggestion would be greatly appreciated!

Hey there!

Did you ever solve the Problem?
Any hints?

I have the same issue!

OpenHAB runs for a certain amount of time, then these messages start appearing and everything is executed with like 10 minutes delay until nothing works anymore! Problem started in OH2.3, now im on 2.5 SNAPSHOT!

No errors in log!

Help apreciated!

Best regards,
Marcel

Have you tried cleaning the cache and tmp files?

Commands for apt-get install:

sudo systemctl stop openhab2

sudo openhab-cli clean-cache

sudo systemctl start openhab2

Tried that multiple times yes…

I’m kind of running out of ideas…

I’ll try removing all my config files and adding everything step by step.
Perhaps it’s something in there…

In my case it was obviously related to OOM error (out of memory in Java).
Actually I have another thread with this topic:

What helped me finally was expanding the memory on my raspberry pi 3:
EXTRA_JAVA_OPTS="-Xms400m -Xmx650m"
in /etc/default/openhab2

1 Like

Thanks very much for the hint!

After removing almost everything except my zwave and mqtt stuff, the system is running stable again, so it could have been a memory issue or some binding was causing the problems…

I am glad I was able to help.
Good luck for your further investigation.

1 Like