Insteon latest binding not working with Motion Sensor

Bernd,

I have posted some logs, but haven’t heard from you, These new forums are a bit odd to find things in, so I’m not sure you’re seeing these posts.

The motion sensor does not work in the latest insteonplm binding. I downloaded it and compiled it myself to make sure.

If I change the items file relating to the motion sensor, it then reads and works briefly, before lapsing into not working again.

Here is what the log looks like when I change the items file:

2015-10-20 19:00:55 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:00:55 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:00:55 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:00:55
2015-10-20 19:00:56 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:00:56 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:00:56 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:00:56 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:00:56
2015-10-20 19:01:22 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:01:22 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:01: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:01: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:01: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:01:25 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:01:25
2015-10-20 19:01: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:01: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:01: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:01:26 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:01:26
2015-10-20 19:01:52 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:01:52 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:01:53 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:01:55 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:01:55 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:01:55 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:01:55 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:01:55
2015-10-20 19:01:56 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:01:56 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:01:56 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:01:56 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:01:56
2015-10-20 19:01:58 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:01:58 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:01:58 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:01:58 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 28.5C.D7
2015-10-20 19:01:58 INFO  o.o.b.i.InsteonPLMActiveBinding[:550]- device 28.5C.D7     found in the modem database!
2015-10-20 19:01:58 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:02:53 DEBUG o.o.b.i.internal.driver.Poller[:83]- stopped polling device 28.5C.D7|data->MotionSensorData(0:1:4)|contact->WirelessMotionSensorContact(0:1:5)|lastheardfrom->GenericLastTime(0:0:0)
2015-10-20 19:02:53 DEBUG o.o.b.i.InsteonPLMActiveBinding[:217]- item porchMotionSensor              binding changed: addr=28.5C.D7|prodKey: 0x00004A|feature:contact|params: related=38.82.16
2015-10-20 19:02:53 INFO  o.o.b.i.InsteonPLMActiveBinding[:477]- device 28.5C.D7 found in the modem database!
2015-10-20 19:02:53 DEBUG o.o.b.i.internal.driver.Poller[:64]- start polling device 28.5C.D7|data->MotionSensorData(0:1:4)|contact->WirelessMotionSensorContact(0:1:5)|lastheardfrom->GenericLastTime(0:0:0)
2015-10-20 19:02:53 DEBUG o.o.b.i.InsteonPLMActiveBinding[:217]- item porchMotionSensorBattery_value binding changed: addr=28.5C.D7|prodKey: 0x00004A|feature:data|params:field=battery_level
2015-10-20 19:02:53 DEBUG o.o.b.i.InsteonPLMActiveBinding[:217]- item porchMotionSensorLight         binding changed: addr=28.5C.D7|prodKey: 0x00004A|feature:data|params:field=light_level
2015-10-20 19:02:53 DEBUG o.o.b.i.InsteonPLMActiveBinding[:217]- item porchMotionDetectorLastUpdate  binding changed: addr=28.5C.D7|prodKey: 0x00004A|feature:lastheardfrom
2015-10-20 19:03:20 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:03:20 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:03:20 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:03:20 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:03:20 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:03:20 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:WirelessMotionSensorContact publishing: OPEN
2015-10-20 19:03:20 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:03:20
2015-10-20 19:03:20 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:03:20 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:03:21 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:03:21 DEBUG o.o.b.i.i.d.MessageDispatcher[:134]- 28.5C.D7:WirelessMotionSensorContact DIRECT_ACK: q:QUERY_PENDING cmd: 80
2015-10-20 19:03:21 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:03:21 DEBUG o.o.b.i.i.d.MessageDispatcher[:159]- defdisp: 28.5C.D7:WirelessMotionSensorContact set status to: QUERY_ANSWERED
2015-10-20 19:03:21 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:03:21
2015-10-20 19:03:22 DEBUG o.o.b.i.i.d.RequestQueueManager[:132]- device queue for 28.5C.D7 is empty!
2015-10-20 19:03:52 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:03:52 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:03:52 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:03:52 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:03:52 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:03:52 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:WirelessMotionSensorContact publishing: CLOSED
2015-10-20 19:03:52 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:03:52
2015-10-20 19:03:52 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:03:52 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:03:54 DEBUG o.o.b.i.i.d.RequestQueueManager[:132]- device queue for 28.5C.D7 is empty!
2015-10-20 19:03:54 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:03:54 DEBUG o.o.b.i.i.d.MessageDispatcher[:134]- 28.5C.D7:WirelessMotionSensorContact DIRECT_ACK: q:QUERY_PENDING cmd: 80
2015-10-20 19:03:54 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:03:54 DEBUG o.o.b.i.i.d.MessageDispatcher[:159]- defdisp: 28.5C.D7:WirelessMotionSensorContact set status to: QUERY_ANSWERED
2015-10-20 19:03:54 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:03:54
2015-10-20 19:03:54 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:03:54 DEBUG o.o.b.i.i.d.MessageHandler[:576]- MotionSensorDataReplyHandler: 28.5C.D7 got light level: 1, battery level: 91
2015-10-20 19:03:54 DEBUG o.o.b.i.i.device.DeviceFeature[:249]- 28.5C.D7:MotionSensorData publishing: 1
2015-10-20 19:03:54 DEBUG o.o.b.i.i.device.DeviceFeature[:249]- 28.5C.D7:MotionSensorData publishing: 91
2015-10-20 19:03:54 DEBUG o.o.b.i.i.d.MessageDispatcher[:151]- 28.5C.D7:WirelessMotionSensorContact->NoOpMsgHandler DIRECT
2015-10-20 19:03:54 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-20T19:03:54

