Corrupt Extended Set/Get Data on motion sensor commands

[dracoventions]

Calling enable_night_only in the insteon_motionsensor branch results in the following error log. Calling get_extended_info behaves similarly.

05/26/2013 04:50:06 PM [Insteon::BaseInterface] DEBUG3: Message received with 2 hops left, delaying next transmit by 250 milliseconds to avoid collisions.
05/26/2013 04:50:06 PM [Insteon::BaseInterface] DEBUG3: PLM command:insteon_received; Device command:extended_set_get; type:direct; group: 
05/26/2013 04:50:06 PM [Insteon::BaseObject] DEBUG3: Adding hop count of 1 to hop_array of $mo_FrontDoorOutside
05/26/2013 04:50:06 PM [Insteon::MotionSensor] Extended Set/Get ACK Received for $mo_FrontDoorOutside
05/26/2013 04:50:07 PM [Insteon_PLM] DEBUG3: Received PLM raw data: 025123195e20f4a91b2e0001016409800e00820e0a4b5d00d1
05/26/2013 04:50:07 PM [Insteon::BaseInterface] DEBUG3: Message received with 2 hops left, plus ACK will take 3 to deliver, delaying next transmit by 1050 milliseconds to avoid collisions.
05/26/2013 04:50:07 PM [Insteon::BaseInterface] DEBUG: PLM command:insteon_ext_received; Device command:extended_set_get; type:direct; group: 
05/26/2013 04:50:07 PM [Insteon::BaseInterface] Processing message for $mo_FrontDoorOutside
05/26/2013 04:50:07 PM [Insteon::MotionSensor] WARN: Corrupt Extended Set/Get Data Received for $mo_FrontDoorOutside
05/26/2013 04:50:09 PM process_queue: Attempting to send 'obj=$mo_FrontDoorOutside; command=extended_set_get; interface_data=23195E1F2e0001000000000000000000000000d1; extra=000100000000000000000000000000'
05/26/2013 04:50:09 PM [Insteon::BaseInterface] WARN: number of retries (5) for obj=$mo_FrontDoorOutside; command=extended_set_get; interface_data=23195E1F2e0001000000000000000000000000d1; extra=000100000000000000000000000000 exceeds limit.  Now moving on...

I fixed the error by changing:

