Insteon IO Linc Garage Door troubles

jonsteinmetz · January 4, 2016, 3:46am

I am playing around with OpenHAB and trying to get my garage door opener to correctly update the status of the door. I am using the IO Linc garage door kit and things are working for the most part. My insteon items and sitemap are configured exactly like the PLM binding [docs] (https://github.com/openhab/openhab/wiki/Insteon-PLM-Binding#io-linc-garage-door-openers). This yields a switch which can control the garage door and it works. The problem is that the status does not update quickly enough. I have also been using Indigo and it has some notes in its UI for this device that seem to indicate that it will poll the status of the device 4 seconds after detecting a state change in order to refresh the state. I can see that this seems to be needed because it appears that the device sends out the old state when the state changes. That is, if the garage door is closed and I go press the wall switch to open it the logs indicate that the state being sent is closed. Here is an edited part of the log:

21:37:30.727 [DEBUG] [o.o.b.i.i.device.DeviceFeature:250  ] - 34.8B.3E:IOLincContact publishing: CLOSED
21:37:30.731 [INFO ] [runtime.busevents             :26   ] - garageDoorContact state updated to CLOSED

If I wait around long enough the state will be updated to be open by what I assume is a polling feature of the binding.
I have made a rule to run when the state changes and it does get triggered and what I would like to do is set a timer and trigger the polling to happen after 4 seconds but I have not figured out how to trigger the polling. I have searched around on this forum and the net and have not found anything yet.
So I guess I have two questions:

Is there a better way to have the status update immediately other than triggering the polling? It seems that the IO Linc have a few configuration options so maybe I have it misconfigured.
Is there a way to poll a device from a rule?

Thanks

Bernd_Pfrommer · January 4, 2016, 4:31pm

It’s been a while since I last used the I/O Linc for my garage door, but I don’t recall having to poll afterwards.
I would expect the device to send out a group broadcast announcement the moment it detects open or closed. You need to link your modem as a responder to the I/O linc so it actually sees these messages. Make sure that is done. If you just link it as controller, then you’ll be able to open/close the door, but the modem will not get notified when the sensor updates.

jonsteinmetz · January 4, 2016, 7:29pm

Thanks. I am definitely seeing the message when the contact changes state, but it appears to be sending out the old state. So if manually operate the door opener I immediately see a state change but it appears to be the old state. A little later when the normal polling process happens the state updates to its correct state.

Thanks

Bernd_Pfrommer · January 4, 2016, 7:32pm

Jon,
Please switch on debug logging and post the log at the time when the broadcast message is sent. I want to see exactly what message is coming in. I do not recall the sensor sending out the wrong state, so something funny is going on here.

ranielsen · January 4, 2016, 7:50pm

I have an I/O Linc on each garage door. Here’s the event log for the past couple of days. I’m not seeing the previous state show up:

$ egrep “OPEN|CLOSE” events.log
2016-01-03 11:54:32 - garageDoor1 state updated to OPEN
2016-01-03 11:55:26 - garageDoor1 state updated to CLOSED
2016-01-03 14:38:19 - garageDoor1 state updated to OPEN
2016-01-03 14:39:11 - garageDoor1 state updated to CLOSED
2016-01-03 16:34:04 - garageDoor1 state updated to OPEN
2016-01-03 16:34:49 - garageDoor1 state updated to CLOSED
2016-01-03 17:35:16 - garageDoor1 state updated to OPEN
2016-01-03 17:36:35 - garageDoor1 state updated to CLOSED
2016-01-04 06:49:48 - garageDoor1 state updated to OPEN
2016-01-04 06:50:30 - garageDoor1 state updated to CLOSED
2016-01-04 08:10:37 - garageDoor2 state updated to OPEN
2016-01-04 08:11:53 - garageDoor2 state updated to CLOSED
2016-01-04 08:50:48 - garageDoor1 state updated to OPEN
2016-01-04 08:55:35 - garageDoor1 state updated to CLOSED
2016-01-04 13:36:01 - garageDoor1 state updated to OPEN
2016-01-04 13:36:32 - garageDoor1 state updated to CLOSED

Everything looks as expected. The last OPEN/CLOSE I triggered remotely. BTW, I’m using a PLM not a hub.

jonsteinmetz · January 4, 2016, 9:33pm

Great, I switched on debug logging following these instructions. Starting in the closed position I manually pressed the button to open the garage door. Here is the new contents in the insteonplm.log file:

2016-01-04 15:23:00 DEBUG o.o.b.i.InsteonPLMActiveBinding[:511]- got msg: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x02|command2:0x00|
2016-01-04 15:23:00 DEBUG o.o.b.i.i.d.MessageDispatcher[:123]- defdisp: 34.8B.3E:IOLincContact qs:QUERY_ANSWERED cmd: 80
2016-01-04 15:23:00 DEBUG o.o.b.i.i.d.MessageDispatcher[:123]- defdisp: 34.8B.3E:IOLincSwitch qs:QUERY_PENDING cmd: 80
2016-01-04 15:23:00 DEBUG o.o.b.i.i.d.MessageDispatcher[:129]- changing key to 0x19 for msg IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x02|command2:0x00|
2016-01-04 15:23:00 DEBUG o.o.b.i.i.d.MessageDispatcher[:139]- 34.8B.3E:IOLincSwitch->SwitchRequestReplyHandler DIRECT: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x02|command2:0x00|
2016-01-04 15:23:00 INFO  o.o.b.i.i.d.MessageHandler[:333]- SwitchRequestReplyHandler: set device 34.8B.3E to OFF
2016-01-04 15:23:00 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:IOLincSwitch publishing: OFF
2016-01-04 15:23:00 DEBUG o.o.b.i.i.d.MessageDispatcher[:145]- defdisp: 34.8B.3E:IOLincSwitch set status to: QUERY_ANSWERED
2016-01-04 15:23:00 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:GenericLastTime publishing: 2016-01-04T15:23:00
2016-01-04 15:23:00 DEBUG o.o.b.i.i.d.RequestQueueManager[:129]- device queue for 34.8B.3E is empty!
2016-01-04 15:24:51 DEBUG o.o.b.i.InsteonPLMActiveBinding[:511]- got msg: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x00|
2016-01-04 15:24:51 DEBUG o.o.b.i.i.d.MessageDispatcher[:62]- 34.8B.3E:IOLincContact->ClosedContactHandler cmd1:0x13 group 1/1:IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x00|
2016-01-04 15:24:51 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:IOLincContact publishing: CLOSED
2016-01-04 15:24:51 DEBUG o.o.b.i.i.d.MessageDispatcher[:62]- 34.8B.3E:IOLincSwitch->NoOpMsgHandler cmd1:0x13 group 1/1:IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x00|
2016-01-04 15:24:51 DEBUG o.o.b.i.i.d.MessageHandler[:230]- NoOpMsgHandler ignore msg 0x13: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x00|
2016-01-04 15:24:51 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:GenericLastTime publishing: 2016-01-04T15:24:51
2016-01-04 15:24:52 DEBUG o.o.b.i.InsteonPLMActiveBinding[:511]- got msg: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x13|command2:0x01|
2016-01-04 15:24:52 DEBUG o.o.b.i.i.d.MessageDispatcher[:62]- 34.8B.3E:IOLincContact->ClosedContactHandler cmd1:0x13 group 1/1:IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x13|command2:0x01|
2016-01-04 15:24:52 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:IOLincContact publishing: CLOSED
2016-01-04 15:24:52 DEBUG o.o.b.i.i.d.MessageDispatcher[:62]- 34.8B.3E:IOLincSwitch->NoOpMsgHandler cmd1:0x13 group 1/1:IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x13|command2:0x01|
2016-01-04 15:24:52 DEBUG o.o.b.i.i.d.MessageHandler[:230]- NoOpMsgHandler ignore msg 0x13: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x13|command2:0x01|
2016-01-04 15:24:52 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:GenericLastTime publishing: 2016-01-04T15:24:52

Here are the new contents of the events.log file:

2016-01-04 15:24:51 - garageDoorContact state updated to CLOSED
2016-01-04 15:24:52 - garageDoorContact state updated to CLOSED

A couple minutes later these entries appeared in the insteonplm.log file:

2016-01-04 15:27:57 DEBUG o.o.b.i.i.device.InsteonDevice[:344]- qe taken off direct: IOLincContact(1:1:4) OUT:Cmd:0x62|toAddress:34.8B.3E|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x01|
2016-01-04 15:27:57 DEBUG o.o.b.i.i.device.InsteonDevice[:364]- next request queue processed in 3000 msec, quiettime = 500
2016-01-04 15:27:57 DEBUG o.o.b.i.internal.driver.Port[:320]- writing (500): OUT:Cmd:0x62|toAddress:34.8B.3E|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x01|
2016-01-04 15:27:57 DEBUG o.o.b.i.InsteonPLMActiveBinding[:511]- got msg: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x02|command2:0x00|
2016-01-04 15:27:57 DEBUG o.o.b.i.i.d.MessageDispatcher[:123]- defdisp: 34.8B.3E:IOLincContact qs:QUERY_PENDING cmd: 80
2016-01-04 15:27:57 DEBUG o.o.b.i.i.d.MessageDispatcher[:129]- changing key to 0x19 for msg IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x02|command2:0x00|
2016-01-04 15:27:57 DEBUG o.o.b.i.i.d.MessageDispatcher[:139]- 34.8B.3E:IOLincContact->ContactRequestReplyHandler DIRECT: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x02|command2:0x00|
2016-01-04 15:27:57 INFO  o.o.b.i.i.d.MessageHandler[:586]- ContactRequestReplyHandler: set contact 34.8B.3E to: OPEN
2016-01-04 15:27:57 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:IOLincContact publishing: OPEN
2016-01-04 15:27:57 DEBUG o.o.b.i.i.d.MessageDispatcher[:145]- defdisp: 34.8B.3E:IOLincContact set status to: QUERY_ANSWERED
2016-01-04 15:27:57 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:GenericLastTime publishing: 2016-01-04T15:27:57
2016-01-04 15:28:00 DEBUG o.o.b.i.i.device.InsteonDevice[:344]- qe taken off direct: IOLincSwitch(1:1:4) OUT:Cmd:0x62|toAddress:34.8B.3E|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|
2016-01-04 15:28:00 DEBUG o.o.b.i.i.device.InsteonDevice[:364]- next request queue processed in 500 msec, quiettime = 500
2016-01-04 15:28:00 DEBUG o.o.b.i.internal.driver.Port[:320]- writing (500): OUT:Cmd:0x62|toAddress:34.8B.3E|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x00|

Thanks for taking a look.

Bernd_Pfrommer · January 5, 2016, 12:03am

It should be sending a 0x13 when it closes, and a 0x11 when the contact opens. No idea why it isn’t doing it. It’s sending 0x13, one time with cmd2=0, another time with cmd2=1. Does it send cmd2=1 when it means open (or vice versa)?

jonsteinmetz · January 5, 2016, 5:21pm

OK, I made a change to the IO Linc to send an ON command when the sensor changes and it appears to be sending the correct state now. Here is the output in the insteonplm.log when I opened the garage door from a closed state, then closed it again:

2016-01-05 10:47:59 DEBUG o.o.b.i.InsteonPLMActiveBinding[:511]- got msg: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x11|command2:0x00|
2016-01-05 10:47:59 DEBUG o.o.b.i.i.d.MessageDispatcher[:62]- 34.8B.3E:IOLincContact->OpenedContactHandler cmd1:0x11 group 1/1:IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x11|command2:0x00|
2016-01-05 10:47:59 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:IOLincContact publishing: OPEN
2016-01-05 10:47:59 DEBUG o.o.b.i.i.d.MessageDispatcher[:62]- 34.8B.3E:IOLincSwitch->NoOpMsgHandler cmd1:0x11 group 1/1:IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x11|command2:0x00|
2016-01-05 10:47:59 DEBUG o.o.b.i.i.d.MessageHandler[:230]- NoOpMsgHandler ignore msg 0x11: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x11|command2:0x00|
2016-01-05 10:47:59 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:GenericLastTime publishing: 2016-01-05T10:47:59
2016-01-05 10:48:00 DEBUG o.o.b.i.InsteonPLMActiveBinding[:511]- got msg: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x11|command2:0x01|
2016-01-05 10:48:00 DEBUG o.o.b.i.i.d.MessageDispatcher[:62]- 34.8B.3E:IOLincContact->OpenedContactHandler cmd1:0x11 group 1/1:IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x11|command2:0x01|
2016-01-05 10:48:00 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:IOLincContact publishing: OPEN
2016-01-05 10:48:00 DEBUG o.o.b.i.i.d.MessageDispatcher[:62]- 34.8B.3E:IOLincSwitch->NoOpMsgHandler cmd1:0x11 group 1/1:IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x11|command2:0x01|
2016-01-05 10:48:00 DEBUG o.o.b.i.i.d.MessageHandler[:230]- NoOpMsgHandler ignore msg 0x11: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x11|command2:0x01|
2016-01-05 10:48:00 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:GenericLastTime publishing: 2016-01-05T10:48:00
2016-01-05 10:48:00 DEBUG o.o.b.i.InsteonPLMActiveBinding[:511]- got msg: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:11.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|
2016-01-05 10:48:00 DEBUG o.o.b.i.i.d.MessageDispatcher[:62]- 34.8B.3E:IOLincContact->OpenedContactHandler cmd1:0x11 group 1/1:IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:11.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|
2016-01-05 10:48:00 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:IOLincContact publishing: OPEN
2016-01-05 10:48:00 DEBUG o.o.b.i.i.d.MessageDispatcher[:62]- 34.8B.3E:IOLincSwitch->NoOpMsgHandler cmd1:0x11 group 1/1:IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:11.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|
2016-01-05 10:48:00 DEBUG o.o.b.i.i.d.MessageHandler[:230]- NoOpMsgHandler ignore msg 0x11: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:11.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|
2016-01-05 10:48:00 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:GenericLastTime publishing: 2016-01-05T10:48:00
2016-01-05 10:49:52 DEBUG o.o.b.i.InsteonPLMActiveBinding[:511]- got msg: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x00|
2016-01-05 10:49:52 DEBUG o.o.b.i.i.d.MessageDispatcher[:62]- 34.8B.3E:IOLincContact->ClosedContactHandler cmd1:0x13 group 1/1:IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x00|
2016-01-05 10:49:52 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:IOLincContact publishing: CLOSED
2016-01-05 10:49:52 DEBUG o.o.b.i.i.d.MessageDispatcher[:62]- 34.8B.3E:IOLincSwitch->NoOpMsgHandler cmd1:0x13 group 1/1:IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x00|
2016-01-05 10:49:52 DEBUG o.o.b.i.i.d.MessageHandler[:230]- NoOpMsgHandler ignore msg 0x13: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x00|
2016-01-05 10:49:52 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:GenericLastTime publishing: 2016-01-05T10:49:52
2016-01-05 10:49:53 DEBUG o.o.b.i.InsteonPLMActiveBinding[:511]- got msg: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x13|command2:0x01|
2016-01-05 10:49:53 DEBUG o.o.b.i.i.d.MessageDispatcher[:62]- 34.8B.3E:IOLincContact->ClosedContactHandler cmd1:0x13 group 1/1:IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x13|command2:0x01|
2016-01-05 10:49:53 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:IOLincContact publishing: CLOSED
2016-01-05 10:49:53 DEBUG o.o.b.i.i.d.MessageDispatcher[:62]- 34.8B.3E:IOLincSwitch->NoOpMsgHandler cmd1:0x13 group 1/1:IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x13|command2:0x01|
2016-01-05 10:49:53 DEBUG o.o.b.i.i.d.MessageHandler[:230]- NoOpMsgHandler ignore msg 0x13: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:33.E4.23|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x13|command2:0x01|
2016-01-05 10:49:53 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:GenericLastTime publishing: 2016-01-05T10:49:53
2016-01-05 10:49:53 DEBUG o.o.b.i.InsteonPLMActiveBinding[:511]- got msg: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:13.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|
2016-01-05 10:49:53 DEBUG o.o.b.i.i.d.MessageDispatcher[:62]- 34.8B.3E:IOLincContact->ClosedContactHandler cmd1:0x13 group 1/1:IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:13.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|
2016-01-05 10:49:53 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:IOLincContact publishing: CLOSED
2016-01-05 10:49:53 DEBUG o.o.b.i.i.d.MessageDispatcher[:62]- 34.8B.3E:IOLincSwitch->NoOpMsgHandler cmd1:0x13 group 1/1:IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:13.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|
2016-01-05 10:49:53 DEBUG o.o.b.i.i.d.MessageHandler[:230]- NoOpMsgHandler ignore msg 0x13: IN:Cmd:0x50|fromAddress:34.8B.3E|toAddress:13.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|
2016-01-05 10:49:53 DEBUG o.o.b.i.i.device.DeviceFeature[:250]- 34.8B.3E:GenericLastTime publishing: 2016-01-05T10:49:53

I updated the IO Linc using my copy of Indigo on the Mac and the checkbox was titled “Input sensor opened sends INSTEON ON command”. It is possible I changed it to the other state while initially setting up the controller in Indigo.
Now I need to figure out why it is getting broadcast 3 times. It looks like one is a group broadcast, one is a message to the PLM, and the third to another device. It looks like that other device (11.01.01) is marked as cannot be removed from the devices internal settings according to the Indigo UI. I will keep investigating and will take a look at insteon-terminal though it seems to have a limited knowledge of instead device types. Any other suggestions for managing the PLM and device settings?

Thanks for all of the help

Bernd_Pfrommer · January 5, 2016, 6:22pm

If a device is linked correctly as a responder (and it looks like your PLM is), you will see 3 messages for each event:

The original broadcast, which enables a single device to quickly signal its state change to all devices on the network
The CLEANUP, which is not really a broadcast but a direct point-to-point message to all linked devices sequentially to make sure everybody got it.
The CLEANUP SUCCESS (cmd2 = 0x06), a broadcast indicating whether the device has gotten acks from all responders that it has send a CLEANUP to.

So this is not a sign of misconfiguration.
But nevertheless, the InsteonTerminal is great for looking at link state. Querying the modem link state should definitely work. I think at some point I added a 2450 device. If it still works at all, I don’t know. But the code base is very small, you can easily fix things that are broken.

ranielsen · January 5, 2016, 6:37pm

I have 2 - 2450’s and I haven’t had any issues with either of them.

LORDUDE · April 6, 2016, 3:34pm

Is anybody having random OPEN trigger events with I/O lincs? I was running OpenHab on a raspberry Pi for few weeks and never had a false trigger with the garage I/O lincs. Because I did not like the performance of OpenHab on the RPi I switched to a Celeron NUC running on mSSD (huge difference in performance) however now I’m getting random triggers on both I/O Links simultaneously day and night. The triggers only last few few seconds (goes to open during one poll and back to close on the next poll) I have change poll times from 1sec all the way up to 30sec and is does not make any difference. I’m using a 2012 Hub with the RPi connecting to it thru WLAN (Hub is in a different subnet) the NUC is connecting to the Hub on eth1 which should be more reliable.

Both OpenHab RPi and NUC were running on Debian Jessie, I move the configuration from one distro to the other (one nice feature of OpenHab)

craigh · July 19, 2016, 6:21pm

I think I am seeing an error with my garage door contact.

I start up openhab, so the value for the contact is NULL

What I believe is then happening is when the binding polls for the status, it incorrectly is handling the messages, resulting in a CLOSED state.

2016-07-19 10:57:59.670 [DEBUG] [i.i.device.RequestQueueManager:101  ] - starting request queue thread
2016-07-19 10:57:59.676 [DEBUG] [o.o.b.i.i.device.InsteonDevice:459  ] - qe taken off direct: IOLincContact(1:1:4) OUT:Cmd:0x62|toAddress:3D.E5.56|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x01|
2016-07-19 10:57:59.677 [DEBUG] [o.o.b.i.i.device.InsteonDevice:479  ] - next request queue processed in 500 msec, quiettime = 500
2016-07-19 10:57:59.678 [DEBUG] [o.o.b.i.internal.driver.Port  :415  ] - writing (500): OUT:Cmd:0x62|toAddress:3D.E5.56|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x01|
2016-07-19 10:58:00.120 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:591  ] - got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x00|command2:0x01|
2016-07-19 10:58:00.121 [DEBUG] [b.i.i.device.MessageDispatcher:149  ] - 3D.E5.56:IOLincContact DIRECT_ACK: q:QUERY_PENDING cmd: 80
2016-07-19 10:58:00.122 [DEBUG] [b.i.i.device.MessageDispatcher:154  ] - changing key to 0x19 for msg IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x00|command2:0x01|
2016-07-19 10:58:00.127 [INFO ] [.o.b.i.i.device.MessageHandler:834  ] - ContactRequestReplyHandler: set contact 3D.E5.56 to: CLOSED
2016-07-19 10:58:00.129 [DEBUG] [o.o.b.i.i.device.DeviceFeature:321  ] - 3D.E5.56:IOLincContact publishing: CLOSED
2016-07-19 10:58:00.137 [DEBUG] [b.i.i.device.MessageDispatcher:176  ] - defdisp: 3D.E5.56:IOLincContact set status to: QUERY_ANSWERED
2016-07-19 10:58:00.141 [INFO ] [smarthome.event.ItemStateEvent:43   ] - garageDoorContact updated to CLOSED
2016-07-19 10:58:00.147 [DEBUG] [.core.common.ThreadPoolManager:145  ] - Created thread pool 'items' with size 5
2016-07-19 10:58:00.148 [DEBUG] [o.o.b.i.i.device.DeviceFeature:321  ] - 3D.E5.56:GenericLastTime publishing: 2016-07-19T10:58:00
2016-07-19 10:58:00.157 [INFO ] [s.event.ItemStateChangedEvent :43   ] - garageDoorContact changed from NULL to CLOSED
2016-07-19 10:58:00.174 [DEBUG] [i.i.device.RequestQueueManager:137  ] - device queue for 3D.E5.56 is empty!