I have a hidden door contact sensor as well and that works fine.

Nick,

This is really weird. I don’t understand where these messages come from:

2015-10-20 19:01:58 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:01:58 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:01:58 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 28.5C.D7: RESP group: 01 data1: 00 data2: 00 data3: 00

The ModemDBBuilder should have long finished gathering the modem database. It does that right upon startup. I wonder if it ever completed in your case. Do you have a line like that in your log:

2015-10-20 19:33:41 INFO  o.o.b.i.InsteonPLMActiveBinding[:536]- modem database has 110 entries!

Bernd,

Yes the entry is there, but remember I said that the motion sensor works once on startup, then stops working. This is log entry is just after startup, when it works once then stops. Is there any way to send you the whole log? Maybe you can see other things in it. I tried to attach one to the forum post, but it only allows images.

Nick Waterton P.Eng.
National Support Leader - Nuclear Medicine, PET and RP
GE Healthcare

M+1 416 859 8545
F +1 905 248 3089
E nick.waterton@med.ge.commailto:nick.waterton@med.ge.com

2300 Meadowvale Boulevard
Mississauga, ON L5N 5P9 Canada

GE imagination at work

Do you think you can wait with triggering it until the full modem db has been downloaded? I wonder if there is a race condition. You are using a hub, I’m going directly off the PLM. For me, the modem db download is virtually instant.

So again, please try to get the full modem db downloaded, only then trigger the motion sensor (and multiple times thereafter).

Bernd

Bernd,

I’m sure that can’t be it, the sensor only triggers at night, and I’ve restarted during the day with no success. I only noticed that it worked once, because I was restarting last night (trying to figure out if something in the items file was the issue).

Is there a way to send you the log? I’ve tried uploading here, but there are all sorts of limits, I can’t even cut and paste.

I can see the database downloading OK. Here is the entry:

