Latest Insteon Binding Motion Sensor Issues

Nicholas_Waterton · October 19, 2015, 3:46am

Bernd,

I can see the data coming in from the binding, but it doesn’t seem to be getting across to the Openhab UI (I can see it being stored as OPEN when it’s CLOSED - ie received command1 0x13.

Here is the latest log. device is 28,5C,D7. I see the command, but there is no corresponding publish. This only started last Thursday, I’m not sure what changed, but I have been changing network settings/rebooting and so on.

2015-10-18 23:30:46 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-18 23:30:46 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-18 23:30:46 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-18 23:30:46 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-18T23:30:46
2015-10-18 23:30:47 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x11|command2:0x01|
2015-10-18 23:30:47 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x11|command2:0x01|
2015-10-18 23:30:47 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x11|command2:0x01|
2015-10-18 23:30:47 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-18T23:30:47
2015-10-18 23:30:47 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: GenericDimmer(1:3:8) OUT:Cmd:0x62|toAddress:13.4D.F9|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|
2015-10-18 23:30:47 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 500 msec, quiettime = 500
2015-10-18 23:30:47 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x62|toAddress:13.4D.F9|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|
2015-10-18 23:30:48 DEBUG o.o.b.i.i.d.RequestQueueManager[:132]- device queue for 13.4D.F9 is empty!
2015-10-18 23:30:48 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:13.4D.F9|toAddress:2A.E7.67|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x01|command2:0xFF|
2015-10-18 23:30:48 DEBUG o.o.b.i.i.d.MessageDispatcher[:134]- 13.4D.F9:GenericDimmer DIRECT_ACK: q:QUERY_PENDING cmd: 80
2015-10-18 23:30:48 DEBUG o.o.b.i.i.d.MessageDispatcher[:139]- changing key to 0x19 for msg IN:Cmd:0x50|fromAddress:13.4D.F9|toAddress:2A.E7.67|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x01|command2:0xFF|
2015-10-18 23:30:48 INFO  o.o.b.i.i.d.MessageHandler[:472]- DimmerRequestReplyHandler: set device 13.4D.F9 to level 100
2015-10-18 23:30:48 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 13.4D.F9:GenericDimmer publishing: 100
2015-10-18 23:30:48 DEBUG o.o.b.i.i.d.MessageDispatcher[:159]- defdisp: 13.4D.F9:GenericDimmer set status to: QUERY_ANSWERED
2015-10-18 23:30:48 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 13.4D.F9:GenericLastTime publishing: 2015-10-18T23:30:48
2015-10-18 23:31:00 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: IOLincContact(1:1:4) OUT:Cmd:0x62|toAddress:2F.73.A5|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x01|
2015-10-18 23:31:00 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 1500 msec, quiettime = 500
2015-10-18 23:31:00 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x62|toAddress:2F.73.A5|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x01|
2015-10-18 23:31:01 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:2F.73.A5|toAddress:2A.E7.67|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x00|command2:0x00|
2015-10-18 23:31:01 DEBUG o.o.b.i.i.d.MessageDispatcher[:134]- 2F.73.A5:IOLincContact DIRECT_ACK: q:QUERY_PENDING cmd: 80
2015-10-18 23:31:01 DEBUG o.o.b.i.i.d.MessageDispatcher[:139]- changing key to 0x19 for msg IN:Cmd:0x50|fromAddress:2F.73.A5|toAddress:2A.E7.67|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x00|command2:0x00|
2015-10-18 23:31:01 INFO  o.o.b.i.i.d.MessageHandler[:700]- ContactRequestReplyHandler: set contact 2F.73.A5 to: OPEN
2015-10-18 23:31:01 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 2F.73.A5:IOLincContact publishing: OPEN
2015-10-18 23:31:01 DEBUG o.o.b.i.i.d.MessageDispatcher[:159]- defdisp: 2F.73.A5:IOLincContact set status to: QUERY_ANSWERED
2015-10-18 23:31:01 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 2F.73.A5:GenericLastTime publishing: 2015-10-18T23:31:01
2015-10-18 23:31:02 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:31.A7.49|toAddress:2A.E7.67|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x14|command2:0xFF|
2015-10-18 23:31:02 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 31.A7.49:GenericLastTime publishing: 2015-10-18T23:31:02
2015-10-18 23:31:02 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: IOLincSwitch(1:1:4) OUT:Cmd:0x62|toAddress:2F.73.A5|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|
2015-10-18 23:31:02 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 500 msec, quiettime = 500
2015-10-18 23:31:02 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x62|toAddress:2F.73.A5|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|
2015-10-18 23:31:02 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:2F.73.A5|toAddress:2A.E7.67|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x00|command2:0x00|
2015-10-18 23:31:02 DEBUG o.o.b.i.i.d.MessageDispatcher[:134]- 2F.73.A5:IOLincSwitch DIRECT_ACK: q:QUERY_PENDING cmd: 80
2015-10-18 23:31:02 DEBUG o.o.b.i.i.d.MessageDispatcher[:139]- changing key to 0x19 for msg IN:Cmd:0x50|fromAddress:2F.73.A5|toAddress:2A.E7.67|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x00|command2:0x00|
2015-10-18 23:31:02 INFO  o.o.b.i.i.d.MessageHandler[:419]- SwitchRequestReplyHandler: set device 2F.73.A5 to OFF
2015-10-18 23:31:02 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 2F.73.A5:IOLincSwitch publishing: OFF
2015-10-18 23:31:02 DEBUG o.o.b.i.i.d.MessageDispatcher[:159]- defdisp: 2F.73.A5:IOLincSwitch set status to: QUERY_ANSWERED
2015-10-18 23:31:02 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 2F.73.A5:GenericLastTime publishing: 2015-10-18T23:31:02
2015-10-18 23:31:02 DEBUG o.o.b.i.i.d.RequestQueueManager[:132]- device queue for 2F.73.A5 is empty!
2015-10-18 23:31:07 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: GenericDimmer(1:3:8) OUT:Cmd:0x62|toAddress:38.82.76|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|
2015-10-18 23:31:07 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 500 msec, quiettime = 500
2015-10-18 23:31:07 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x62|toAddress:38.82.76|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|
2015-10-18 23:31:07 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:38.82.76|toAddress:2A.E7.67|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x01|command2:0x00|
2015-10-18 23:31:07 DEBUG o.o.b.i.i.d.MessageDispatcher[:134]- 38.82.76:GenericDimmer DIRECT_ACK: q:QUERY_PENDING cmd: 80
2015-10-18 23:31:07 DEBUG o.o.b.i.i.d.MessageDispatcher[:139]- changing key to 0x19 for msg IN:Cmd:0x50|fromAddress:38.82.76|toAddress:2A.E7.67|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x01|command2:0x00|
2015-10-18 23:31:07 INFO  o.o.b.i.i.d.MessageHandler[:468]- DimmerRequestReplyHandler: set device 38.82.76 to level 0
2015-10-18 23:31:07 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 38.82.76:GenericDimmer publishing: 0
2015-10-18 23:31:07 DEBUG o.o.b.i.i.d.MessageDispatcher[:159]- defdisp: 38.82.76:GenericDimmer set status to: QUERY_ANSWERED
2015-10-18 23:31:07 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 38.82.76:GenericLastTime publishing: 2015-10-18T23:31:07
2015-10-18 23:31:08 DEBUG o.o.b.i.i.d.RequestQueueManager[:132]- device queue for 38.82.76 is empty!
2015-10-18 23:31:14 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: GenericDimmer(1:3:8) OUT:Cmd:0x62|toAddress:13.4D.6D|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|
2015-10-18 23:31:14 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 500 msec, quiettime = 500
2015-10-18 23:31:14 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x62|toAddress:13.4D.6D|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|
2015-10-18 23:31:14 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:13.4D.6D|toAddress:2A.E7.67|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x02|command2:0xFF|
2015-10-18 23:31:14 DEBUG o.o.b.i.i.d.MessageDispatcher[:134]- 13.4D.6D:GenericDimmer DIRECT_ACK: q:QUERY_PENDING cmd: 80
2015-10-18 23:31:14 DEBUG o.o.b.i.i.d.MessageDispatcher[:139]- changing key to 0x19 for msg IN:Cmd:0x50|fromAddress:13.4D.6D|toAddress:2A.E7.67|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x02|command2:0xFF|
2015-10-18 23:31:14 INFO  o.o.b.i.i.d.MessageHandler[:472]- DimmerRequestReplyHandler: set device 13.4D.6D to level 100
2015-10-18 23:31:14 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 13.4D.6D:GenericDimmer publishing: 100
2015-10-18 23:31:14 DEBUG o.o.b.i.i.d.MessageDispatcher[:159]- defdisp: 13.4D.6D:GenericDimmer set status to: QUERY_ANSWERED
2015-10-18 23:31:14 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 13.4D.6D:GenericLastTime publishing: 2015-10-18T23:31:14
2015-10-18 23:31:14 DEBUG o.o.b.i.i.d.RequestQueueManager[:132]- device queue for 13.4D.6D is empty!
2015-10-18 23:31:14 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:13.4D.6D|toAddress:2A.E7.67|messageFlags:0x23=ACK_OF_DIRECT:3:0|command1:0x02|command2:0xFF|
2015-10-18 23:31:14 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 13.4D.6D:GenericLastTime publishing: 2015-10-18T23:31:14
2015-10-18 23:31:16 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x01|
2015-10-18 23:31:16 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x01|
2015-10-18 23:31:16 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x01|
2015-10-18 23:31:16 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-18T23:31:16
2015-10-18 23:31:17 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x01|
2015-10-18 23:31:17 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x01|
2015-10-18 23:31:17 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x01|
2015-10-18 23:31:17 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-18T23:31:17
2015-10-18 23:31:20 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: GenericDimmer(1:3:8) OUT:Cmd:0x62|toAddress:38.DA.D6|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|
2015-10-18 23:31:20 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 500 msec, quiettime = 500
2015-10-18 23:31:20 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x62|toAddress:38.DA.D6|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|
2015-10-18 23:31:21 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:38.DA.D6|toAddress:2A.E7.67|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x00|command2:0xFE|
2015-10-18 23:31:21 DEBUG o.o.b.i.i.d.MessageDispatcher[:134]- 38.DA.D6:GenericDimmer DIRECT_ACK: q:QUERY_PENDING cmd: 80
2015-10-18 23:31:21 DEBUG o.o.b.i.i.d.MessageDispatcher[:139]- changing key to 0x19 for msg IN:Cmd:0x50|fromAddress:38.DA.D6|toAddress:2A.E7.67|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x00|command2:0xFE|
2015-10-18 23:31:21 INFO  o.o.b.i.i.d.MessageHandler[:472]- DimmerRequestReplyHandler: set device 38.DA.D6 to level 100
2015-10-18 23:31:21 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 38.DA.D6:GenericDimmer publishing: 100
2015-10-18 23:31:21 DEBUG o.o.b.i.i.d.MessageDispatcher[:159]- defdisp: 38.DA.D6:GenericDimmer set status to: QUERY_ANSWERED
2015-10-18 23:31:21 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 38.DA.D6:GenericLastTime publishing: 2015-10-18T23:31:21
2015-10-18 23:31:21 DEBUG o.o.b.i.i.d.RequestQueueManager[:132]- device queue for 38.DA.D6 is empty!
2015-10-18 23:31:27 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: GenericSwitch(1:1:6) OUT:Cmd:0x62|toAddress:25.33.A3|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|
2015-10-18 23:31:27 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 500 msec, quiettime = 500
2015-10-18 23:31:27 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x62|toAddress:25.33.A3|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|
2015-10-18 23:31:28 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:25.33.A3|toAddress:2A.E7.67|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x00|command2:0xFF|
2015-10-18 23:31:28 DEBUG o.o.b.i.i.d.MessageDispatcher[:134]- 25.33.A3:GenericSwitch DIRECT_ACK: q:QUERY_PENDING cmd: 80
2015-10-18 23:31:28 DEBUG o.o.b.i.i.d.MessageDispatcher[:139]- changing key to 0x19 for msg IN:Cmd:0x50|fromAddress:25.33.A3|toAddress:2A.E7.67|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x00|command2:0xFF|
2015-10-18 23:31:28 INFO  o.o.b.i.i.d.MessageHandler[:422]- SwitchRequestReplyHandler: set device 25.33.A3 to ON
2015-10-18 23:31:28 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 25.33.A3:GenericSwitch publishing: ON
2015-10-18 23:31:28 DEBUG o.o.b.i.i.d.MessageDispatcher[:159]- defdisp: 25.33.A3:GenericSwitch set status to: QUERY_ANSWERED
2015-10-18 23:31:28 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 25.33.A3:GenericLastTime publishing: 2015-10-18T23:31:28
2015-10-18 23:31:28 DEBUG o.o.b.i.i.d.RequestQueueManager[:132]- device queue for 25.33.A3 is empty!
2015-10-18 23:31:34 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: GenericDimmer(1:3:8) OUT:Cmd:0x62|toAddress:34.CB.62|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|
2015-10-18 23:31:34 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 500 msec, quiettime = 500
2015-10-18 23:31:34 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x62|toAddress:34.CB.62|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|
2015-10-18 23:31:34 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:34.CB.62|toAddress:2A.E7.67|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x00|command2:0x00|
2015-10-18 23:31:34 DEBUG o.o.b.i.i.d.MessageDispatcher[:134]- 34.CB.62:GenericDimmer DIRECT_ACK: q:QUERY_PENDING cmd: 80
2015-10-18 23:31:34 DEBUG o.o.b.i.i.d.MessageDispatcher[:139]- changing key to 0x19 for msg IN:Cmd:0x50|fromAddress:34.CB.62|toAddress:2A.E7.67|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x00|command2:0x00|
2015-10-18 23:31:34 INFO  o.o.b.i.i.d.MessageHandler[:468]- DimmerRequestReplyHandler: set device 34.CB.62 to level 0
2015-10-18 23:31:34 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 34.CB.62:GenericDimmer publishing: 0
2015-10-18 23:31:34 DEBUG o.o.b.i.i.d.MessageDispatcher[:159]- defdisp: 34.CB.62:GenericDimmer set status to: QUERY_ANSWERED
2015-10-18 23:31:34 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 34.CB.62:GenericLastTime publishing: 2015-10-18T23:31:34
2015-10-18 23:31:34 DEBUG o.o.b.i.i.d.RequestQueueManager[:132]- device queue for 34.CB.62 is empty!
2015-10-18 23:31:40 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: GenericDimmer(1:3:8) OUT:Cmd:0x62|toAddress:13.4D.F3|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|
2015-10-18 23:31:40 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 500 msec, quiettime = 500
2015-10-18 23:31:40 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x62|toAddress:13.4D.F3|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|
2015-10-18 23:31:41 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:13.4D.F3|toAddress:2A.E7.67|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x10|command2:0x00|
2015-10-18 23:31:41 DEBUG o.o.b.i.i.d.MessageDispatcher[:134]- 13.4D.F3:GenericDimmer DIRECT_ACK: q:QUERY_PENDING cmd: 80
2015-10-18 23:31:41 DEBUG o.o.b.i.i.d.MessageDispatcher[:139]- changing key to 0x19 for msg IN:Cmd:0x50|fromAddress:13.4D.F3|toAddress:2A.E7.67|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x10|command2:0x00|
2015-10-18 23:31:41 INFO  o.o.b.i.i.d.MessageHandler[:468]- DimmerRequestReplyHandler: set device 13.4D.F3 to level 0
2015-10-18 23:31:41 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 13.4D.F3:GenericDimmer publishing: 0
2015-10-18 23:31:41 DEBUG o.o.b.i.i.d.MessageDispatcher[:159]- defdisp: 13.4D.F3:GenericDimmer set status to: QUERY_ANSWERED
2015-10-18 23:31:41 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 13.4D.F3:GenericLastTime publishing: 2015-10-18T23:31:41
2015-10-18 23:31:41 DEBUG o.o.b.i.i.d.RequestQueueManager[:132]- device queue for 13.4D.F3 is empty!
2015-10-18 23:32:07 INFO  o.o.b.i.InsteonPLMActiveBinding[:603]- devices:  41 configured,  41 polling, msgs received:   108

Bernd_Pfrommer · October 19, 2015, 12:18pm

Just tested with my motion sensor, and it works fine there (see log below).
Could it be that the contact state is not published because there is no item hooked up to it, i.e. did you remove the item definition that refers to the #contact feature?

2015-10-19 08:13:26 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:27.8C.A3|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x13|command2:0x01|
2015-10-19 08:13:26 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:27.8C.A3|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x13|command2:0x01|
2015-10-19 08:13:26 DEBUG o.o.b.i.i.d.MessageDispatcher[:70]- all link message is no duplicate: true/true
2015-10-19 08:13:26 DEBUG o.o.b.i.i.d.MessageDispatcher[:72]- 27.8C.A3:MotionSensorData->NoOpMsgHandler cmd1:0x13 group 1/1:IN:Cmd:0x50|fromAddress:27.8C.A3|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x13|command2:0x01|
2015-10-19 08:13:26 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:27.8C.A3|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x13|command2:0x01|
2015-10-19 08:13:26 DEBUG o.o.b.i.i.d.MessageDispatcher[:70]- all link message is no duplicate: true/true
2015-10-19 08:13:26 DEBUG o.o.b.i.i.d.MessageDispatcher[:72]- 27.8C.A3:WirelessMotionSensorContact->ClosedSleepingContactHandler cmd1:0x13 group 1/1:IN:Cmd:0x50|fromAddress:27.8C.A3|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x13|command2:0x01|
2015-10-19 08:13:26 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 27.8C.A3:WirelessMotionSensorContact publishing: CLOSED
2015-10-19 08:13:26 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: WirelessMotionSensorContact(1:1:5) OUT:Cmd:0x62|toAddress:27.8C.A3|messageFlags:0x1F=DIRECT:3:3|command1:0x2E|command2:0x00|userData1:0x00|userData2:0x00|userData3:0x00|userData4:0x00|userData5:0x00|userData6:0x00|userData7:0x00|userData8:0x00|userData9:0x00|userData10:0x00|userData11:0x00|userData12:0x00|userData13:0x00|userData14:0xD2|
2015-10-19 08:13:26 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 27.8C.A3:GenericLastTime publishing: 2015-10-19T08:13:26
2015-10-19 08:13:26 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x62|toAddress:27.8C.A3|messageFlags:0x1F=DIRECT:3:3|command1:0x2E|command2:0x00|userData1:0x00|userData2:0x00|userData3:0x00|userData4:0x00|userData5:0x00|userData6:0x00|userData7:0x00|userData8:0x00|userData9:0x00|userData10:0x00|userData11:0x00|userData12:0x00|userData13:0x00|userData14:0xD2|

Nicholas_Waterton · October 20, 2015, 11:41pm

Bernd,

I made another post, I didn’t see your reply. But no I didn’t delete the contact item. If I change the items file relating to the motion sensor, it works once, then stops responding again.

this is my log:

2015-10-20 19:36:50 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:28.5C.D7|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2015-10-20 19:37:19 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x02|LinkAddr:28.5C.D7|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2015-10-20 19:37:19 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x03|LinkAddr:28.5C.D7|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2015-10-20 19:37:20 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:28.5C.D7|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2015-10-20 19:37:25 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:37:25 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:37:25 DEBUG o.o.b.i.i.d.MessageDispatcher[:72]- 28.5C.D7:MotionSensorData->NoOpMsgHandler cmd1:0x11 group 1/1:IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:37:25 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:37:25 DEBUG o.o.b.i.i.d.MessageDispatcher[:72]- 28.5C.D7:WirelessMotionSensorContact->OpenedSleepingContactHandler cmd1:0x11 group 1/1:IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:37:25 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:WirelessMotionSensorContact publishing: OPEN
2015-10-20 19:37:25 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:37:25
2015-10-20 19:37:25 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: WirelessMotionSensorContact(1:1:5) OUT:Cmd:0x62|toAddress:28.5C.D7|messageFlags:0x1F=DIRECT:3:3|command1:0x2E|command2:0x00|userData1:0x00|userData2:0x00|userData3:0x00|userData4:0x00|userData5:0x00|userData6:0x00|userData7:0x00|userData8:0x00|userData9:0x00|userData10:0x00|userData11:0x00|userData12:0x00|userData13:0x00|userData14:0xD2|
2015-10-20 19:37:25 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x62|toAddress:28.5C.D7|messageFlags:0x1F=DIRECT:3:3|command1:0x2E|command2:0x00|userData1:0x00|userData2:0x00|userData3:0x00|userData4:0x00|userData5:0x00|userData6:0x00|userData7:0x00|userData8:0x00|userData9:0x00|userData10:0x00|userData11:0x00|userData12:0x00|userData13:0x00|userData14:0xD2|
2015-10-20 19:37:27 DEBUG o.o.b.i.i.d.RequestQueueManager[:132]- device queue for 28.5C.D7 is empty!
2015-10-20 19:37:28 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:2A.E7.67|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x2E|command2:0x00|
2015-10-20 19:37:28 DEBUG o.o.b.i.i.d.MessageDispatcher[:134]- 28.5C.D7:WirelessMotionSensorContact DIRECT_ACK: q:QUERY_PENDING cmd: 80
2015-10-20 19:37:28 DEBUG o.o.b.i.i.d.MessageDispatcher[:139]- changing key to 0x19 for msg IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:2A.E7.67|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x2E|command2:0x00|
2015-10-20 19:37:28 DEBUG o.o.b.i.i.d.MessageDispatcher[:159]- defdisp: 28.5C.D7:WirelessMotionSensorContact set status to: QUERY_ANSWERED
2015-10-20 19:37:28 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:37:28
2015-10-20 19:37:28 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x51|fromAddress:28.5C.D7|toAddress:2A.E7.67|messageFlags:0x17=DIRECT:3:1|command1:0x2E|command2:0x00|userData1:0x01|userData2:0x01|userData3:0x00|userData4:0x00|userData5:0x33|userData6:0x1A|userData7:0x00|userData8:0x80|userData9:0x0E|userData10:0x01|userData11:0x1A|userData12:0x5B|userData13:0x00|userData14:0xD2|
2015-10-20 19:37:28 DEBUG o.o.b.i.i.d.MessageHandler[:576]- MotionSensorDataReplyHandler: 28.5C.D7 got light level: 26, battery level: 91
2015-10-20 19:37:28 DEBUG o.o.b.i.i.device.DeviceFeature[:249]- 28.5C.D7:MotionSensorData publishing: 26
2015-10-20 19:37:28 DEBUG o.o.b.i.i.device.DeviceFeature[:249]- 28.5C.D7:MotionSensorData publishing: 91
2015-10-20 19:37:28 DEBUG o.o.b.i.i.d.MessageDispatcher[:151]- 28.5C.D7:WirelessMotionSensorContact->NoOpMsgHandler DIRECT
2015-10-20 19:37:28 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:37:28
2015-10-20 19:37:39 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:37:39 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:37:39 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:37:39 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:37:39
2015-10-20 19:37:40 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:37:40 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:37:40 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:37:40 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:37:40
2015-10-20 19:37:49 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x02|LinkAddr:28.5C.D7|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2015-10-20 19:37:49 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x03|LinkAddr:28.5C.D7|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2015-10-20 19:37:50 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:28.5C.D7|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2015-10-20 19:38:09 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x13|command2:0x01|
2015-10-20 19:38:09 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x13|command2:0x01|
2015-10-20 19:38:09 DEBUG o.o.b.i.i.d.MessageDispatcher[:72]- 28.5C.D7:MotionSensorData->NoOpMsgHandler cmd1:0x13 group 1/1:IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x13|command2:0x01|
2015-10-20 19:38:09 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x13|command2:0x01|
2015-10-20 19:38:09 DEBUG o.o.b.i.i.d.MessageDispatcher[:72]- 28.5C.D7:WirelessMotionSensorContact->ClosedSleepingContactHandler cmd1:0x13 group 1/1:IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x13|command2:0x01|
2015-10-20 19:38:09 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:WirelessMotionSensorContact publishing: CLOSED
2015-10-20 19:38:09 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: WirelessMotionSensorContact(1:1:5) OUT:Cmd:0x62|toAddress:28.5C.D7|messageFlags:0x1F=DIRECT:3:3|command1:0x2E|command2:0x00|userData1:0x00|userData2:0x00|userData3:0x00|userData4:0x00|userData5:0x00|userData6:0x00|userData7:0x00|userData8:0x00|userData9:0x00|userData10:0x00|userData11:0x00|userData12:0x00|userData13:0x00|userData14:0xD2|
2015-10-20 19:38:09 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:38:09
2015-10-20 19:38:09 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x62|toAddress:28.5C.D7|messageFlags:0x1F=DIRECT:3:3|command1:0x2E|command2:0x00|userData1:0x00|userData2:0x00|userData3:0x00|userData4:0x00|userData5:0x00|userData6:0x00|userData7:0x00|userData8:0x00|userData9:0x00|userData10:0x00|userData11:0x00|userData12:0x00|userData13:0x00|userData14:0xD2|
2015-10-20 19:38:11 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:2A.E7.67|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x2E|command2:0x00|
2015-10-20 19:38:11 DEBUG o.o.b.i.i.d.MessageDispatcher[:134]- 28.5C.D7:WirelessMotionSensorContact DIRECT_ACK: q:QUERY_PENDING cmd: 80
2015-10-20 19:38:11 DEBUG o.o.b.i.i.d.MessageDispatcher[:139]- changing key to 0x19 for msg IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:2A.E7.67|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x2E|command2:0x00|
2015-10-20 19:38:11 DEBUG o.o.b.i.i.d.MessageDispatcher[:159]- defdisp: 28.5C.D7:WirelessMotionSensorContact set status to: QUERY_ANSWERED
2015-10-20 19:38:11 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:38:11
2015-10-20 19:38:11 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x51|fromAddress:28.5C.D7|toAddress:2A.E7.67|messageFlags:0x17=DIRECT:3:1|command1:0x2E|command2:0x00|userData1:0x01|userData2:0x01|userData3:0x00|userData4:0x00|userData5:0x33|userData6:0x1A|userData7:0x00|userData8:0x80|userData9:0x0E|userData10:0x00|userData11:0x01|userData12:0x5B|userData13:0x00|userData14:0xD2|
2015-10-20 19:38:11 DEBUG o.o.b.i.i.d.MessageHandler[:576]- MotionSensorDataReplyHandler: 28.5C.D7 got light level: 1, battery level: 91
2015-10-20 19:38:11 DEBUG o.o.b.i.i.device.DeviceFeature[:249]- 28.5C.D7:MotionSensorData publishing: 1
2015-10-20 19:38:11 DEBUG o.o.b.i.i.device.DeviceFeature[:249]- 28.5C.D7:MotionSensorData publishing: 91
2015-10-20 19:38:11 DEBUG o.o.b.i.i.d.MessageDispatcher[:151]- 28.5C.D7:WirelessMotionSensorContact->NoOpMsgHandler DIRECT
2015-10-20 19:38:11 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:38:11
2015-10-20 19:38:11 DEBUG o.o.b.i.i.d.RequestQueueManager[:132]- device queue for 28.5C.D7 is empty!
2015-10-20 19:38:12 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 28.5C.D7: RESP group: 02 data1: 00 data2: 00 data3: 00
2015-10-20 19:38:12 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 28.5C.D7: RESP group: 03 data1: 00 data2: 00 data3: 00
2015-10-20 19:38:12 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 28.5C.D7: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-20 19:38:12 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 28.5C.D7
2015-10-20 19:38:12 INFO  o.o.b.i.InsteonPLMActiveBinding[:550]- device 28.5C.D7     found in the modem database!
2015-10-20 19:38:12 DEBUG o.o.b.i.internal.driver.Poller[:64]- start polling device 28.5C.D7|data->MotionSensorData(2:1:4)|contact->WirelessMotionSensorContact(1:1:5)|lastheardfrom->GenericLastTime(1:0:0)
2015-10-20 19:39:16 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:39:16 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:39:16 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:39:16 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:39:16
2015-10-20 19:39:26 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:39:26 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:39:26 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:39:26 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:39:26
2015-10-20 19:39:27 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:39:27 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:39:27 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-20 19:39:27 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:39:27
2015-10-20 19:39:41 DEBUG o.o.b.i.InsteonPLMActiveBinding[:522]- got msg: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xC3=ALL_LINK_BROADCAST:3:0|command1:0x11|command2:0x01|
2015-10-20 19:39:41 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xC3=ALL_LINK_BROADCAST:3:0|command1:0x11|command2:0x01|
2015-10-20 19:39:41 DEBUG o.o.b.i.i.d.MessageDispatcher[:68]- all link message: IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xC3=ALL_LINK_BROADCAST:3:0|command1:0x11|command2:0x01|
2015-10-20 19:39:41 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:39:41

So my question to you is - does your motion sensor respond more than once? mine works, then stops.