Logging zWave updates

travellingkiwi · October 2, 2018, 3:49pm

I’m the kind of person who needs to see that’s stuff is working. Preferably at a glance. Especially if it’s an unfamiliar piece of software.

One thing that I have struggled with is the zWave logs… There seems to be 2 settings.

tell me almost nothing (info)
Tell me in excruciating detail that makes it hard to eyeball all about ever messages and the parsing of the messages (debug)
There doesn’t seem to be a lot of difference between debug and trace. It’s more like trace and trace++

Is there a way (Besides bribing the kind person who develops it - although I’m not above buying them a pint if there ever in the same establishment as myself) to have the zWave log inbound and outbound values. e.g.

NODE 13 - SET switch_xyz ON
NODE 13 - switch_xyz RECV POWER 1.4kW
NODE 13 - switch_xyz RECV METER 2.9kWh

or similar… A half way house so I can see what’s being set and read for zWave devices. Without having 40 lines per update as in the current ‘debug’

chris · October 2, 2018, 4:01pm

There are 3 = info, debug, and trace.

What it seems you want to see is what is logged in the events log isn’t it?

At the end of the day, debug logging is there for, well, debugging the binding . You might call it trace logging, but there is certainly a lot more detail if you enable trace logging… I don’t want to cut it back so far that it becomes useless for its primary function.

travellingkiwi · October 7, 2018, 10:41am

Yeah, I understand that. Wasn’t going to ask you to cut it back… But something in the middle would be nice. Don’t worry, U understand you’re probably constrained by what’s available in openhab itself.

I missed the event log due to the spamming of updates for the controller frame counts etc…

chris · October 7, 2018, 5:00pm

I think if you remove the items from these, then they shouldn’t fill up the event log.

travellingkiwi · October 7, 2018, 6:25pm

Yeah. I’d wanted them as stats… but sadly it looks like I can’t filter selectively… I’ve removed them now. It looks like I’m seeing inbound packets (Reported in openhab.log) but not in events.log… I need to clean things up a bit to prove it though…

It’s weird. I’ve for devices I can switch on/off but don’t report to me (Watts, kWh etc). And a Fibaro multi-sensor that stopped talking to me today as well, after I managed to get my Qubino 2 relay to talk to be again (By reset and re-include).

Annoying doesn’t begin to describe it

travellingkiwi · October 7, 2018, 8:32pm

Here’s one… A Qubino 2 relay flush switch… Originally it was my Node 3. After a recent power outage it disappeared. Several hours of exclude/include/reset/include & repeat I finally got it to include again. As node 52. I can switch it on & off, but none of the meters (Power) are working…

In the logs I see

2018-10-07 21:28:20.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2018-10-07 21:28:38.493 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 34 0A 32 02 21 34 00 00 00 2E 00 00 DE
2018-10-07 21:28:38.528 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0&lt;&gt;128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=52, callback=0, payload=00 34 0A 32 02 21 34 00 00 00 2E 00 00
2018-10-07 21:28:38.530 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=52, callback=0, payload=00 34 0A 32 02 21 34 00 00 00 2E 00 00
2018-10-07 21:28:38.531 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2018-10-07 21:28:38.533 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 52: Application Command Request (ALIVE:DONE)
2018-10-07 21:28:38.534 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 52: resetResendCount initComplete=true isDead=false
2018-10-07 21:28:38.535 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 52: Incoming command class COMMAND_CLASS_METER, endpoint 0
2018-10-07 21:28:38.536 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 52: SECURITY not supported
2018-10-07 21:28:38.537 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 52: Received COMMAND_CLASS_METER V3 METER_REPORT
2018-10-07 21:28:38.538 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 52: Meter: Type=Electric(1), Scale=W(2), Value=4.6
2018-10-07 21:28:38.539 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 52: Commands processed 1.
2018-10-07 21:28:38.540 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 52: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@148c536.
2018-10-07 21:28:38.541 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2018-10-07 21:28:38.542 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2018-10-07 21:28:38.543 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

Yet there’s nothing in the event log… And the items attached to the ‘Thing’ don’t update either.

chris · October 7, 2018, 9:36pm

Can you provide the exact device you have so I can link this back to the database entry.

Thanks.

rlkoshak · October 8, 2018, 4:44pm

You should be able to filter what gets logged or what you see in the logs as selectively as you need at any given time.

travellingkiwi · October 8, 2018, 7:54pm

That one is a Qubino (ZMNHBD Flush 2 relays)

The lack of updates for the devices isn’t limited to just the QUbino though. It generally seems to be almost across the board. I can get stats for several of the 20+ devices I have… Restarting openhab changes the devices I do get stats for. The actual number varies between 0 - 5 or so that are actually working… It’s a bit weird.

chris · October 8, 2018, 9:04pm

Have you deleted all things and added them back again?

I can’t see anything immediately wrong here - the data is obviously being received, so associations are working. The channel is properly configured, and the data is being processed. I think we probably need to see a log from startup to see what is happening.

travellingkiwi · October 8, 2018, 9:32pm

Yes, I deleted all my things. And rescanned and added them back from the inbox. The items didn’t get deleted. I re-attached them to the things from PaperUI. Initially things looked ok, but I noticed some devices didn’t update. Lots of messing around, but I just seem to get only a random selection of items ever actually being updated.

I can gather and upload debug logs. No problems. Where would you like them?