Physically pulling the contacts apart (expect from OPEN to CLOSED)

2016-07-19 12:03:18.083 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:591  ] - got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x00|
2016-07-19 12:03:18.086 [DEBUG] [b.i.i.device.MessageDispatcher:75   ] - all link message: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x00|
2016-07-19 12:03:18.086 [DEBUG] [b.i.i.device.MessageDispatcher:77   ] - all link message is no duplicate: true/true
2016-07-19 12:03:18.087 [DEBUG] [b.i.i.device.MessageDispatcher:79   ] - 3D.E5.56:IOLincContact->ClosedContactHandler cmd1:0x13 group 1/1:IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x00|
2016-07-19 12:03:18.087 [DEBUG] [o.o.b.i.i.device.DeviceFeature:321  ] - 3D.E5.56:IOLincContact publishing: CLOSED
2016-07-19 12:03:18.088 [DEBUG] [b.i.i.device.MessageDispatcher:75   ] - all link message: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x00|
2016-07-19 12:03:18.088 [DEBUG] [b.i.i.device.MessageDispatcher:77   ] - all link message is no duplicate: true/true
2016-07-19 12:03:18.089 [DEBUG] [b.i.i.device.MessageDispatcher:79   ] - 3D.E5.56:IOLincSwitch->NoOpMsgHandler cmd1:0x13 group 1/1:IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x00|
2016-07-19 12:03:18.089 [DEBUG] [o.o.b.i.i.device.DeviceFeature:321  ] - 3D.E5.56:GenericLastTime publishing: 2016-07-19T12:03:18
2016-07-19 12:03:18.090 [INFO ] [smarthome.event.ItemStateEvent:43   ] - garageDoorContact updated to CLOSED
2016-07-19 12:03:18.095 [INFO ] [s.event.ItemStateChangedEvent :43   ] - garageDoorContact changed from OPEN to CLOSED
2016-07-19 12:03:18.326 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:591  ] - got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x13|command2:0x01|
2016-07-19 12:03:18.326 [DEBUG] [b.i.i.device.MessageDispatcher:75   ] - all link message: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x13|command2:0x01|
2016-07-19 12:03:18.327 [DEBUG] [b.i.i.device.MessageDispatcher:75   ] - all link message: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x13|command2:0x01|
2016-07-19 12:03:18.328 [DEBUG] [o.o.b.i.i.device.DeviceFeature:321  ] - 3D.E5.56:GenericLastTime publishing: 2016-07-19T12:03:18
2016-07-19 12:03:18.616 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:591  ] - got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x4A=ALL_LINK_CLEANUP:2:2|command1:0x13|command2:0x01|
2016-07-19 12:03:18.617 [DEBUG] [b.i.i.device.MessageDispatcher:75   ] - all link message: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x4A=ALL_LINK_CLEANUP:2:2|command1:0x13|command2:0x01|
2016-07-19 12:03:18.618 [DEBUG] [b.i.i.device.MessageDispatcher:75   ] - all link message: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x4A=ALL_LINK_CLEANUP:2:2|command1:0x13|command2:0x01|
2016-07-19 12:03:18.619 [DEBUG] [o.o.b.i.i.device.DeviceFeature:321  ] - 3D.E5.56:GenericLastTime publishing: 2016-07-19T12:03:18
2016-07-19 12:03:18.908 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:591  ] - got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:13.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|
2016-07-19 12:03:18.909 [DEBUG] [b.i.i.device.MessageDispatcher:75   ] - all link message: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:13.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|
2016-07-19 12:03:18.910 [DEBUG] [b.i.i.device.MessageDispatcher:75   ] - all link message: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:13.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|
2016-07-19 12:03:18.910 [DEBUG] [o.o.b.i.i.device.DeviceFeature:321  ] - 3D.E5.56:GenericLastTime publishing: 2016-07-19T12:03:18

