Can't get EcoNet flood sensor to clear

GeekGoneOld · March 15, 2019, 9:29pm

I’m using UI5 1.5.673 (the z-wave plus beta).

I am trying to get and EcoNet EZW1204 flood switch (a z-wave plus sensor) to work. It includes fine, it configures as generic I/O. I uploaded D_FloodSensor.xml. I edited D_FloodSensor.json for UI5 (is only avail on UI7) and uploaded. I changed GenericIO to FloodSensor in the device (2 places) and the category/sub category to 4/2. It seems to accept those changes as I would expect…

I tripped the switch and it shows up as tripped in the UI. I then untripped it and the trip never clears (Advanced: Tripped). I manually set tripped to 0 and sl_alarm to “OK” then I tripped the sensor, waited a few seconds and cleared the sensor. I looked at the log file (attached) and question the following:

At 15:58:07.581 it says “unhandled”. Does this mean it was not handled at all or unhandled goes to a default handler (cause this transition IS recorded!)? Also, what is the message that was unhandled? Lifeline? Notification?
At 15:58:07.921 Ver seems to have figured out it must update “Tripped”. Is this from processing the message above?
What is the event at 15:58:08.005? I have no notifications and no triggers set up from this though I did type in a name for a notification then deleted it. I will check the config when I look up the syntax for the browser!
At 15:58.08.005 there is an alarm report message received. Then it updates the alarm report (correctly) then updates the battery level and time but I don’t see a corresponding report message, implying that the alarm message at .005 might not be the one that caused the update. In fact, I’d be almost certain of that since the restore alarm message got logged but didn’t update the sl_alarm.
Looking at the similar sequence on the untrigger event 12 seconds later, it appears that the messages that actually caused the data to be written (tripped and sl_alarm for the tripped case, battery for both cases) are not shown.

So I wonder:

Was I stupid to change GenericIO to FloodSensor
Is this a “not compatible in any way with UI5 because it is z-wave plus” even though f/w 673 was specifically to allow some z-wave plus into UI5?
How does Vera actually get notified. We seem to have “lifeline”, Alarm class, Notification class, Basic Command class all at work in the device. The device seems to send out lifeline (whatever class that might be) as well as Sensor binary report (for tripped variable), Alarm report (for sl_alarm variable), Battery report (for battery level/time).
What are the “unhandled” messages?
How can I see the messages that actually ARE handled (and cause writes to the variables). I put on detailed logging but at a very quick glance got nothing more out of it (though there are many more log entries!).

