Strange behaviour of OpenHab 2.5. 1-2 , it almost restarts openhab

Tags: #<Tag:0x00007faf9aa01558> #<Tag:0x00007faf9aa01440>

Hi
I have openhabian 2.5.1-2 on Rpi 2 with many connected devices and Influxdb/Graphana.
From time to time I observe strange situation - Rpi where Openhab is installed disconect from network, it also (I do not why) it cause openhabian to (almost) restart.
I do not why it reload all modules. When I disconnect / connect Ethernet cable from RPi, network works properly.

BTW Where can I find RPI logs to find what was a cause of disconnection.

Log look like this:

2020-11-15 05:02:04.588 [INFO ] [.eclipse.smarthome.model.script.FILE] - Temperature_control: ========= End of processing ========
2020-11-15 05:16:07.479 [ERROR] [o.client.mqttv3.internal.ClientState] - paho2113976080387579: Timed out as no write activity, keepAlive=60,000 lastOutboundActivity=1,605,413,464,638 lastInboundActivity=1,605,413,767,403 time=1,605,413,767,177 lastPing=1,605,413,464,638
2020-11-15 05:16:07.767 [WARN ] [t.mqtt.internal.MqttBrokerConnection] - MQTT connection to 'mosquitto' was lost: Connection lost : ReasonCode 32109 : Cause : null
2020-11-15 05:16:07.772 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting connection helper to periodically try restoring connection to broker 'mosquitto'
2020-11-15 05:16:18.698 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting MQTT broker connection 'mosquitto'
2020-11-15 05:37:34.770 [WARN ] [cTransformationWhitelistWatchService] - Cannot read whitelist file, exec transformations won't be processed: /etc/openhab2/misc/exec.whitelist
2020-11-15 05:37:39.963 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Could not find broadcast address of primary IP, using broadcast address null of first interface instead
2020-11-15 05:37:47.192 [WARN ] [g.eclipse.smarthome.core.net.NetUtil] - Could not find broadcast address of primary IP, using broadcast address null of first interface instead
2020-11-15 05:37:55.672 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'General.items'
2020-11-15 05:37:56.118 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'FloorHeatingSystem.items'
2020-11-15 05:37:56.327 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'LightSystem.items'
2020-11-15 05:37:56.428 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'FloodAlarm.items'
2020-11-15 05:37:56.554 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'GardenWateringSystem.items'
2020-11-15 05:37:56.803 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'IntruderAlarmSystem.items'
2020-11-15 05:37:58.461 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mapdb.persist'
2020-11-15 05:37:58.565 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'influxdb.persist'
2020-11-15 05:38:00.543 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'default.sitemap'

Is it possible that a small amount of free memory causes these problems? Current situation on my RPi

Memory = Free: 0.04GB (4%), Used: 0.90GB (96%), Total: 0.95GB
Swap = Free: 0.05GB (55%), Used: 0.04GB (45%), Total: 0.09GB
Root = Free: 23.84GB (87%), Used: 3.43GB (13%), Total: 28.46GB

Yes, this looks like a possible cause. For me, when memory is low, I lose connection to the Pi’s (as if they have dropped off the network). Watching the activity light shows that the Pi is doing something for a long time, before the Pi becomes available again (as you say, like a restart).

I moved some services to another device to reduce the amount of used memory, and have not had any issues since.

1 Like

In deamon.log I’ve found:

Nov 15 05:36:38 openHABianPi avahi-daemon[372]: Received packet from invalid interface.
Nov 15 05:36:49 openHABianPi avahi-daemon[372]: Received packet from invalid interface.
Nov 15 05:36:49 openHABianPi systemd[1]: openhab2.service: main process exited, code=killed, status=9/KILL
Nov 15 05:36:55 openHABianPi karaf[11821]: Can't connect to the container. The container is not running.
Nov 15 05:36:55 openHABianPi systemd[1]: openhab2.service: control process exited, code=exited status=1
Nov 15 05:36:55 openHABianPi systemd[1]: Unit openhab2.service entered failed state.
Nov 15 05:36:59 openHABianPi influxd[668]: [I] 2020-11-15T04:36:59Z compacted level 1 group (0) into /var/lib/influxdb/data/_internal/monitor/1243/000000008-000000002.tsm.tmp (#0) engine=tsm1
Nov 15 05:36:59 openHABianPi influxd[668]: [I] 2020-11-15T04:36:59Z compacted level 1 2 files into 1 files in 44.374708888s engine=tsm1
Nov 15 05:36:59 openHABianPi influxd[668]: [I] 2020-11-15T04:36:59Z beginning level 2 compaction of group 0, 2 TSM files engine=tsm1
Nov 15 05:36:59 openHABianPi influxd[668]: [I] 2020-11-15T04:36:59Z compacting level 2 group (0) /var/lib/influxdb/data/_internal/monitor/1243/000000006-000000002.tsm (#0) engine=tsm1
Nov 15 05:36:59 openHABianPi influxd[668]: [I] 2020-11-15T04:36:59Z compacting level 2 group (0) /var/lib/influxdb/data/_internal/monitor/1243/000000008-000000002.tsm (#1) engine=tsm1
Nov 15 05:37:00 openHABianPi systemd[1]: openhab2.service holdoff time over, scheduling restart.
Nov 15 05:37:00 openHABianPi systemd[1]: Stopping openHAB 2 - empowering the smart home...
Nov 15 05:37:00 openHABianPi systemd[1]: Starting openHAB 2 - empowering the smart home...
Nov 15 05:37:00 openHABianPi systemd[1]: Started openHAB 2 - empowering the smart home.
Nov 15 05:37:15 openHABianPi influxd[668]: [I] 2020-11-15T04:37:15Z compacted level 2 group (0) into /var/lib/influxdb/data/_internal/monitor/1243/000000008-000000003.tsm.tmp (#0) engine=tsm1