Physically putting the contacts together (expect from CLOSED to OPEN)

2016-07-19 12:03:53.811 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:591  ] - got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x11|command2:0x00|
2016-07-19 12:03:53.814 [DEBUG] [b.i.i.device.MessageDispatcher:75   ] - all link message: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x11|command2:0x00|
2016-07-19 12:03:53.815 [DEBUG] [b.i.i.device.MessageDispatcher:77   ] - all link message is no duplicate: true/true
2016-07-19 12:03:53.816 [DEBUG] [b.i.i.device.MessageDispatcher:79   ] - 3D.E5.56:IOLincContact->OpenedContactHandler cmd1:0x11 group 1/1:IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x11|command2:0x00|
2016-07-19 12:03:53.816 [DEBUG] [o.o.b.i.i.device.DeviceFeature:321  ] - 3D.E5.56:IOLincContact publishing: OPEN
2016-07-19 12:03:53.818 [DEBUG] [b.i.i.device.MessageDispatcher:75   ] - all link message: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x11|command2:0x00|
2016-07-19 12:03:53.818 [DEBUG] [b.i.i.device.MessageDispatcher:77   ] - all link message is no duplicate: true/true
2016-07-19 12:03:53.819 [DEBUG] [b.i.i.device.MessageDispatcher:79   ] - 3D.E5.56:IOLincSwitch->NoOpMsgHandler cmd1:0x11 group 1/1:IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x11|command2:0x00|
2016-07-19 12:03:53.820 [DEBUG] [o.o.b.i.i.device.DeviceFeature:321  ] - 3D.E5.56:GenericLastTime publishing: 2016-07-19T12:03:53
2016-07-19 12:03:53.820 [INFO ] [smarthome.event.ItemStateEvent:43   ] - garageDoorContact updated to OPEN
2016-07-19 12:03:53.823 [INFO ] [s.event.ItemStateChangedEvent :43   ] - garageDoorContact changed from CLOSED to OPEN
2016-07-19 12:03:53.997 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:591  ] - got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x11|command2:0x01|
2016-07-19 12:03:53.998 [DEBUG] [b.i.i.device.MessageDispatcher:75   ] - all link message: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x11|command2:0x01|
2016-07-19 12:03:53.999 [DEBUG] [b.i.i.device.MessageDispatcher:75   ] - all link message: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x11|command2:0x01|
2016-07-19 12:03:54.000 [DEBUG] [o.o.b.i.i.device.DeviceFeature:321  ] - 3D.E5.56:GenericLastTime publishing: 2016-07-19T12:03:53
2016-07-19 12:03:54.195 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:591  ] - got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:11.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|
2016-07-19 12:03:54.196 [DEBUG] [b.i.i.device.MessageDispatcher:75   ] - all link message: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:11.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|
2016-07-19 12:03:54.196 [DEBUG] [b.i.i.device.MessageDispatcher:75   ] - all link message: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:11.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|
2016-07-19 12:03:54.197 [DEBUG] [o.o.b.i.i.device.DeviceFeature:321  ] - 3D.E5.56:GenericLastTime publishing: 2016-07-19T12:03:54

