Debugging a Z-Wave device (Ecolink garage door sensor, TILTZWAVE2.5-ECO)

RealBrianWarner · May 26, 2020, 7:29pm

I have two Ecolink garage door sensors (Z-Wave catalog, Chris’ database) that seem to only report the binary_sensor and battery-level states, despite subscribing to all of their channels (alarm_power, alarm_access, alarm_burglar). Per this thread, I’ve defined everything but the battery as a Switch.

For example, when I pop the cover I see a log entry that the node has been updated. Based upon the documentation, I’m guessing this should correspond with a tamper alarm, but the item linked to the channel isn’t updated.

[me.event.ThingUpdatedEvent] - Thing 'zwave:device:[...]:node52' has been updated.

Finally, I see binary_sensor updates in the log when I tilt the sensor, but its state does not appear in PaperUI or Habmin. Only the battery % is displayed.

Something seems to be out of alignment with this device. I’d like to attempt to debug it, but am not sure where to start. I’m on 2.5 stable, with the most recent Z-Wave snapshot (2.5.6-20200524). Do we have any pointers on where to begin?

Bruce_Osborne · May 26, 2020, 7:59pm

Start with the binding documentation with a heading like “When things don’t go as expected”.
Do not filter the debug logs.

RealBrianWarner · May 26, 2020, 9:19pm

Thanks! Should have looked there in the first place.

I now have a debug logs for the node from when I set it to the opened and closed orientations. I’m seeing this line, NODE 52: Alarm converter NOTIFICATION event is 22, channel alarm_access is not implemented.

That’s one of the channels which I’ve subscribed to but which does not appear in Paper UI. What’s a reasonable next step?

Door sensor set to opened orientation:

2020-05-26 16:25:43.300 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 11 00 04 00 34 0B 71 05 00 00 00 FF 06 16 00 00 00 4E 
2020-05-26 16:25:43.301 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=52, callback=0, payload=00 34 0B 71 05 00 00 00 FF 06 16 00 00 00 
2020-05-26 16:25:43.301 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=52, callback=0, payload=00 34 0B 71 05 00 00 00 FF 06 16 00 00 00 
2020-05-26 16:25:43.301 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-05-26 16:25:43.301 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 52: Application Command Request (ALIVE:REQUEST_NIF)
2020-05-26 16:25:43.301 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 52: Incoming command class COMMAND_CLASS_ALARM, endpoint 0
2020-05-26 16:25:43.301 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 52: SECURITY not supported
2020-05-26 16:25:43.301 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 52: Received COMMAND_CLASS_ALARM V5 NOTIFICATION_REPORT
2020-05-26 16:25:43.301 [DEBUG] [ernal.protocol.commandclass.ZWaveAlarmCommandClass] - NODE 52: NOTIFICATION report - 0 = 0, event=22, status=255, plen=0
2020-05-26 16:25:43.301 [DEBUG] [ernal.protocol.commandclass.ZWaveAlarmCommandClass] - NODE 52: Alarm Type = ACCESS_CONTROL (0)
2020-05-26 16:25:43.301 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 52: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2020-05-26 16:25:43.301 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 52: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_ALARM, value=255
2020-05-26 16:25:43.301 [DEBUG] [nding.zwave.internal.converter.ZWaveAlarmConverter] - NODE 52: Alarm converter processing NOTIFICATION
2020-05-26 16:25:43.302 [DEBUG] [nding.zwave.internal.converter.ZWaveAlarmConverter] - NODE 52: Alarm converter NOTIFICATION event is 22, type OnOffType
2020-05-26 16:25:43.302 [DEBUG] [nding.zwave.internal.converter.ZWaveAlarmConverter] - NODE 52: Alarm converter processing NOTIFICATION
2020-05-26 16:25:43.302 [DEBUG] [nding.zwave.internal.converter.ZWaveAlarmConverter] - NODE 52: Alarm converter NOTIFICATION event is 22, type OnOffType
2020-05-26 16:25:43.302 [DEBUG] [nding.zwave.internal.converter.ZWaveAlarmConverter] - NODE 52: Alarm converter NOTIFICATION event is 22, channel alarm_access is not implemented.
2020-05-26 16:25:43.302 [DEBUG] [nding.zwave.internal.converter.ZWaveAlarmConverter] - NODE 52: Alarm converter processing NOTIFICATION
2020-05-26 16:25:43.302 [DEBUG] [nding.zwave.internal.converter.ZWaveAlarmConverter] - NODE 52: Alarm converter NOTIFICATION event is 22, type OnOffType
2020-05-26 16:25:43.302 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 52: Commands processed 1.
2020-05-26 16:25:43.302 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 52: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@368fb280.
2020-05-26 16:25:43.302 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-05-26 16:25:43.302 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-05-26 16:25:43.302 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-05-26 16:25:43.302 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-05-26 16:25:43.317 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0A 00 04 00 34 04 30 03 FF FF F2 
2020-05-26 16:25:43.318 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=52, callback=0, payload=00 34 04 30 03 FF FF 
2020-05-26 16:25:43.318 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=52, callback=0, payload=00 34 04 30 03 FF FF 
2020-05-26 16:25:43.318 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-05-26 16:25:43.318 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 52: Application Command Request (ALIVE:REQUEST_NIF)
2020-05-26 16:25:43.318 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 52: Incoming command class COMMAND_CLASS_SENSOR_BINARY, endpoint 0
2020-05-26 16:25:43.318 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 52: SECURITY not supported
2020-05-26 16:25:43.318 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 52: Received COMMAND_CLASS_SENSOR_BINARY V2 SENSOR_BINARY_REPORT
2020-05-26 16:25:43.318 [DEBUG] [rotocol.commandclass.ZWaveBinarySensorCommandClass] - Processing Sensor Type 255
2020-05-26 16:25:43.318 [DEBUG] [rotocol.commandclass.ZWaveBinarySensorCommandClass] - Sensor Type is null
2020-05-26 16:25:43.318 [DEBUG] [rotocol.commandclass.ZWaveBinarySensorCommandClass] - NODE 52: Sensor Binary report, type=Unknown, value=255
2020-05-26 16:25:43.318 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 52: Got an event from Z-Wave network: ZWaveBinarySensorValueEvent
2020-05-26 16:25:43.318 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 52: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_BINARY, value=255
2020-05-26 16:25:43.318 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 52: Updating channel state zwave:device:f18426fd:node52:sensor_binary to ON [OnOffType]
2020-05-26 16:25:43.319 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 52: Commands processed 1.
2020-05-26 16:25:43.319 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 52: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@248faddf.
2020-05-26 16:25:43.319 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-05-26 16:25:43.319 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-05-26 16:25:43.319 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-05-26 16:25:43.319 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