2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:104]- got all link records.
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:130]- MDB ------- start of modem link records ------------------
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 1F.7C.03: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 1F.7C.03: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 26.41.54: RESP group: 02 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 26.41.54: RESP group: 03 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 26.41.54: RESP group: 04 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 26.41.54: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 26.41.54: CTRL group: 00 data1: 03 data2: 10 data3: 10
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.65: CTRL group: 27 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.65: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.65: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.65: CTRL group: 0E data1: 03 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.65: CTRL group: 0F data1: 03 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.CB.DA: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 22.C1.89: CTRL group: 17 data1: 0F data2: 06 data3: 06
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 38.85.F6: CTRL group: 0F data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 38.85.F6: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 38.85.F6: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.5C: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.5C: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.5C: CTRL group: 27 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 32.C0.8A: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 32.C0.8A: CTRL group: 27 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 26.5A.BA: CTRL group: 27 data1: 01 data2: 3A data3: 3A
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 26.5A.BA: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 22.17.16: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 22.17.16: RESP group: 03 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 22.17.16: RESP group: 04 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 22.17.16: RESP group: 05 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 22.17.16: RESP group: 06 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 22.17.16: CTRL group: F2 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 22.17.16: CTRL group: F3 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 22.17.16: CTRL group: F4 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 22.17.16: CTRL group: F5 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 22.17.16: CTRL group: F6 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 22.17.16: CTRL group: F7 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 22.17.16: CTRL group: F8 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.0E: CTRL group: 27 data1: 01 data2: 01 data3: 01
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.0E: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.0E: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 38.82.16: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 38.82.16: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.C0.1E: CTRL group: 27 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.C0.1E: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.C0.1E: RESP group: 03 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.C0.1E: RESP group: 04 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.C0.1E: RESP group: 05 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.C0.1E: RESP group: 06 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.C0.1E: CTRL group: F2 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.C0.1E: CTRL group: F3 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.C0.1E: CTRL group: F4 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.C0.1E: CTRL group: F5 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.C0.1E: CTRL group: F6 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.C0.1E: CTRL group: F7 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.C0.1E: CTRL group: F8 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 37.24.16: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 37.24.16: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 32.7E.93: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 32.7E.93: RESP group: 03 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 32.7E.93: RESP group: 04 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 2F.74.A6: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 2F.74.A6: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 2F.74.A6: CTRL group: 10 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 27.4E.7B: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 27.4E.7B: CTRL group: 27 data1: 01 data2: 0E data3: 0E
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 27.4E.7B: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 27.4E.7B: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 33.20.55: CTRL group: 01 data1: 02 data2: 08 data3: 08
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 33.20.55: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 33.20.55: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 36.B4.0C: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 36.B4.0C: RESP group: 02 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 36.B4.0C: RESP group: 04 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 28.43.36: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 11.99.C9: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 11.99.C9: RESP group: 02 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 11.99.C9: RESP group: 03 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 11.99.C9: RESP group: 04 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 11.99.C9: RESP group: 05 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 11.99.C9: RESP group: 06 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 38.19.66: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 38.19.66: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 31.A7.49: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 31.A7.49: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 27.4A.41: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 27.4A.41: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 27.4A.41: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 32.BB.80: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 32.BB.80: CTRL group: 27 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 32.BB.7F: CTRL group: 27 data1: 01 data2: 3A data3: 3A
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 32.BB.7F: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 20.AF.0B: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 20.AF.0B: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 15.0C.D2: CTRL group: 27 data1: 01 data2: 1E data3: 1E
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 15.0C.D2: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 15.0C.D2: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.74: CTRL group: 27 data1: 01 data2: 01 data3: 01
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.74: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.74: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.CA.8E: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 2E.87.56: RESP group: 02 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 2E.87.56: RESP group: 03 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 2E.87.56: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 2E.87.56: RESP group: 04 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 38.80.F5: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 38.80.F5: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 38.80.F5: CTRL group: 1B data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 27.94.5A: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 27.94.5A: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 27.94.5A: CTRL group: 00 data1: 01 data2: 25 data3: 25
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 28.5C.D7: RESP group: 02 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 28.5C.D7: RESP group: 03 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 28.5C.D7: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 1F.C9.FD: CTRL group: 27 data1: 01 data2: 24 data3: 24
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 1F.C9.FD: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 1F.C9.FD: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 2E.87.97: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 2E.87.97: RESP group: 02 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 2E.87.97: RESP group: 03 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 2E.87.97: RESP group: 04 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.F9: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.F9: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 2F.73.A5: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 2F.73.A5: CTRL group: 22 data1: 07 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 2F.73.A5: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 2F.73.A5: CTRL group: 27 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.6D: CTRL group: 27 data1: 01 data2: 01 data3: 01
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.6D: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.6D: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.6D: CTRL group: 0E data1: 03 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.6D: CTRL group: 0F data1: 03 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 38.82.76: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 38.82.76: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 38.DA.D6: CTRL group: 01 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 38.DA.D6: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 38.DA.D6: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 38.DA.D6: CTRL group: 27 data1: 01 data2: 20 data3: 20
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 38.DA.D6: CTRL group: 0F data1: 01 data2: 20 data3: 20
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 25.33.A3: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 34.CB.62: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 34.CB.62: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 34.CB.62: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.F3: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.F3: CTRL group: 00 data1: 01 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:137]- MDB 13.4D.F3: RESP group: 01 data1: 00 data2: 00 data3: 00
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:142]- MDB -----
2015-10-18 15:09:04 DEBUG o.o.b.i.i.d.ModemDBBuilder[:144]- MDB ---------------- end of modem link records -----------
2015-10-18 15:09:04 INFO  o.o.b.i.InsteonPLMActiveBinding[:536]- modem database has 44 entries!
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 1F.7C.03
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 26.41.54
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 13.4D.65
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 13.CB.DA
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 22.C1.89
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 38.85.F6
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 13.4D.5C
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 32.C0.8A
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 26.5A.BA
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 22.17.16
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 13.4D.0E
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 38.82.16
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 13.C0.1E
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 37.24.16
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 32.7E.93
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 2F.74.A6
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 27.4E.7B
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 33.20.55
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 36.B4.0C
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 28.43.36
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 11.99.C9
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 38.19.66
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 31.A7.49
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 27.4A.41
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 32.BB.80
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 32.BB.7F
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 20.AF.0B
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 15.0C.D2
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 13.4D.74
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 13.CA.8E
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 2E.87.56
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 38.80.F5
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 27.94.5A
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 28.5C.D7
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 1F.C9.FD
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 2E.87.97
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 13.4D.F9
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 2F.73.A5
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 13.4D.6D
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 38.82.76
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 38.DA.D6
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 25.33.A3
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 34.CB.62
2015-10-18 15:09:04 DEBUG o.o.b.i.InsteonPLMActiveBinding[:541]- modem db entry: 13.4D.F3