No activity, wait for status polling, note- contacts are together

2016-07-19 11:12:45.361 [INFO ] [.o.b.i.InsteonPLMActiveBinding:684  ] - devices:   1 configured,   1 polling, msgs received:    13
2016-07-19 11:12:59.659 [DEBUG] [o.o.b.i.i.device.InsteonDevice:459  ] - qe taken off direct: IOLincContact(1:1:4) OUT:Cmd:0x62|toAddress:3D.E5.56|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x01|
2016-07-19 11:12:59.661 [DEBUG] [o.o.b.i.i.device.InsteonDevice:479  ] - next request queue processed in 500 msec, quiettime = 500
2016-07-19 11:12:59.662 [DEBUG] [o.o.b.i.internal.driver.Port  :415  ] - writing (500): OUT:Cmd:0x62|toAddress:3D.E5.56|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x01|
2016-07-19 11:12:59.986 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:591  ] - got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x00|command2:0x01|
2016-07-19 11:12:59.988 [DEBUG] [b.i.i.device.MessageDispatcher:149  ] - 3D.E5.56:IOLincContact DIRECT_ACK: q:QUERY_PENDING cmd: 80
2016-07-19 11:12:59.989 [DEBUG] [b.i.i.device.MessageDispatcher:154  ] - changing key to 0x19 for msg IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x00|command2:0x01|
2016-07-19 11:12:59.990 [INFO ] [.o.b.i.i.device.MessageHandler:834  ] - ContactRequestReplyHandler: set contact 3D.E5.56 to: CLOSED
2016-07-19 11:12:59.990 [DEBUG] [o.o.b.i.i.device.DeviceFeature:321  ] - 3D.E5.56:IOLincContact publishing: CLOSED
2016-07-19 11:12:59.994 [DEBUG] [b.i.i.device.MessageDispatcher:176  ] - defdisp: 3D.E5.56:IOLincContact set status to: QUERY_ANSWERED
2016-07-19 11:12:59.995 [DEBUG] [o.o.b.i.i.device.DeviceFeature:321  ] - 3D.E5.56:GenericLastTime publishing: 2016-07-19T11:12:59
2016-07-19 11:12:59.996 [INFO ] [smarthome.event.ItemStateEvent:43   ] - garageDoorContact updated to CLOSED
2016-07-19 11:13:00.018 [INFO ] [s.event.ItemStateChangedEvent :43   ] - garageDoorContact changed from OPEN to CLOSED
2016-07-19 11:13:00.159 [DEBUG] [i.i.device.RequestQueueManager:137  ] - device queue for 3D.E5.56 is empty!