Door sensor set to closed orientation:

2020-05-26 16:26:02.585 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 11 00 04 00 34 0B 71 05 00 00 00 FF 06 17 00 00 00 4F 
2020-05-26 16:26:02.585 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=52, callback=0, payload=00 34 0B 71 05 00 00 00 FF 06 17 00 00 00 
2020-05-26 16:26:02.585 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=52, callback=0, payload=00 34 0B 71 05 00 00 00 FF 06 17 00 00 00 
2020-05-26 16:26:02.585 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-05-26 16:26:02.586 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 52: Application Command Request (ALIVE:REQUEST_NIF)
2020-05-26 16:26:02.586 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 52: Incoming command class COMMAND_CLASS_ALARM, endpoint 0
2020-05-26 16:26:02.586 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 52: SECURITY not supported
2020-05-26 16:26:02.586 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 52: Received COMMAND_CLASS_ALARM V5 NOTIFICATION_REPORT
2020-05-26 16:26:02.586 [DEBUG] [ernal.protocol.commandclass.ZWaveAlarmCommandClass] - NODE 52: NOTIFICATION report - 0 = 0, event=23, status=255, plen=0
2020-05-26 16:26:02.586 [DEBUG] [ernal.protocol.commandclass.ZWaveAlarmCommandClass] - NODE 52: Alarm Type = ACCESS_CONTROL (0)
2020-05-26 16:26:02.586 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 52: Got an event from Z-Wave network: ZWaveAlarmValueEvent
2020-05-26 16:26:02.586 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 52: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_ALARM, value=255
2020-05-26 16:26:02.586 [DEBUG] [nding.zwave.internal.converter.ZWaveAlarmConverter] - NODE 52: Alarm converter processing NOTIFICATION
2020-05-26 16:26:02.586 [DEBUG] [nding.zwave.internal.converter.ZWaveAlarmConverter] - NODE 52: Alarm converter NOTIFICATION event is 23, type OnOffType
2020-05-26 16:26:02.586 [DEBUG] [nding.zwave.internal.converter.ZWaveAlarmConverter] - NODE 52: Alarm converter processing NOTIFICATION
2020-05-26 16:26:02.586 [DEBUG] [nding.zwave.internal.converter.ZWaveAlarmConverter] - NODE 52: Alarm converter NOTIFICATION event is 23, type OnOffType
2020-05-26 16:26:02.586 [DEBUG] [nding.zwave.internal.converter.ZWaveAlarmConverter] - NODE 52: Alarm converter NOTIFICATION event is 23, channel alarm_access is not implemented.
2020-05-26 16:26:02.586 [DEBUG] [nding.zwave.internal.converter.ZWaveAlarmConverter] - NODE 52: Alarm converter processing NOTIFICATION
2020-05-26 16:26:02.586 [DEBUG] [nding.zwave.internal.converter.ZWaveAlarmConverter] - NODE 52: Alarm converter NOTIFICATION event is 23, type OnOffType
2020-05-26 16:26:02.586 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 52: Commands processed 1.
2020-05-26 16:26:02.586 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 52: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@75f737df.
2020-05-26 16:26:02.587 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-05-26 16:26:02.587 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-05-26 16:26:02.587 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-05-26 16:26:02.587 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-05-26 16:26:02.601 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0A 00 04 00 34 04 30 03 00 FF 0D 
2020-05-26 16:26:02.602 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=52, callback=0, payload=00 34 04 30 03 00 FF 
2020-05-26 16:26:02.602 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=52, callback=0, payload=00 34 04 30 03 00 FF 
2020-05-26 16:26:02.602 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-05-26 16:26:02.602 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 52: Application Command Request (ALIVE:REQUEST_NIF)
2020-05-26 16:26:02.602 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 52: Incoming command class COMMAND_CLASS_SENSOR_BINARY, endpoint 0
2020-05-26 16:26:02.602 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 52: SECURITY not supported
2020-05-26 16:26:02.602 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 52: Received COMMAND_CLASS_SENSOR_BINARY V2 SENSOR_BINARY_REPORT
2020-05-26 16:26:02.602 [DEBUG] [rotocol.commandclass.ZWaveBinarySensorCommandClass] - Processing Sensor Type 255
2020-05-26 16:26:02.602 [DEBUG] [rotocol.commandclass.ZWaveBinarySensorCommandClass] - Sensor Type is null
2020-05-26 16:26:02.602 [DEBUG] [rotocol.commandclass.ZWaveBinarySensorCommandClass] - NODE 52: Sensor Binary report, type=Unknown, value=0
2020-05-26 16:26:02.602 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 52: Got an event from Z-Wave network: ZWaveBinarySensorValueEvent
2020-05-26 16:26:02.602 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 52: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_BINARY, value=0
2020-05-26 16:26:02.603 [DEBUG] [rg.openhab.binding.zwave.handler.ZWaveThingHandler] - NODE 52: Updating channel state zwave:device:f18426fd:node52:sensor_binary to OFF [OnOffType]
2020-05-26 16:26:02.603 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 52: Commands processed 1.
2020-05-26 16:26:02.603 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 52: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@3d25c352.
2020-05-26 16:26:02.603 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-05-26 16:26:02.603 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-05-26 16:26:02.603 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