02 03/15/19 15:58:07.581 ^[[33;1mZWaveNode::HandlePollUpdate_Basic_Set node 38 device 48 unhandled^[[0m <0x803> 06 03/15/19 15:58:07.921 Device_Variable::m_szValue_set device: 48 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: ^[[35;1mTripped^[[0m was: 0 now: 1 #hooks 07 03/15/19 15:58:08.005 Event::Evaluate 13 Laundry Flood scene Laundry Flood is false repeat 0/-1 <0x803> 02 03/15/19 15:58:08.005 ^[[33;1mZWaveNode::HandlePollUpdate_Alarm node 38 device 48 v1type: 0 v1level: 0 source: 0 status: 255 type: 5 event: 2 parms: 0 code: WATER_LEAK^[[ 06 03/15/19 15:58:08.006 Device_Variable::m_szValue_set device: 48 service: urn:micasaverde-com:serviceId:HaDevice1 variable: ^[[35;1msl_Alarm^[[0m was: OK now: WATER_LEAK # 06 03/15/19 15:58:08.194 Device_Variable::m_szValue_set device: 48 service: urn:micasaverde-com:serviceId:HaDevice1 variable: ^[[35;1mBatteryDate^[[0m was: 1552678977 now: 1 06 03/15/19 15:58:08.195 Device_Variable::m_szValue_set device: 48 service: urn:micasaverde-com:serviceId:HaDevice1 variable: ^[[35;1mBatteryLevel^[[0m was: 100 now: 100 #ho 02 03/15/19 15:58:20.111 ^[[33;1mZWaveNode::HandlePollUpdate_Basic_Set node 38 device 48 unhandled^[[0m <0x803> 02 03/15/19 15:58:20.491 ^[[33;1mZWaveNode::HandlePollUpdate_Alarm node 38 device 48 v1type: 0 v1level: 0 source: 0 status: 255 type: 5 event: 0 parms: 1 code: (null)^[[0m < 06 03/15/19 15:58:20.611 Device_Variable::m_szValue_set device: 48 service: urn:micasaverde-com:serviceId:HaDevice1 variable: ^[[35;1mBatteryDate^[[0m was: 1552679888 now: 1 06 03/15/19 15:58:20.612 Device_Variable::m_szValue_set device: 48 service: urn:micasaverde-com:serviceId:HaDevice1 variable: ^[[35;1mBatteryLevel^[[0m was: 100 now: 100 #ho

GeekGoneOld · March 16, 2019, 7:20am

Well, I got rid of the event at 15:58:08.005. Turns out it was a notification that was created by a bug in Vera and didn’t show anywhere except by looking at user_data.json.

Now for more info. I carefully looked at a log with advanced logging turned on. I found that the ONLY reports it was processing were the notification (class 0x71) and battery (0x80) and it was ignoring the Basic (0x20), and Binary Sensor (0x30). Oddly, though, it only processed the notification when it went into alarm and didn’t update any values when it went out of alarm. I’ve captured a detailed log of just the notification messages. Hopefully someone can analyze it and help me out.

Just as another note, I’m perfectly willing to edit code if that’s what it takes. I just need a bit of guideance as to where to look.

42 03/16/19 1:28:08.331 24 03/16/19 1:28:08.332 41 03/16/19 1:28:08.333 24 03/16/19 1:28:08.341 24 03/16/19 1:28:08.341 10 03/16/19 1:28:08.342 10 03/16/19 1:28:08.343 31 03/16/19 1:28:08.345 31 03/16/19 1:28:08.346 24 03/16/19 1:28:08.347 24 03/16/19 1:28:08.348 06 03/16/19 1:28:08.349 10 03/16/19 1:28:08.350 10 03/16/19 1:28:08.379 10 03/16/19 1:28:08.383 10 03/16/19 1:28:08.384 10 03/16/19 1:28:08.386 06 03/16/19 1:28:08.387 02 03/16/19 1:28:08.388 06 03/16/19 1:28:08.453 10 03/16/19 1:28:08.454 <snip> 42 03/16/19 1:28:19.671 24 03/16/19 1:28:19.672 41 03/16/19 1:28:19.673 24 03/16/19 1:28:19.680 24 03/16/19 1:28:19.681 10 03/16/19 1:28:19.682 10 03/16/19 1:28:19.683 31 03/16/19 1:28:19.684 31 03/16/19 1:28:19.685 31 03/16/19 1:28:19.686 24 03/16/19 1:28:19.687 24 03/16/19 1:28:19.688 02 03/16/19 1:28:19.689 24 03/16/19 1:28:19.689 31 03/16/19 1:28:19.691 0x1 0xf 0x0 0x4 0x0 0x26 0x9 0x71 0x5 0x0 0x0 0x0 0xff 0x5 0x2 0x0 0x57 (^[[34;1m#####&#q########W^[[0m) <0x1406> ZWaveSerial::ReceiveData got frame type 0x0 command id 0x4 m_iFrameID 38 gwf_ach <0x1406> ACK: 0x6 (^[[36;1m#^[[0m) <0x1406> ZWaveSerial::ReceivedFrame holding the srm mutex for m_iFrameID 38 gwf_ach <0x1406> ZWaveSerial::ReceivedFrame receive data not waiting for frame: (nil)/null ack -1 expect 0 good 0 type 0 cmd:4/0 gd: 1 m_pRes (nil) m_pReq (nil) resp REQUEST p AlarmManager::AddRelativeAlarm current time 1552714088 delay 0 type 52 <0x1406> AlarmManager::AddAbsoluteAlarm alarm 0x7923d0 entry 0x7a8f10 id 54 type 52 param=0x908e38 entry->when: 1552714088 time: 1552714088 bCancelFirst 0=0 <0x1406> AlarmManager::Run 0x7923d0 notified of a change entry 0x8f5718 id 11 deleted 0 <0x803> AlarmManager::Run callback for alarm 0x7923d0 entry 0x7a8f10 type 52 id 54 param=0x908e38 entry->when: 1552714088 time: 1552714088 tnum: 1 slow 0 tardy 0 <0x8 ZWaveJobHandler::DoReceivedFrame m_iFrameID 38 gwf_ach node 38 command 0x4 data <0x803> ZWaveNode::HandlePollUpdate node 38 device 48 class 0x71 command 0x5 m_iFrameID 38/8049496 data 0x0 0x0 0x0 0xff 0x5 0x2 0x0 (^[[34;1m#######^[[0m) <0x803> Device_Variable::m_szValue_set device: 48 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: ^[[35;1mTripped^[[0m was: EMPTY now: 1 #hooks: 0 up UserData::m_iDataVersion_Variables_incr Tripped user data 714071001 variables 714071068 <0x803> luvd_get_info_data_request creating file buffer /data_request?id=lu_status&DataVersion=714071067&MinimumDelay=1000&Timeout=60&LoadTime=1552714071&rand=0.40759 luvd_get_info_data_request done /data_request?id=lu_status&DataVersion=714071067&MinimumDelay=1000&Timeout=60&LoadTime=1552714071&rand=0.4075906705763095 ret mg_callback /data_request stop id: 3 <0x5015> UserData::DataIsDirty UpdateStateList was 1 incr 0 user data 714071001 variables 714071068 <0x803> Device_Variable::m_szValue_set device: 48 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: ^[[35;1mArmedTripped^[[0m was: 1 now: 1 #hooks: 0 u ^[[33;1mZWaveNode::HandlePollUpdate_Alarm node 38 device 48 v1type: 0 v1level: 0 source: 0 status: 255 type: 5 event: 2 parms: 0 code: WATER_LEAK^[[0m <0x803> Device_Variable::m_szValue_set device: 48 service: urn:micasaverde-com:serviceId:HaDevice1 variable: ^[[35;1msl_Alarm^[[0m was: WATER_LEAK now: WATER_LEAK #ho UserData::m_iDataVersion_Variables_incr sl_Alarm user data 714071001 variables 714071069 <0x803> 0x1 0x10 0x0 0x4 0x0 0x26 0xa 0x71 0x5 0x0 0x0 0x0 0xff 0x5 0x0 0x1 0x2 0x4a (^[[34;1m#####&\nq#########J^[[0m) <0x1406> ZWaveSerial::ReceiveData got frame type 0x0 command id 0x4 m_iFrameID 50 gwf_ach <0x1406> ACK: 0x6 (^[[36;1m#^[[0m) <0x1406> ZWaveSerial::ReceivedFrame holding the srm mutex for m_iFrameID 50 gwf_ach <0x1406> ZWaveSerial::ReceivedFrame receive data not waiting for frame: (nil)/null ack -1 expect 0 good 0 type 0 cmd:4/0 gd: 1 m_pRes (nil) m_pReq (nil) resp REQUEST p AlarmManager::AddRelativeAlarm current time 1552714099 delay 0 type 52 <0x1406> AlarmManager::AddAbsoluteAlarm alarm 0x7923d0 entry 0x796cc0 id 63 type 52 param=0x8786b0 entry->when: 1552714099 time: 1552714099 bCancelFirst 0=0 <0x1406> AlarmManager::Run 0x7923d0 notified of a change entry 0x7a2700 id 1 deleted 0 <0x402> AlarmManager::Run 0x7923d0 notified of a change entry 0x7f72e0 id 58 deleted 0 <0x803> AlarmManager::Run callback for alarm 0x7923d0 entry 0x796cc0 type 52 id 63 param=0x8786b0 entry->when: 1552714099 time: 1552714099 tnum: 1 slow 0 tardy 0 <0x8 ZWaveJobHandler::DoReceivedFrame m_iFrameID 50 gwf_ach node 38 command 0x4 data <0x803> ZWaveNode::HandlePollUpdate node 38 device 48 class 0x71 command 0x5 m_iFrameID 50/8841376 data 0x0 0x0 0x0 0xff 0x5 0x0 0x1 0x2 (^[[34;1m########^[[0m) <0x80 ^[[33;1mZWaveNode::HandlePollUpdate_Alarm node 38 device 48 v1type: 0 v1level: 0 source: 0 status: 255 type: 5 event: 0 parms: 1 code: (null)^[[0m <0x803> ZWaveJobHandler::DoReceivedFrame m_iFrameID 50 done 1 <0x803> AlarmManager::Run finish callback for alarm 0x7923d0 entry 0x796cc0 type 52 id 63 param=0x8786b0 entry->when: 1552714099 time: 1552714099 tnum: 1 slow 0 durat

GeekGoneOld · March 17, 2019, 6:28am

Does anyone know if the code for ZWaveNode::HandlePollUpdate is available for viewing? If it is, I may be able to answer my own questions. I suspect my problem is that notification report (command class notification - new to ZW+) is being interpreted as command class alarm.