Again, I believe the polling is interpreting the incorrect state. It should be OPEN.

I can dig in and try and troubleshoot, I am just trying to wrap my head around the expected messages right now. Hoping someone more familiar can confirm this is indeed a bug, or my expectations are incorrect.

thanks,
craig

craigh · July 19, 2016, 10:43pm

Ok, did some debugging with insteon terminal. I believe either there is a bug in ContactRequestReplyHandler, or that class is just not suitable for the IOLinc 2450. (i.e. Maybe it does work for wireless contacts, etc).

Within the handleMessage method, the message is parsed with:

OpenClosedType oc = (cmd2 == 0) ? OpenClosedType.OPEN : OpenClosedType.CLOSED;

This doesn’t match up with the getStatus method return messages coming from my IOLinc 2450. It seems inverted.

Any thoughts by those that are more familiar?

thanks,
craig

>>> modem.startWatch()
>>> 

<< pulled contacts apart >>

>>> modem got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x00|
modem got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x13|command2:0x00|
modem got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x13|command2:0x01|
modem got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x13|command2:0x01|
modem got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:13.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|
modem got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:13.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|

gdOpener.getStatus()

sent msg: OUT:Cmd:0x62|toAddress:3D.E5.56|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x01|
>>> modem got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x00|command2:0x00|
modem got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x00|command2:0x00|
contact state = CLOSED

