Java Runtime Environment: openjdk version “17.0.13” 2024-10-15
openHAB version: 4.3.2
Issue of the topic: After restart everything works fine, but after some time commands are not physically executed on devices. My devices are mixed shellies, tasmotas and various bindings. I dont see any errors in logs. After restarr everything is fine for some time. Rules are executed. All the data from devices is being collected. Looking for clue where to look for error.
openhab.service - openHAB - empowering the smart home
Loaded: loaded (/lib/systemd/system/openhab.service; enabled; vendor preset: enabled)
Active: active (running) since Sun 2025-01-26 23:14:24 CET; 1 day 22h ago
Docs: Introduction | openHAB https://community.openhab.org
Main PID: 754432 (java)
Tasks: 394 (limit: 18904)
Memory: 2.8G
CPU: 15h 15min 51.194s
CGroup: /system.slice/openhab.service
|-754432 /usr/bin/java -XX:-UsePerfData -Dopenhab.home=/usr/share/openhab -Dopenhab.conf=/etc/openhab -Dopenhab.runtime=/usr/share/openhab/runtime -Dopenhab.userdata=/var/lib/openhab -Dopenhab.logdir=/var/log/openhab -Dfelix.cm.dir=/var/lib/openhab/config -Djava.l>
`-838228 /usr/bin/ffmpeg -rtsp_transport tcp -threads 1 -skip_frame nokey -hide_banner -i rtsp://@192.168.1.162:554/live/ch01_1 -an -vsync vfr -q:v 2 -update 1 http://127.0.0.1:8080/ipcamera/2d13aeb708/snapshot.jpg
sty 28 01:26:11 biuro karaf[754432]: OK
sty 28 01:26:11 biuro karaf[754432]: OK
sty 28 01:26:12 biuro karaf[754432]: OK
sty 28 01:26:12 biuro karaf[754432]: OK
sty 28 01:26:13 biuro karaf[754432]: OK
sty 28 01:26:13 biuro karaf[754432]: OK
sty 28 01:26:38 biuro karaf[754432]: OK
sty 28 01:26:39 biuro karaf[754432]: OK
sty 28 01:26:39 biuro karaf[754432]: OK
sty 28 01:26:39 biuro karaf[754432]: OK
all I can see is this msg cease to show up:
Jan 28 01:25:02 biuro karaf[754432]: OK
Jan 28 01:25:02 biuro karaf[754432]: message repeated 5 times: [ OK]
Jan 28 01:25:02 biuro karaf[754432]: OK
Jan 28 01:25:03 biuro karaf[754432]: message repeated 2 times: [ OK]
Jan 28 01:25:03 biuro karaf[754432]: OK
Jan 28 01:25:10 biuro karaf[754432]: message repeated 20 times: [ OK]
Jan 28 01:25:38 biuro karaf[754432]: OK
Jan 28 01:26:01 biuro karaf[754432]: message repeated 9 times: [ OK]
Jan 28 01:26:02 biuro karaf[754432]: OK
Jan 28 01:26:02 biuro karaf[754432]: OK
Jan 28 01:26:03 biuro karaf[754432]: OK
Jan 28 01:26:13 biuro karaf[754432]: message repeated 23 times: [ OK]
Jan 28 01:26:38 biuro karaf[754432]: OK
Jan 28 01:26:39 biuro karaf[754432]: message repeated 3 times: [ OK]
2025-01-28 21:12:27.874 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor’ changed from ON to OFF
2025-01-28 21:12:30.016 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor’ changed from OFF to ON
2025-01-28 21:20:08.139 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor’ changed from ON to OFF
2025-01-28 23:01:01.299 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor’ changed from OFF to ON
2025-01-28 23:01:01.857 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor’ changed from ON to OFF
2025-01-28 23:01:02.652 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor’ changed from OFF to ON
I can click the switch in GUI, send command to item in console, the rules also change the state of the items.
Those are not commands. Those are changes. There should be separate log entries for commands.
Only commands go out to the devices, updates and changes are local to OH. When you toggle an Item from the UI you should see a log entry indicating the command. Then you might see something about autupdate predicting the new state and if the Item changes in response to the command you’ll see the changed log entry like you have above.
yeah, item name and ON , OFF. This is filtered by item name:
2025-01-28 23:00:07.859 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor_last_update’ changed from 2025-01-28T22:59:52.000+0100 to 2025-01-28T23:00:08.000+0100
2025-01-28 23:00:22.929 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor_last_update’ changed from 2025-01-28T23:00:08.000+0100 to 2025-01-28T23:00:23.000+0100
2025-01-28 23:00:38.002 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor_watt’ changed from 0 W to 20.24 W
2025-01-28 23:00:38.002 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor_last_update’ changed from 2025-01-28T23:00:23.000+0100 to 2025-01-28T23:00:38.000+0100
2025-01-28 23:00:53.291 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor_watt’ changed from 20.24 W to 0 W
2025-01-28 23:00:53.294 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor_last_update’ changed from 2025-01-28T23:00:38.000+0100 to 2025-01-28T23:00:53.000+0100
2025-01-28 23:01:01.298 [INFO ] [openhab.event.ItemCommandEvent ] - Item ‘gniazdo_telewizor’ received command ON
2025-01-28 23:01:01.298 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item ‘gniazdo_telewizor’ predicted to become ON
2025-01-28 23:01:01.299 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor’ changed from OFF to ON
2025-01-28 23:01:01.857 [INFO ] [openhab.event.ItemCommandEvent ] - Item ‘gniazdo_telewizor’ received command OFF
2025-01-28 23:01:01.857 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item ‘gniazdo_telewizor’ predicted to become OFF
2025-01-28 23:01:01.857 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor’ changed from ON to OFF
2025-01-28 23:01:02.651 [INFO ] [openhab.event.ItemCommandEvent ] - Item ‘gniazdo_telewizor’ received command ON
2025-01-28 23:01:02.652 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item ‘gniazdo_telewizor’ predicted to become ON
2025-01-28 23:01:02.652 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor’ changed from OFF to ON
2025-01-28 23:01:08.357 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor_last_update’ changed from 2025-01-28T23:00:53.000+0100 to 2025-01-28T23:01:08.000+0100
2025-01-28 23:01:23.424 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor_last_update’ changed from 2025-01-28T23:01:08.000+0100 to 2025-01-28T23:01:23.000+0100
2025-01-28 23:01:38.517 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor_last_update’ changed from 2025-01-28T23:01:23.000+0100 to 2025-01-28T23:01:38.000+0100
2025-01-28 23:01:53.603 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor_last_update’ changed from 2025-01-28T23:01:38.000+0100 to 2025-01-28T23:01:53.000+0100
2025-01-28 23:02:08.674 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor_last_update’ changed from 2025-01-28T23:01:53.000+0100 to 2025-01-28T23:02:08.000+0100
2025-01-28 23:02:23.744 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor_last_update’ changed from 2025-01-28T23:02:08.000+0100 to 2025-01-28T23:02:23.000+0100
this is unfiltered:
2025-01-28 23:01:01.040 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘Serwer_Storage2_Used’ changed from 59236155392 B to 59238252544 B
2025-01-28 23:01:01.059 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘Serwer_Storage2_Available’ changed from 180699004928 B to 180696907776 B
2025-01-28 23:01:01.107 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘Serwer_Memory_AvailablePercent’ changed from 0.59 to 0.591
2025-01-28 23:01:01.298 [INFO ] [openhab.event.ItemCommandEvent ] - Item ‘gniazdo_telewizor’ received command ON
2025-01-28 23:01:01.298 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item ‘gniazdo_telewizor’ predicted to become ON
2025-01-28 23:01:01.299 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor’ changed from OFF to ON
2025-01-28 23:01:01.857 [INFO ] [openhab.event.ItemCommandEvent ] - Item ‘gniazdo_telewizor’ received command OFF
2025-01-28 23:01:01.857 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item ‘gniazdo_telewizor’ predicted to become OFF
2025-01-28 23:01:01.857 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor’ changed from ON to OFF
2025-01-28 23:01:02.120 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘Serwer_CPU_Temperature’ changed from 35 °C to 45 °C
2025-01-28 23:01:02.154 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘Serwer_Memory_Used’ changed from 6803161088 B to 6848249856 B
2025-01-28 23:01:02.194 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘Serwer_Memory_Available’ changed from 9834594304 B to 9790554112 B
2025-01-28 23:01:02.348 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘Serwer_Memory_UsedPercent’ changed from 0.409 to 0.412
2025-01-28 23:01:02.450 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘Serwer_Storage2_Used’ changed from 59238252544 B to 59235106816 B
2025-01-28 23:01:02.473 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘Serwer_Storage2_Available’ changed from 180696907776 B to 180701102080 B
2025-01-28 23:01:02.651 [INFO ] [openhab.event.ItemCommandEvent ] - Item ‘gniazdo_telewizor’ received command ON
2025-01-28 23:01:02.652 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item ‘gniazdo_telewizor’ predicted to become ON
2025-01-28 23:01:02.652 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘gniazdo_telewizor’ changed from OFF to ON
2025-01-28 23:01:03.533 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘Serwer_CPU_Temperature’ changed from 45 °C to 42 °C
2025-01-28 23:01:03.557 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘Serwer_Memory_Used’ changed from 6848249856 B to 6816792576 B
2025-01-28 23:01:03.594 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘Serwer_Memory_Available’ changed from 9790554112 B to 9820962816 B
2025-01-28 23:01:03.594 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘Serwer_Cpu_Load’ changed from 0.292 to 0.503
2025-01-28 23:01:03.716 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘Serwer_CurrentProcess_Load’ changed from 0.096 to 0.068
2025-01-28 23:01:03.740 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘Serwer_Memory_UsedPercent’ changed from 0.412 to 0.41
2025-01-28 23:01:03.912 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘Serwer_Memory_AvailablePercent’ changed from 0.591 to 0.59
OK, the command events are happening. Next step is to pick one of the add-ons that fail to respond to commands after awhile, and put it into debug logging level. When it stops responding, verify that you still see the commands in events.log and see if there is any indication from the binding that it saw the commands or not.
I’ve not seen anything like this reported before so we need to systematically follow the events until we see it being dropped.
That won’t help. Pick one of your bindings that stops working and put that into debug level logging. Trace isn’t necceary. We want to see if the binding shows no evidence of seeing the commands, or if it sees them and fails to do anything with them.
Adjusting openhab.event will give us no additional information.
Hey there, with the last restart 3 days ago I have also removed bindings for chromecast, androidtv and onkyo. Since then had no problems with my instance.