Bruce_Osborne · May 26, 2020, 9:26pm

Sometimes the zwave log viewer helps. I will take a look too while we wait on expert input.

https://www.cd-jackson.com/index.php/openhab/zwave-log-viewer

EDIT: Sorry I have no ideas but others likely will.

apskinner · July 18, 2020, 2:10pm

Following this because I have exactly the same problem.
No tamper is reported in the UI - the decoded logs for opening and closing the device shows:-

Time	Node	Entry
10:06:48.664	2	
RX REQ ApplicationCommandHandler ALARM_REPORT V1 UNKNOWN[00] V1LEVEL=0 HOME_SECURITY EVENT=3 0 /128
10:06:50.950	2	
RX REQ ApplicationCommandHandler WAKE_UP_NOTIFICATION 0 /128
10:06:50.974	2	
Node is AWAKE
10:06:52.026	2	
TX REQ SendData 179 WAKE_UP_NO_MORE_INFORMATION  ACK AUTO_ROUTE EXPLORE
10:06:52.034		
RX ACK 0 /128
10:06:52.054	2	
RX RES SendData 179 ACCEPTED BY CONTROLLER 0 /128
10:06:52.068	2	
RX REQ SendData 179 ACK RECEIVED from device in 42ms 0 /128
10:06:52.108	2	
Node is ASLEEP