if (substr($msg{extra},0,6) eq "000001") {

to

if (substr($msg{extra},0,6) eq "000101") {

in Security.pm

I don't know if different motion sensors might send back something different, but since get_extended_info is sending '000100000000000000000000000000' (flags=00, D1=01) I think it makes sense that it would return a result starting with '0001' instead of '0000'. I assume the second '01' value for the D2 byte indicates it's a result of a get/set but it could also indicate the value of some setting that could change so I'm not sure if it should be included in the check or not.

[krkeegan]

Interesting, my motion sensor responds to get_extended_info with C2 =00 D1-D2=0001, the full response is below.

025114360f20f5f5132e0000010300ff0c00ff0e01c84d0000

Additionally, the documentation from insteon has the following example:

[TX] - 02 62 AA AA AA 1F 2E 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  
[RX] - 02 50 55 61 09 0D DB 29 27 2E 00
[RX] - 02 51 AA AA AA 11 11 11 13 2E 00 00 01 64 02 23 00 00 00 00 00 00 00 00 00 

It looks like maybe my error is with the get_extended_info which according to the documentation should be all 0s. Although I think I took the message format from HouseLinc.

Just for information what is the release date of your Motion Sensors? Mine are:
5011
1910

[krkeegan]

Yup, setting get_extended_info to all zeros appears to work. I assume your motion sensor will respond with 00 in D1 with this change. I will push it to the repo in a second.

[dracoventions]

When I send all 00s, I still get D1=01:

05/27/2013 08:12:50 AM [Insteon_PLM] DEBUG2: Sending obj=$mo_FrontDoorOutside; command=extended_set_get; interface_data=23195E1A2e0000000000000000000000000000d2; extra=000000000000000000000000000000 incurred delay of 0.46 seconds; starting hop-count: 2
05/27/2013 08:12:50 AM [Insteon_PLM] DEBUG3: Sending  PLM raw data: 026223195e1a2e0000000000000000000000000000d2
05/27/2013 08:12:51 AM [Insteon_PLM] DEBUG3: Received PLM raw data: 026223195e1a2e0000000000000000000000000000d206025023195e110201cb0600
05/27/2013 08:12:51 AM [Insteon_PLM] DEBUG3: Received PLM acknowledge: obj=$mo_FrontDoorOutside; command=extended_set_get; interface_data=23195E1A2e0000000000000000000000000000d2; extra=000000000000000000000000000000
05/27/2013 08:12:51 AM [Insteon::BaseInterface] WARN! Dropped duplicate incoming message 23195e110201cb0600, from $mo_FrontDoorOutside.
05/27/2013 08:12:51 AM [Insteon_PLM] DEBUG3: Received PLM raw data: 025023195e20f4a9262e00
05/27/2013 08:12:51 AM Adding dupe message check key '23195e20f4a9202e00' at 1369667571675 + 348 = 1369667572023
05/27/2013 08:12:51 AM [Insteon::BaseInterface] DEBUG3: Message received with 1 hops left, delaying next transmit by 150 milliseconds to avoid collisions.
05/27/2013 08:12:51 AM [Insteon::BaseInterface] DEBUG3: PLM command:insteon_received; Device command:extended_set_get; type:direct; group: 
05/27/2013 08:12:51 AM [Insteon::BaseObject] DEBUG3: Adding hop count of 1 to hop_array of $mo_FrontDoorOutside
05/27/2013 08:12:51 AM [Insteon::MotionSensor] Extended Set/Get ACK Received for $mo_FrontDoorOutside
05/27/2013 08:12:51 AM [Insteon_PLM] DEBUG3: Received PLM raw data: 025123195e20f4a91b2e0001016409800a00820e0a765d00d2
05/27/2013 08:12:51 AM Adding dupe message check key '23195e20f4a9102e0001016409800a00820e0a765d00d2' at 1369667571885 + 1464 = 1369667573349
05/27/2013 08:12:51 AM [Insteon::BaseInterface] DEBUG3: Message received with 2 hops left, plus ACK will take 3 to deliver, delaying next transmit by 1050 milliseconds to avoid collisions.
05/27/2013 08:12:51 AM [Insteon::BaseInterface] DEBUG: PLM command:insteon_ext_received; Device command:extended_set_get; type:direct; group: 
05/27/2013 08:12:51 AM [Insteon::BaseInterface] Processing message for $mo_FrontDoorOutside
05/27/2013 08:12:51 AM [Insteon::MotionSensor] WARN: Corrupt Extended Set/Get Data Received for $mo_FrontDoorOutside

My motion sensor is 1513 (Feb 2013) and I'm guessing they've added some new status or setting to be reported as D1. Does the documentation mention if D2 is supposed to always return 01 or does 01 represent a setting that could change? Unless the values of D1-D2 are documented and represent things that are sure to not change in future hardware versions, I don't think it's appropriate to be looking for them to have particular values in the response.

Where do you get the documentation you're using?

[krkeegan]

For extended_get_set requests D1 is commonly used through the insteon spec as the data type and D2 is used to signify a response when set to 01. The motion sensor being a relatively simple device currently only has one data type. It seems that Insteon decided recently to move this from a data type 00 to a data type 01. Maybe this signifies an intention on their part to add more data types, who knows.

I think it is appropriate to look for data types that we know work, and throw errors for those that don't. If we simply accept any data type, we may end up in a situation in which MH receives a data_type in which the battery value has been moved. This would result in the battery or light level settings being incorrect, but without any error notifying the user of the potential error.

The Insteon code throughout MH has generally been designed to throw an error early, rather than risk allowing an obscure bug to get buried.

My solution would be to continue to check the returned data_type and allow both D1=00 and D1=01 to be accepted.

[dracoventions]

I suppose that makes sense if that's what D1 tends to be used for. Though wouldn't it be nice if they could make their specs more concrete.

[krkeegan]

Agreed, I can't believe how vague, amorphous, and simply lacking the Insteon specs are. I have seen evidence in other forums that the lack of clear specs has hindered other platforms as well (ISY, Indigo).

[krkeegan]

Fixed cded9e3