The sensor works once (if it’s at night), then after that you can see the commands coming in, but the binding ignores them. The only thing it sees is the “lastheardfrom” entry, which gets updated.

I can’t post anymore in this message, (reached character limit).

I’ve seen people use pastebin to post logs, but I’ve never used it. A
public google drive document would work as well.

I’ll try to reproduce this at home, but it’s a pain to set up. Give me a
few days. You have a hub or a hub2 (2014)?

Bernd,

I have the old hub (not hub2). I have a new hub pro too, that is set up but not configured yet - don’t think that should mean anything though.

I have just erased the log, started new, and manually activated the motion sensor. It saw the manual OPEN, then the manual CLOSE (0x13), then nothing. I’m not sure if that is working once or twice (an OPEN then CLOSE). Maybe it’s the CLOSE that is killing it? anyway, the log should be small enough to post here. I have to rename it as .xml, but it’s just a text file. If that doesn’t work, I’ll put it in dropbox or something. It’s 9:30 am here (so I have to manually activate the sensor).

insteonplm.log.xml (383.5 KB)

Bernd,

OK, I have turned TRACE on, and captured the log (also looked through the code). It looks like the binding thinks that the messages are duplicates. For some reason the state machine is not advancing.

This is from the TRACE log:

2015-10-21 11:48:06 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-21 11:48:06 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-21 11:48:06 TRACE o.o.b.i.i.d.MessageHandler[:250]- updating group state for 1 to BCAST
2015-10-21 11:48:06 TRACE o.o.b.i.i.d.GroupMessageStateMachine[:122]- group state: EXPECT_CLEAN --BCAST--> EXPECT_CLEAN, publish: false
2015-10-21 11:48:06 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-21 11:48:06 TRACE o.o.b.i.i.d.MessageHandler[:250]- updating group state for 1 to BCAST
2015-10-21 11:48:06 TRACE o.o.b.i.i.d.GroupMessageStateMachine[:122]- group state: EXPECT_CLEAN --BCAST--> EXPECT_CLEAN, publish: false
2015-10-21 11:48:06 TRACE o.o.b.i.i.d.MessageDispatcher[:312]- 28.5C.D7:GenericLastTime->LastTimeHandler IN:Cmd:0x50|fromAddress:28.5C.D7|toAddress:00.00.01|messageFlags:0xCB=ALL_LINK_BROADCAST:3:2|command1:0x11|command2:0x01|
2015-10-21 11:48:06 DEBUG o.o.b.i.i.device.DeviceFeature[:263]- 28.5C.D7:GenericLastTime publishing: 2015-10-21T11:48:06
2015-10-21 11:48:06 TRACE o.o.b.i.i.d.DeviceFeatureListener[:94]- old state: DateTimeType:2015-10-21T11:48:02=?2015-10-21T11:48:06

