Can Only Control One X10 Device via 2245-222 Insteon Hub 2

  • Platform information:
    • Hardware: Raspberry Pi 3B, 1GB RAM
    • OS: openhabian 5.10.43v64
    • Java Runtime Environment: Zulu11 build 11.0.14.1
    • openHAB version: 3.2.0

I am trying to control some X10 powerline devices (Robodog) from OpenHAB using the Insteon binding via an Insteon 2245-222 Hub 2. I believe I got this working using OpenHAB 2 as well as the Insteon app but my notes and memory are sketchy and I put OpenHAB on hold due to other priorities. Now that Insteon is defunct, I am trying again on OpenHAB 3 - so far, I am getting much further.

I followed the instructions at https://community.openhab.org/t/problem-with-x10-on-insteon-binding/109355/6. I defined one Robodog at address B.1 and product key X00.00.01 (generic X10 switch). I created a new item and linked the Switch channel to the new item. I did not configure a Parent Group because nothing in the list seemed suitable. Both the Thing and the Item show as online. From the OpenHAB console, I can see the Robodog using insteon display_devices and insteon display_channels.

If I toggle the Robodog switch, the Log Viewer indicates ON and OFF commands are sent to Robodog. However, Robodog does not bark. I created a second Robodog Thing/Item/Channel for address C.1. At first, it also did not work but has been working consistently, possibly after an OpenHAB restart.

I turned on DEBUG tracing for the Insteon binding. Activating the working C.1 Robodog shows:

2022-05-04 18:09:20.050 [DEBUG] [nternal.handler.InsteonDeviceHandler] - channel insteon:device:hub2:bf6281eed6:switch was triggered with the command ON
2022-05-04 18:09:20.052 [DEBUG] [nsteon.internal.device.InsteonDevice] - processing command ON features: 1
2022-05-04 18:09:20.054 [DEBUG] [nsteon.internal.device.InsteonDevice] - gave up waiting for query reply from device C.1
2022-05-04 18:09:20.056 [DEBUG] [nsteon.internal.device.InsteonDevice] - qe taken off direct: X10Switch(1:3:2) OUT:Cmd:0x63|rawX10:0x26|X10Flag:0x00|
2022-05-04 18:09:20.058 [DEBUG] [binding.insteon.internal.driver.Port] - writing (500): OUT:Cmd:0x63|rawX10:0x26|X10Flag:0x00|
2022-05-04 18:09:20.059 [DEBUG] [nsteon.internal.device.InsteonDevice] - next request queue processed in 2000 msec, quiettime = 2000
2022-05-04 18:09:20.059 [DEBUG] [teon.internal.driver.hub.HubIOStream] - getting http://10.1.2.202:25105/buffstatus.xml
2022-05-04 18:09:20.061 [DEBUG] [steon.internal.device.CommandHandler] - X10OnOffCommandHandler: sent msg to switch C.1 ON
2022-05-04 18:09:20.061 [DEBUG] [nsteon.internal.device.InsteonDevice] - gave up waiting for query reply from device C.1
2022-05-04 18:09:20.063 [DEBUG] [ding.insteon.internal.InsteonBinding] - found binding config for channel insteon:device:hub2:bf6281eed6:switch
2022-05-04 18:09:20.063 [DEBUG] [nsteon.internal.device.InsteonDevice] - qe taken off direct: X10Switch(1:3:2) OUT:Cmd:0x63|rawX10:0x22|X10Flag:0x80|
2022-05-04 18:09:20.064 [DEBUG] [teon.internal.driver.hub.HubIOStream] - getting http://10.1.2.202:25105/3?02632600=I=3
2022-05-04 18:09:20.065 [DEBUG] [nsteon.internal.device.InsteonDevice] - next request queue processed in 2000 msec, quiettime = 2000
2022-05-04 18:09:20.223 [DEBUG] [teon.internal.driver.hub.HubIOStream] - getting http://10.1.2.202:25105/buffstatus.xml
==> /var/log/openhab/events.log <==
2022-05-04 18:09:20.037 [INFO ] [openhab.event.ItemCommandEvent ] - Item ‘X10Robodog2_Switch’ received command ON
2022-05-04 18:09:20.038 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item ‘X10Robodog2_Switch’ predicted to become ON
2022-05-04 18:09:20.048 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘X10Robodog2_Switch’ changed from OFF to ON
==> /var/log/openhab/openhab.log <==
2022-05-04 18:09:20.731 [DEBUG] [binding.insteon.internal.driver.Port] - writing (500): OUT:Cmd:0x63|rawX10:0x22|X10Flag:0x80|
2022-05-04 18:09:20.734 [DEBUG] [teon.internal.driver.hub.HubIOStream] - getting http://10.1.2.202:25105/buffstatus.xml
2022-05-04 18:09:20.740 [DEBUG] [teon.internal.driver.hub.HubIOStream] - getting http://10.1.2.202:25105/3?02632280=I=3
2022-05-04 18:09:21.230 [DEBUG] [teon.internal.driver.hub.HubIOStream] - getting http://10.1.2.202:25105/buffstatus.xml
2022-05-04 18:09:22.062 [DEBUG] [.internal.device.RequestQueueManager] - device queue for C.1 is empty!

