I am troubleshooting an issue that started yesterday. Here is some rubber ducking and maybe someone ran into that already.
The short version is that:
I have a BatteryLevel group
All my battery powered items are in this group
I am using BatteryLevel*: strategy = everyChange, everyDay, restoreOnStartup
Everything is working fine for a long time in that regard.
Yesterday, most of my devices suddenly got updated to 18.
I upgraded OH and did a restart. The Battery levels started recovering after the restart.
As I woke up devices, I saw the actual battery level coming in.
Suddenly again, most of my devices (around 56/60) got reset all to the same value, this time 19.
First I thought about an issue with Z2M but I have the issue on both some zwave and zigbee devices. Moreover, everything looks normal in Z2M.
Looking at a graph, I see the rest coming every 2 hours, then the freq. changed to some 1h then less than that.
I am using git so I can see my history. So far, I did not spot what could be the cause of this “reset”. Morever my last chanegs are not related to battery levels…
For me it looks like something is command your group.
Did you changed your rules or something?
Or misslinked a channel to the group item…
I.e. if I set my light dimmer group to 50 all lights get a command 50.
Yes, I did consider that. I have 2 rules with Member of BatteryLevele but:
they work for a while now
they are “read/only” (I check the level and send alerts)
I disabled those rules for now
In the meantime, I reverted all the commits (3) I made the last day although they are related to temperature and not related to batteries… I don’t see anything that would cause such a trouble but I may miss something. So monitoring for now and If that works, I will reintroduce my commits one by one so see when it breaks.
I am seeing a bunch of zwave errors just before the values are changed. Not sure whether this is a cause or consequence.
The value appears to be incremental. 18…19…20…21…
With some more monitoring I guess I will figure out whether this is a temp, hour, or some random incremented value…
2024-12-08 18:32:47.197 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.handleCommand()' on 'org.openhab.binding.zwave.handler.ZWaveThingHandler@1194293d': Value must be between 0 and 100
java.lang.IllegalArgumentException: Value must be between 0 and 100
at org.openhab.core.library.types.PercentType.validateValue(PercentType.java:93) ~[bundleFile:?]
at org.openhab.core.library.types.PercentType.<init>(PercentType.java:88) ~[bundleFile:?]
at org.openhab.core.library.types.DecimalType.as(DecimalType.java:194) ~[bundleFile:?]
at org.openhab.binding.zwave.handler.ZWaveThingHandler.convertCommandToDataType(ZWaveThingHandler.java:1241) ~[?:?]
at org.openhab.binding.zwave.handler.ZWaveThingHandler.handleCommand(ZWaveThingHandler.java:1177) ~[?:?]
at jdk.internal.reflect.GeneratedMethodAccessor249.invoke(Unknown Source) ~[?:?]
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:569) ~[?:?]
at org.openhab.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:147) [bundleFile:?]
at org.openhab.core.internal.common.InvocationHandlerSync.invoke(InvocationHandlerSync.java:59) [bundleFile:?]
at jdk.proxy2143.$Proxy2311.handleCommand(Unknown Source) [?:?]
at org.openhab.core.thing.internal.profiles.ProfileCallbackImpl.handleCommand(ProfileCallbackImpl.java:95) [bundleFile:?]
at org.openhab.core.thing.internal.profiles.SystemDefaultProfile.onCommandFromItem(SystemDefaultProfile.java:49) [bundleFile:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:569) ~[?:?]
at org.openhab.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:147) [bundleFile:?]
at org.openhab.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
at java.lang.Thread.run(Thread.java:840) [?:?]
Yes, atm I am at the same conclusion: “something sends a command to those Battery items”.
I can see it started yesterday at 23:30. My latest changes were at 15:00 the day before so it does not match at all. I inspected all “my” .sendCommand in search of an error/typo but I see nothing that would send such a value.
Here is another extract of what I get:
2024-12-08 19:02:47.470 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'Hallway2_FibEye__BatteryLevel' received command 22
2024-12-08 19:02:47.470 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'Office_Marquise__BatteryLevel' predicted to become 22
2024-12-08 19:02:47.470 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'LivingRoom_FibEye__BatteryLevel' predicted to become 22
2024-12-08 19:02:47.471 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'LivingRoom_Velux__BatteryLevel' predicted to become 22
2024-12-08 19:02:47.471 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Office_Marquise__BatteryLevel' changed from 21 to 22
I am wondering about that [penhab.event... as well but that may be a trick to keep the string short. Maybe some frontail trick…
I suspect, on my end or maybe in OH, a silly error like a missing " or >. Yet the parser should(™) catch that.
Reverting my commits, it is “holding it” now.
So the issue may be in one of my changes. I am now very intersted in knowing what causes the issue… For now, I will let run in the current state to validate that it really works again.
That explains the issue however, I am not, at least via rules, sending this command.
I searched my code and I get no hit for BatteryLevel. so no postUpdate/sendCommand from my end.
So the challenge is now to find what is sending this command in my back.
By default the class name generating the log statement is fixed. If the class name is longer than the fixed length (17 characters I think) it cuts off the front part of the class name. This is normal and configurable from log4j2.xml.
Any links? Like @Baschtlwaschtl mentioned above, is a Channel is linked to the Group that could explain the commands send to members of the Group.
It happens to be a ZigBee device but I have some Zwave devices in the mix.
Today I uninstalled your battery addon @rlkoshak but I was not using it yet.
I turned OFF the android tablet running HabPanel and since, I don’t see the issue.
But since it appears to be random, I will wait a bit.
Atm, I am a bit puzzled by the value sent to the command. It seems to be incremental. It started at 14. I am now at 44.
I am now running ok for a while (no code item/rules changes).
The command seems to be coming every ~45 min but not always. I don’t see other items/groups affected. My OH is not exposed to the internet (I have seem people having troubles with that).
I will leave it like that for now and turn on my tablet tomorrow again to see if that does something.I really don’t get why it would but at that point, I am observing…
That’s a good question indeed. I will test that too.
I spotted something. I had my tablet with HabPanel off the whole night. Everything worked “as usual”. I turn on the tablet + HabPanel today at 8:18. I instantly got:
2024-12-10 08:17:44.743 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'BatteryLevel' received command 100
2024-12-10 08:17:44.745 [INFO ] [openhab.event.ItemCommandEvent ] - Item 'Office_FibEye__BatteryLevel' received command 100
... many more...
It is actually possible that I always add this issue but never noticed. The “magic number” could be the BatteryLevel of the tablet. It was indeed down recently.
I still don’t explain what/how/why this tablet would send this command but I think I am getting closer to an explanation…
Yes I agree with you. Moreover, I was not using it yet.
Having an unexplained issue, I decided to remove battery related stuff, especially when not used. But your addon looks nice, I just never had the time to see how it works and set it up. I will likely reinstall once the mystery is solved
if you KNOW what you are doing, everyhting should be fine but read on…
I would recommend NOT using a group called BatteryLevel (I switched to BatteryPercent) to stay clear from the default value in case I reinstall the App and forget about this issue)
Make sure to configure the App as you wish and either do not send the value or rename the rather generic BatteryLevel into something more specific that has no chance to collide with the group name
I would add to the above that the App allows defining a device ID.
That is probably better than renaming BatteryLevel into BatteryLevelXYZ.
Defining the device id as MyTablet__ for instance, will yield to the App sending the enabled channels such as MyTablet__BatteryLevel, etc…