notice the publish: false entries. Is the state machine expecting to go from BCAST to ALL_LINK_CLEANUP? just trying to figure out what this means “group state: EXPECT_CLEAN --BCAST–> EXPECT_CLEAN, publish: false”

I see that my wireless door contact sensor sends ALL_LINK_BROADCAST, then ALL_LINK_CLEANUP, but the motion sensor never sends ALL_LINK_CLEANUP, just the BROADCAST messages. So the door sensor (which works) goes from BCAST to CLEAN, but the motion sensor does not.

Maybe I’m confused about this, but this looks like it might be the issue.

I’ll keep looking…

Bernd,

I have solved the problem. I had to manually link the motion detector to my hub (making the hub a responder). ie button pressing etc.I did not have to do this before - with the previous version of the binding. The motion sensor is set up in the insteon app, and previously just worked (ie broadcast it’s OPEN/CLOSED state). Now, with the new binding, it seems that I have to manually link it to the hub.

Not sure if this is what was intended, but now I’m not sure how many of my other items are not linked to the hub as a responder, they are all set up in the Insteon app, and houselinc, and that used to be enough.

I would link them all with Insteon-Terminal (looks to be very useful software!), but I can’t get it to run, as it seems to need X11 for the command line interface, and my server is headless. I could install X11, and use it over ssh, but it’s a lot of hassle for a command line interface!

Anyway, problem solved for now…

The Insteon Terminal has been upgraded and no longer needs x11.
Instructions have changed as well.

Nick,
The state engine was introduced quite a while ago and hasn’t changed recently, definitely not with the most recent pull request. And yes, the modem will have to be linked as a responder for broadcast messages to be processed correctly.

The insteon terminal now has a text-only mode so no need for X11 anymore. It will allow you to query the modem database directly so you can see which devices are responders, controllers etc.

Come to think of it: in debug mode the binding also logs the contents modem database. You can just check there what devices the modem is linked to as responder. What you cannot do is probe the device’s database. For that you’ll need the Insteon Terminal (and for the battery operated devices you are out of luck entirely, since they don’t respond to queries).

I am having this problem too but my motion sensor is linked as a controller to my HUB 2245-222.

I can see the motion sensor status in the Insteon App for iphone and it responds there but in openhab I seem to get one action (typically closed) and no others.

The motion sensor controls a scene in the hub consisting of a bunch of workshop lights and those turn on and off correctly.

I deleted and relinked but that didn’t help.

Hmmm…

Have you linked by using the buttons or did you use (Insteon provided) software?

I use the button on the motion sensor and then the button on the HUB but when I do it that way the motion sensor doesn’t show up in the Insteon iPhone app and I can’t link it to the workshop lights.

I then ALSO use the app and link it to the lights.

I wonder if, once the motion sensor is part of a scene, it only sends the scene command (broadcast?) and not it’s regular status?

I really want it directly linked to the lights because they turn on instantaneously versus having openhab sense motion and then turn the lights on.

Tonight, just as a test, I will try removing the motion sensor again and ONLY button push link it - but I don’t think I can live without the hard link to the lights.

I would first link with the insteon app, then with the buttons. I believe the crucial part is how you link with the buttons:

  1. first long-press the sensor, then the hub. The hub must be the responder.
  2. This should not be necessary, but for good measure: long-press the hub first, then the sensor. This should make the sensor a responder to the hub.

The best is to use the InsteonTerminal software to examine your hub’s link database. Not sure you can actually examine the sensor’s database. Maybe if you time the query right such that the sensor is awake at that point in time.