Bruce_Osborne · July 18, 2020, 2:17pm

The binding documentation specifically says Debug logs are needed. In addition. they need to be unfiltered. Please follow the documentation.

apskinner · July 18, 2020, 2:22pm

Hi Bruce,

I provided what came from the “ZWAVE Log Viewer” as per your previous post!

I didn’t think there was any value to add by repeating what Brian had produced.

Bruce_Osborne · July 18, 2020, 2:24pm

No other nodes were communicating during that time?

apskinner · July 18, 2020, 2:27pm

I have only the one device, I moved from Europe to Canada and have to start again, due to frequency differences, so no, no other devices when I opened and closed the sensors housing.

I’m wondering if it has anything to do with Association groups. I made sure though HABMIN that the controller was in the Lifeline Group (it wasn’t by default)

Just adding a second sensor of the same type to see if any difference

Bruce_Osborne · July 18, 2020, 2:34pm

What version of openHAB / binding? Most all versions released in the past year automatically discover & determine Lifeline if it is not already defined in the database.

Since you mention HABmin, how does it show your device?
Configuration -> Things -> [your node 2] ->Attributes (all the way at the bottom). You should see something like: (ignore Unknown Manufacturer. That is just HABMin)

chris · July 18, 2020, 2:40pm

It looks like the database for this device does not have this channel - I’ve updated it to add the tamper channel.

@apskinner in general it’s best to provide the raw logs so that we can view them both with the log viewer, and also the raw data - the log viewer provides a simple view of traffic, but doesn’t show everything and when debugging, both are generally required.

apskinner · July 18, 2020, 2:41pm

Bundle is 2.5.6 (Installed yesterday)
Running on Current Stable OH

apskinner · July 18, 2020, 2:42pm

Ok thanks Chris (re logs)
Do I need to do anything to pick up the new database?

chris · July 18, 2020, 2:44pm

Once the new binding is released (possibly tomorrow night) you’ll need to use the latest snapshot version.

Bruce_Osborne · July 18, 2020, 2:47pm

Wait for Chris to export the database (usually once a week, on weekends) & for the snapshot binding build script to pick up the changes.

I normally use the installer script to manually download & install the new binding version.
Zigbee and Z-Wave manual install script - Tutorials & Examples - openHAB Community

In HABmin, delete the “node 2” Thing ( do NOT exclude) and rediscover / add to OH. It will return with the same Thing ID so your existing Items will not break, but it will pick up the database changes.

Be sure to wake up enough times so OH fully discovers it again, of course.

apskinner · July 18, 2020, 2:50pm

Ok,

And not being able to understand the database very well, are all the other channels included…
Obvioulsy the Battery Level and Tilt Sensor are but what about Battery Alarm (low Bat), Access and Burglar - its not clear from the EColink Docs what these are for, but I’m guessing tamper isnt the only thing that can trigger.

My main concern is Tamper and Low Power Alarms

chris · July 18, 2020, 2:53pm

Battery level is the same as low battery - when the number is low (or 0) then the battery is low.

If you’re guessing, then I’m also guessing I don’t even have one of these, so we need your support to tell us what the channels do so we can add the support…

apskinner · July 18, 2020, 2:57pm

Noted There are separate channels for Battery Alarm and Battery Level (one is a switch the other a number) I guess I can have a rules regarding the level, though the battery level in battery devices is never a good indicator - I had one Humidity sensor in the past go from 50% to dead. I assumed the alarm channel for battery would be more reliable.

The docs in your database reflect the paper copy I got in the box. I’ll let you know when I get the new binding and test it out.

chris · July 18, 2020, 2:59pm

It is exactly the same bit of information from the device - the device reports either alarm, OR the level. This is just the way ZWave works.