** Note command2 is 0 for CLOSED.

<< put contacts together >>

modem got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x11|command2:0x00|
modem got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:00.00.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x11|command2:0x00|
modem got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x11|command2:0x01|
modem got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x45=ALL_LINK_CLEANUP:1:1|command1:0x11|command2:0x01|
modem got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:11.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|
modem got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:11.01.01|messageFlags:0xCF=ALL_LINK_BROADCAST:3:3|command1:0x06|command2:0x00|

sent msg: OUT:Cmd:0x62|toAddress:3D.E5.56|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x01|
>>> modem got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x00|command2:0x01|
modem got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x2F=ACK_OF_DIRECT:3:3|command1:0x00|command2:0x01|
contact state = OPEN

Bernd_Pfrommer · July 20, 2016, 12:41pm

Craig,

Here is what I’m seeing on my IOLinc 2450 when it is queried while the garage door is CLOSED:

OUT:Cmd:0x62|toAddress:28.C3.91|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x01|
IN:Cmd:0x50|fromAddress:28.C3.91|toAddress:1E.DB.41|messageFlags:0x27=ACK_OF_DIRECT:3:1|command1:0x00|command2:0x01|
28.C3.91:IOLincContact publishing: CLOSED

So for a closed contact, I’m getting cmd2= 0x01 during polling, which is interpreted as “closed”. If we change the binding, it will break my setup.

Question: what kind of switch are you using to detect if the garage door is open or closed? I don’t recall what I have installed, a “normally open” or “normally closed” switch. I think my switch closes the loop when the garage door is down (closed), and has it open (interrupted) when the door is up.

craigh · July 20, 2016, 2:31pm

Bernd,

Do you have your setup such that the contacts would be in close proximity when the garage door is closed, or when open? I have my contact at the middle top of the door, and then on the wall at the top. So the garage door is closed when the contacts are in close proximity. This shows as OPEN though when querying the status.

I recently purchased a recent garage door kit from insteon. It comes with the IOLInc 2450, and then a wired contact set which connects to the sensor and ground terminals.

I have been reading quite a bit about people setting up their device, and possibly the 2450 has changed over the years.

It is my understanding that now, the contact sensor connects to the sensor and ground wires on the 2450. The NO/NC and common connectors are only for the relay, not the sensor.

The installation directions are on the bottom of page 4 in this manual.

Bernd_Pfrommer · July 20, 2016, 4:48pm

It’s the same kit I am using as well, probably bought some time in 2016.

Have a look at this discussion:

http://forum.micasaverde.com/index.php?topic=16475.0

Somebody claims that it makes a difference about the state which the I/O linc module was (open vs closed) when you linked it. Sounds strange to me, but maybe worth a try.

Maybe also good to look at the lights on the iolinc to see if it thinks it’s open or closed. There is some mention of that in the above thread.

craigh · July 20, 2016, 11:03pm

The IOLinc light is on when the contacts are together which I believe is correct. But querying the status when the contacts are together returns:

gdOpener.getContactStatus()
sent msg: OUT:Cmd:0x62|toAddress:3D.E5.56|messageFlags:0x0F=DIRECT:3:3|command1:0x19|command2:0x01|
>>> modem got msg: IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x00|command2:0x01|
IN:Cmd:0x50|fromAddress:3D.E5.56|toAddress:30.DC.6C|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x00|command2:0x01|
contact state = OPEN

I had one of these IOLincs hooked up to another house I had which was running and ISY, and the contacts also showed OPEN when the contacts are together.

For now I have had to flip the following, and compile the binding myself. Obviously this doesn’t work for the masses. I’m stumped what I can do.

<message-handler cmd="0x11" group="1">OpenedContactHandler</message-handler>
<message-handler cmd="0x13" group="1">ClosedContactHandler</message-handler>

craigh · July 20, 2016, 11:28pm

Bernd,

Did you experiment with the configuration of device types? Is there an example within insteon-terminal which can configure a device via messages? Maybe I could poke around at that.

How did you come up with the device_features.xml? Was it largely reverse engineering by watching the insteon messages, or where you able to find reasonable specifications for the various devices?

craigh · July 21, 2016, 1:53am

Bernd,

Do you know if your contact sensors have 2 wires, or 3 wires? I have 2 on mine, but in reading prior issues it seems there was at one time contact sensors with 3 wires, which would allow you to adjust how the contact sensor shows up as open/closed if they are together/apart.

Bernd_Pfrommer · July 21, 2016, 9:07am

Can’t look at the hardware right now as I am away from home.
You can however suck in your own .xml files via openhab.cfg, and so define your own devices without recompile. See plm wiki. You can override devices this way.
There isn’t much documentation for the iolinc. That one was largely reverse engineered. I still think the binding works ok for the rest of us, so this is an issue with your setup. Try total reset of the device (is there a way to do that?) Remove it from modem link db via insteon terminal, then link it again, paying attention to the state of the contact while you link. See thread referenced in my earlier post.