Activating the failing N.1 Robodog configuration shows:

2022-05-04 18:13:23.721 [DEBUG] [teon.internal.driver.hub.HubIOStream] - getting http://10.1.2.202:25105/buffstatus.xml
2022-05-04 18:13:23.899 [DEBUG] [nternal.handler.InsteonDeviceHandler] - channel insteon:device:hub2:4a4bb000b0:switch was triggered with the command ON
2022-05-04 18:13:23.900 [DEBUG] [nsteon.internal.device.InsteonDevice] - processing command ON features: 1
2022-05-04 18:13:23.902 [DEBUG] [ding.insteon.internal.InsteonBinding] - found binding config for channel insteon:device:hub2:4a4bb000b0:switch
2022-05-04 18:13:24.727 [DEBUG] [teon.internal.driver.hub.HubIOStream] - getting http://10.1.2.202:25105/buffstatus.xml
==> /var/log/openhab/events.log <==
2022-05-04 18:13:23.886 [INFO ] [openhab.event.ItemCommandEvent ] - Item ‘X10Robodog1_Switch’ received command ON
2022-05-04 18:13:23.888 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item ‘X10Robodog1_Switch’ predicted to become ON
2022-05-04 18:13:23.898 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item ‘X10Robodog1_Switch’ changed from OFF to ON
==> /var/log/openhab/openhab.log <==
2022-05-04 18:13:25.733 [DEBUG] [teon.internal.driver.hub.HubIOStream] - getting http://10.1.2.202:25105/buffstatus.xml

It is possible that I did all my earlier testing with the Robodog on C.1, but as far as I know, the Insteon hub does not require that X10 devices be linked to it. It seems Robodog B.1 is going down a different path: “found binding config for channell nsteon:device:hub2:4a4bb000b0:switch” rather than “gave up waiting for query reply from device C.1” (I do not believe the Robodog responds to status queries).

It is posible that I made a mistake in the first Robodog configuration. I compared the Thing/Item/Channel YAML files and cannot find differences other than the Thing identifies and X10 addresses. I have verified using tcpdump that OPenHAB is not sending anything to the B.1 X10 device. I have also created a third Robodog configuration for address D.1 - it also does not work and shows the same console entries as B.1.

My next step is swapping around the configurations to see if the problem moves, but I would prefer to hold off in case I end up losing the ability to interact with the working C.1 X10 device. Any suggestions on how to proceed? I think I still have an OpenHAB v2 system that I could try. I also have an Insteon 2413U USB PLM.

I did some more testing today with Insteon logging=TRACE. There was still no evidence that the Insteon binding sent any requests to the Insteon Hub 2.

I removed all of the X10 Things that were not working. I then manually created a new Robodog3. Rather than manually creating an item and channel (what I did for the working Robodog2), I did it through Settings/Model: Create Equipment from Thing, selecting Robodog3, enabling Channel=Switch, and adding it to the model. Now both Robodogs are barking.

I will take another backup tomorrow and see if there are any obvious differences between the YAML configuration of the failing Robodogs and Robodog3.