Duplicate Log Entries - C8 Pro 2.4.3.176

Was troubleshooting a problem (my error) in a rule and looking through the logs is so annoying in large part because of duplicate entries for actions.
Examples:



and a particularly vexing one:

Device and device drivers:
Basement Pantry and Cabinet Room Lights = Generic Z-Wave Plus Scene Switch
Garage Lights = GE Enbrighten Z-Wave Smart Switch
Pantry Shelf Lights = Generic Z-Wave Smart Switch

All are Z-Wave, all are Jasco devices, but the drivers are different. Still tons of duplicate logs all the time. This has been going on for years and I have seen others post about it, but no real resolution. Is this normal? Is it something I'm doing wrong?

Everything is working by the way, it only makes scouring through logs difficult and I have to believe its s resource/storage waste too.

Any advice would be appreciated.

Probably worth looking at the device and any "In Use" apps for the device, plus posting any rules the device is part of.

You can look at the Events tab on the devices. It will tell you what produced each of those multiple events. I don't think they are duplicate logs, they look like distinct events sent by the driver, as there are milliseconds between them. A "duplicate" log entry would have the same timestamps.

1 Like

I have been seeing logs do that for a long while. I can't figure out why either. Device events show only one operation not the several shown in the logs.

1 Like

Well, I don't understand. I just used Alexa to turn on the "Basement Hallway Lights" because I could watch and confirm that they turned on. I have a rule that fires off in this case that turns that light off in 10 minutes. I get multiple entries:


Yes, they are milliseconds apart. But it's one command. The events for that time period contain this:

This just doesn't seem right to me.

Neither do I. But could you try turning "command retry" off for that device?

Also tagging @mike.maxwell for his input.

Command logic is not turned on.

Scenario 1: Manually switched on this device, waited 12 seconds, switched it off. Got one "on" and one "off" log entry.

Scenario 2: Used the "commands" page of the device page and clicked it on, waited about 10 seconds and hit the off command. Got this in the logs.


Interestingly in the middle the multiple entries my workshop lights were turned off by the "Manage Workshop Lights" app which is a child of "Room Lighting." When it send the off command because of 10 minutes of inactivity, that device reported off 4 times. I'm beginning to think that most of you do not think this is normal, though I'm not alone in seeing this behavior.

Thoughts?

It should be noted that info messages (or any messages) in the live logs may not produce events, in particular multiple logs specifying the same state will not produce multiple events, only one event is produced when a given attribute changes value, you can see this by looking at the events tab for the device details, there will only be one entry.
The device itself is reporting multiple times for a given command, some drivers will not send info messages to the live logs unless the state changes, some will, this driver does, but in either case only one event is committed to the database, and therefore only one app trigger will be processed if anything is subscribing to this particular event.

3 Likes

Me too.
Is the bottom line that the multiple reports as noted in logs would not affect rules, only events? That this is just a cosmetic thing?
C8Pro, 2.4.4.155, ZWJS, retracted Z-Wave radio update, ZEN78 relay paired LR:

Noticed the same. No one has answered why a single event echos through the logs. But it does not seem to affect anything operational wise.

1 Like

I suspect it is the device and not the hub that is showing the duplicates in the log. That is when the device is commanded to turn on/off, it is tgat device that is sending the on/off that you see in the log. I canโ€™t say why, but I suspect this is more informational than a double command. Maybe your device doesnโ€™t get an ACK fast enough? Just speculation.

And that is the bottom line! :slight_smile: