Insteon X10 setup broke after update to 4.3.1

1

Hi there.

I have an Openhab setup where my x10 on/off swiches are controlled via an Insteon Legacy Hub (2242-442). A setup I have had working fine since Openhab version 2.x using textual configs.

Recently I upgraded from version 4.1.2 to 4.3.1 and realized I needed to update my configs, since the initialization process after the upgrade was “complaining” about the Things definitions for my x10 devices. If I remember correctly, it required the format to be something like 0-9A-F{2}.0-9A-F{2}.0-9A-F{2} even for X10 devices.

Previous working setup was:

  • Things file:
    Bridge insteon:network:home [port=“/hub/:9761”] {
    Thing device L2 [address=“L.2”, productKey=“X00.00.01”]
    }

  • Items file:
    Switch DiningRoomSwitch “Dining Switch” {homekit=“Switchable”, channel=“insteon:device:home:L2:switch”}

Anyway, I have updated the Things and Items configurations for the new format like this:

  • Things file:
    Bridge insteon:hub1:home [hostname=, port=9761] {
    Thing x10 L2 [houseCode=“L”, unitCode=2, deviceType=“X10_Switch”]
    }

  • Items file:
    Switch DiningRoomSwitch “Dining Switch” {homekit=“Switchable”, channel=“insteon:x10:home:L2:switch”}

Openhab seems to accept the new configuration as Things show up on-line. However, the x10 switch take almost 30 seconds to react. Other times is does not seem to react at all.

I collected the following TRACE output while turning the switch OFF once only. (sorry, added below as it seems I cannot upload an attachment).

Seems the x10 switch only reacts half way though the TRACE (almost after 30 seconds).

So the question is: What could be wrong here?

Appreciate all the help I can get! Thanks

------------- TRACE -----------------

2025-01-03 18:54:16.526 [DEBUG] [on.internal.handler.X10DeviceHandler] - channel insteon:x10:home:L2:switch received command OFF
2025-01-03 18:54:16.537 [TRACE] [nsteon.internal.device.DeviceFeature] - L2:switch handling command OnOffType:OFF using handler X10OnOffCommandHandler
2025-01-03 18:54:16.542 [TRACE] [ng.insteon.internal.device.X10Device] - enqueuing request with delay 0 msec
2025-01-03 18:54:16.546 [TRACE] [steon.internal.device.RequestManager] - scheduling request for device L2 in 0 msec
2025-01-03 18:54:16.550 [TRACE] [ng.insteon.internal.device.X10Device] - enqueuing request with delay 0 msec
2025-01-03 18:54:16.551 [TRACE] [ng.insteon.internal.device.X10Device] - request taken off direct for switch: OUT:Cmd:0x63|rawX10:0xBE|X10Flag:0x00|
2025-01-03 18:54:16.556 [TRACE] [nsteon.internal.device.DeviceFeature] - L2:switch setting query status to: QUERY_QUEUED
2025-01-03 18:54:16.561 [TRACE] [ding.insteon.internal.transport.Port] - enqueued msg (1): OUT:Cmd:0x63|rawX10:0xBE|X10Flag:0x00|
2025-01-03 18:54:16.561 [DEBUG] [ding.insteon.internal.transport.Port] - writing: OUT:Cmd:0x63|rawX10:0xBE|X10Flag:0x00|
2025-01-03 18:54:16.564 [TRACE] [ng.insteon.internal.device.X10Device] - next request queue processed in 300 msec, quiettime 300 msec
2025-01-03 18:54:16.565 [TRACE] [ding.insteon.internal.transport.Port] - waiting for reply ack
2025-01-03 18:54:16.570 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 300 msec
2025-01-03 18:54:16.574 [TRACE] [steon.internal.device.RequestManager] - rescheduling request for device L2 from 277 to 0 msec
2025-01-03 18:54:16.578 [DEBUG] [ternal.device.feature.CommandHandler] - X10OnOffCommandHandler: sent OFF request to L2
2025-01-03 18:54:16.581 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 29969 msec
2025-01-03 18:54:16.585 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:16.589 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:54:16.617 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 5 data: 0263BE0006
2025-01-03 18:54:16.621 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 2
2025-01-03 18:54:16.626 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 5 extended: false
2025-01-03 18:54:16.629 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-01-03 18:54:16.633 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 0 data:
2025-01-03 18:54:16.638 [DEBUG] [ding.insteon.internal.transport.Port] - got msg: IN:Cmd:0x63|rawX10:0xBE|X10Flag:0x00|ACK/NACK:0x06|
2025-01-03 18:54:16.645 [TRACE] [ding.insteon.internal.transport.Port] - signaling receipt of ack: true
2025-01-03 18:54:16.649 [TRACE] [ding.insteon.internal.transport.Port] - got reply ack: true
2025-01-03 18:54:16.649 [TRACE] [ding.insteon.internal.transport.Port] - reader checking for input data
2025-01-03 18:54:17.152 [TRACE] [ding.insteon.internal.transport.Port] - writer checking message queue
2025-01-03 18:54:17.586 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 28965 msec
2025-01-03 18:54:17.590 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:17.593 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:54:18.589 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 27962 msec
2025-01-03 18:54:18.592 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:18.595 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:54:19.591 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 26959 msec
2025-01-03 18:54:19.595 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:19.598 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 994 msec
2025-01-03 18:54:20.595 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 25956 msec
2025-01-03 18:54:20.598 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:20.601 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 994 msec
2025-01-03 18:54:21.598 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 24953 msec
2025-01-03 18:54:21.609 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:21.612 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 985 msec
2025-01-03 18:54:22.601 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 23950 msec
2025-01-03 18:54:22.604 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:22.608 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 992 msec
2025-01-03 18:54:23.604 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 22947 msec
2025-01-03 18:54:23.608 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:23.611 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 992 msec
2025-01-03 18:54:24.607 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 21944 msec
2025-01-03 18:54:24.610 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:24.614 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:54:25.611 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 20940 msec
2025-01-03 18:54:25.614 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:25.618 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:54:26.614 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 19936 msec
2025-01-03 18:54:26.618 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:26.622 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 992 msec
2025-01-03 18:54:27.617 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 18933 msec
2025-01-03 18:54:27.621 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:27.625 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:54:28.622 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 17929 msec
2025-01-03 18:54:28.625 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:28.629 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:54:29.625 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 16925 msec
2025-01-03 18:54:29.629 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:29.632 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 994 msec
2025-01-03 18:54:30.629 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 15921 msec
2025-01-03 18:54:30.632 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:30.635 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 994 msec
2025-01-03 18:54:31.632 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 14918 msec
2025-01-03 18:54:31.636 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:31.639 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 994 msec
2025-01-03 18:54:32.637 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 13914 msec
2025-01-03 18:54:32.641 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:32.645 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 992 msec
2025-01-03 18:54:33.641 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 12910 msec
2025-01-03 18:54:33.646 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:33.649 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 991 msec
2025-01-03 18:54:34.645 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 11906 msec
2025-01-03 18:54:34.650 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:34.654 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 990 msec
2025-01-03 18:54:35.649 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 10902 msec
2025-01-03 18:54:35.653 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:35.657 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 991 msec
2025-01-03 18:54:36.653 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 9897 msec
2025-01-03 18:54:36.660 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:36.667 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 987 msec
2025-01-03 18:54:37.659 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 8892 msec
2025-01-03 18:54:37.661 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:37.665 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 994 msec
2025-01-03 18:54:38.662 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 7888 msec
2025-01-03 18:54:38.665 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:38.669 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:54:39.665 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 6885 msec
2025-01-03 18:54:39.669 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:39.672 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 994 msec
2025-01-03 18:54:40.670 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 5881 msec
2025-01-03 18:54:40.672 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:40.675 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 994 msec
2025-01-03 18:54:41.672 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 4878 msec
2025-01-03 18:54:41.678 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:41.683 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 990 msec
2025-01-03 18:54:42.676 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 3874 msec
2025-01-03 18:54:42.679 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:42.683 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 994 msec
2025-01-03 18:54:43.680 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 2871 msec
2025-01-03 18:54:43.682 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:43.685 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 994 msec
2025-01-03 18:54:44.682 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 1868 msec
2025-01-03 18:54:44.685 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:44.688 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 995 msec
2025-01-03 18:54:45.686 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 865 msec
2025-01-03 18:54:45.689 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:45.692 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 994 msec
2025-01-03 18:54:46.689 [DEBUG] [ng.insteon.internal.device.X10Device] - gave up waiting for switch query to be sent to L2
2025-01-03 18:54:46.696 [TRACE] [nsteon.internal.device.DeviceFeature] - L2:switch setting query status to: NEVER_QUERIED
2025-01-03 18:54:46.699 [TRACE] [ng.insteon.internal.device.X10Device] - request taken off direct for switch: OUT:Cmd:0x63|rawX10:0xB3|X10Flag:0x80|
2025-01-03 18:54:46.702 [TRACE] [nsteon.internal.device.DeviceFeature] - L2:switch setting query status to: QUERY_QUEUED
2025-01-03 18:54:46.706 [DEBUG] [ding.insteon.internal.transport.Port] - writing: OUT:Cmd:0x63|rawX10:0xB3|X10Flag:0x80|
2025-01-03 18:54:46.706 [TRACE] [ding.insteon.internal.transport.Port] - enqueued msg (0): OUT:Cmd:0x63|rawX10:0xB3|X10Flag:0x80|
2025-01-03 18:54:46.709 [TRACE] [ding.insteon.internal.transport.Port] - waiting for reply ack
2025-01-03 18:54:46.711 [TRACE] [ng.insteon.internal.device.X10Device] - next request queue processed in 300 msec, quiettime 300 msec
2025-01-03 18:54:46.716 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 300 msec
2025-01-03 18:54:46.720 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 269 msec
2025-01-03 18:54:46.754 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 5 data: 0263B38006
2025-01-03 18:54:46.758 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 2
2025-01-03 18:54:46.761 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 5 extended: false
2025-01-03 18:54:46.765 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-01-03 18:54:46.767 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 0 data:
2025-01-03 18:54:46.771 [DEBUG] [ding.insteon.internal.transport.Port] - got msg: IN:Cmd:0x63|rawX10:0xB3|X10Flag:0x80|ACK/NACK:0x06|
2025-01-03 18:54:46.775 [TRACE] [ding.insteon.internal.transport.Port] - signaling receipt of ack: true
2025-01-03 18:54:46.780 [TRACE] [ding.insteon.internal.transport.Port] - got reply ack: true
2025-01-03 18:54:46.780 [TRACE] [ding.insteon.internal.transport.Port] - reader checking for input data
2025-01-03 18:54:46.992 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 29697 msec
2025-01-03 18:54:46.995 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:46.999 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:54:47.282 [TRACE] [ding.insteon.internal.transport.Port] - writer checking message queue
2025-01-03 18:54:47.995 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 28693 msec
2025-01-03 18:54:47.999 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:48.002 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 994 msec
2025-01-03 18:54:48.999 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 27689 msec
2025-01-03 18:54:49.002 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:49.006 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:54:50.003 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 26686 msec
2025-01-03 18:54:50.006 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:50.010 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 992 msec
2025-01-03 18:54:51.006 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 25683 msec
2025-01-03 18:54:51.010 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:51.013 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 992 msec
2025-01-03 18:54:52.009 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 24680 msec
2025-01-03 18:54:52.013 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:52.018 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 991 msec
2025-01-03 18:54:53.012 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 23676 msec
2025-01-03 18:54:53.016 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:53.019 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 994 msec
2025-01-03 18:54:54.017 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 22672 msec
2025-01-03 18:54:54.020 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:54.024 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:54:55.020 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 21668 msec
2025-01-03 18:54:55.024 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:55.027 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 994 msec
2025-01-03 18:54:56.025 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 20664 msec
2025-01-03 18:54:56.028 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:56.032 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:54:57.029 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 19660 msec
2025-01-03 18:54:57.032 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:57.038 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 991 msec
2025-01-03 18:54:58.033 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 18656 msec
2025-01-03 18:54:58.036 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:58.040 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:54:59.036 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 17652 msec
2025-01-03 18:54:59.040 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:54:59.044 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:55:00.040 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 16648 msec
2025-01-03 18:55:00.044 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:55:00.047 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:55:01.044 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 15645 msec
2025-01-03 18:55:01.048 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:55:01.052 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 992 msec
2025-01-03 18:55:02.050 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 14639 msec
2025-01-03 18:55:02.053 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:55:02.057 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:55:03.054 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 13635 msec
2025-01-03 18:55:03.057 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:55:03.061 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 992 msec
2025-01-03 18:55:04.057 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 12632 msec
2025-01-03 18:55:04.061 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:55:04.064 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 992 msec
2025-01-03 18:55:05.061 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 11628 msec
2025-01-03 18:55:05.064 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:55:05.068 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 992 msec
2025-01-03 18:55:06.064 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 10625 msec
2025-01-03 18:55:06.068 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:55:06.071 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 992 msec
2025-01-03 18:55:07.067 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 9622 msec
2025-01-03 18:55:07.070 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:55:07.074 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 992 msec
2025-01-03 18:55:08.069 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 8619 msec
2025-01-03 18:55:08.073 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:55:08.076 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:55:09.073 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 7615 msec
2025-01-03 18:55:09.077 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:55:09.081 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 992 msec
2025-01-03 18:55:10.078 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 6611 msec
2025-01-03 18:55:10.082 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:55:10.086 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 991 msec
2025-01-03 18:55:11.082 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 5607 msec
2025-01-03 18:55:11.087 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:55:11.093 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 989 msec
2025-01-03 18:55:12.087 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 4602 msec
2025-01-03 18:55:12.091 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:55:12.095 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 992 msec
2025-01-03 18:55:13.091 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 3597 msec
2025-01-03 18:55:13.096 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:55:13.102 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 989 msec
2025-01-03 18:55:14.095 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 2593 msec
2025-01-03 18:55:14.099 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:55:14.102 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 993 msec
2025-01-03 18:55:15.099 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 1590 msec
2025-01-03 18:55:15.102 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:55:15.105 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 994 msec
2025-01-03 18:55:16.102 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query to be sent to L2 for another 586 msec
2025-01-03 18:55:16.106 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 1000 msec
2025-01-03 18:55:16.109 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 994 msec
2025-01-03 18:55:17.108 [DEBUG] [ng.insteon.internal.device.X10Device] - gave up waiting for switch query to be sent to L2
2025-01-03 18:55:17.111 [TRACE] [nsteon.internal.device.DeviceFeature] - L2:switch setting query status to: NEVER_QUERIED
2025-01-03 18:55:17.116 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 is empty!
2025-01-03 18:55:17.118 [TRACE] [steon.internal.device.RequestManager] - waiting for request queues to fill

2

Thanks very much for providing the trace logs. There is a bug in OH 4.3.1 that affects the X10 integration including the legacy implementation. I have submitted the below PR to fix this issue.

Could you test the beta release build in the link below and confirm that you are able to control your X10 devices with the legacy and new things? Thanks.

3

I had some old X10 stuff laying around including a plug in switch module.

  • I downloaded the latest beta binding and installed
  • I plugged in said switch on/off module
  • I created a thing for it at address P5.
  • I confirmed that I was able to command it on/off multiple times in a row with no delays.
  • I also confirmed that I was able to use the CM11A binding along with my an old X10 CM11A “PLM” to do the same.
  • I did not re-create a legacy bridge to test the legacy functionality, but I can if needed.
1 Like
4

Thanks @tommycw10 for testing the change I made. Could you confirm that state changes made locally on your X10 device are reflected in OH through the Insteon binding? I am not familiar with such device but the modem is suppose to pick up any X10 traffic when detected on the powerline.

It would be much appreciated if you could. You should be able to easily do so but disabling the new bridge and adding a legacy network bridge along with a legacy x10 device. Once the test is complete, you can get rid of the legacy device discovered in your inbox by running the following console command:

inbox remove insteon:legacy-device
5

Hi @jeshab. Seems I am having trouble running the beta release. I copied the .kar file to addons folder after uninstalling the official version. But my systems keeps hanging, even after I removed the .kar file from said folder. I am running openhab x32 bit version on an RPI 2. Is it compiled for 32 bits?

6

I’ve been testing other stuff as well, so I already had it set up, but I’ve been using the .jar not the .kar and doing the

feature:install openhab-transport-serial

per the instructions. Not sure if you need to do that with the .kar

I don’t think these devices transmit anything on the powerline. That is their big downfall, its “send a pray it was received”, there is no ACK. I have some other stuff that will transmit on the powerline and I’ll see if I can give that a try.

Yes, I’ll probasbly try both of these things tomorrow.

1 Like
7

The Insteon developer manual seems to imply that (unsolicited) X10 messages can be received.

image
image924×859 100 KB

It could be commands sent by another X10 transmitter on the powerline. Maybe the test should be that you send a command via the CM11A binding while having the Insteon binding connected to your IM. You should see an item state change event in your logs for the relevant Insteon X10 item.

8

What do you mean by hanging? Can you access OH console? If so, can you run the following command? You might need to uninstall the binding via the console.

bundle:list | grep Insteon

Try to use the jar package instead as @tommycw10 suggested.

9

Thanks @jeshab and @tommycw10.
Seems .kar file and the fact that official binding did not uninstall cleanly were causing my issues. After clearing openhab cache and using the .jar file, it seems to be running much nicely.
I can confirm it is now working on sending X10 commands, as well as receiving monitored X10 commands as well - I have an x10 based sensor which triggers a notification rule. Both traces are below.

I will also try and test my previously working legacy configuration version.

------------- TRACE for sending X10 command to switch (L2) -------------

2025-01-04 18:52:13.732 [DEBUG] [on.internal.handler.X10DeviceHandler] - channel insteon:x10:home:L2:switch received command ON
2025-01-04 18:52:13.741 [TRACE] [nsteon.internal.device.DeviceFeature] - L2:switch handling command OnOffType:ON using handler X10OnOffCommandHandler
2025-01-04 18:52:13.755 [TRACE] [ng.insteon.internal.device.X10Device] - enqueuing request with delay 0 msec
2025-01-04 18:52:13.765 [TRACE] [steon.internal.device.RequestManager] - scheduling request for device L2 in 0 msec
2025-01-04 18:52:13.780 [TRACE] [ng.insteon.internal.device.X10Device] - request taken off direct for switch: OUT:Cmd:0x63|rawX10:0xBE|X10Flag:0x00|
2025-01-04 18:52:13.789 [TRACE] [nsteon.internal.device.DeviceFeature] - L2:switch setting query status to: QUERY_QUEUED
2025-01-04 18:52:13.798 [TRACE] [ding.insteon.internal.transport.Port] - enqueued msg (1): OUT:Cmd:0x63|rawX10:0xBE|X10Flag:0x00|
2025-01-04 18:52:13.798 [DEBUG] [ding.insteon.internal.transport.Port] - writing: OUT:Cmd:0x63|rawX10:0xBE|X10Flag:0x00|
2025-01-04 18:52:13.794 [TRACE] [ng.insteon.internal.device.X10Device] - enqueuing request with delay 0 msec
2025-01-04 18:52:13.814 [TRACE] [ng.insteon.internal.device.X10Device] - next request queue processed in 300 msec, quiettime 300 msec
2025-01-04 18:52:13.821 [TRACE] [nsteon.internal.device.DeviceFeature] - L2:switch setting query status to: QUERY_SENT
2025-01-04 18:52:13.826 [TRACE] [ding.insteon.internal.transport.Port] - waiting for reply ack
2025-01-04 18:52:13.822 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 300 msec
2025-01-04 18:52:13.838 [TRACE] [steon.internal.device.RequestManager] - rescheduling request for device L2 from 238 to 0 msec
2025-01-04 18:52:13.845 [DEBUG] [ternal.device.feature.CommandHandler] - X10OnOffCommandHandler: sent ON request to L2
2025-01-04 18:52:13.854 [TRACE] [ng.insteon.internal.device.X10Device] - still waiting for switch query reply from L2 for another 5956 msec
2025-01-04 18:52:13.860 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 5 data: 0263BE0006
2025-01-04 18:52:13.869 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 2
2025-01-04 18:52:13.879 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 5 extended: false
2025-01-04 18:52:13.892 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-01-04 18:52:13.888 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 500 msec
2025-01-04 18:52:13.899 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 455 msec
2025-01-04 18:52:13.905 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 0 data:
2025-01-04 18:52:13.910 [DEBUG] [ding.insteon.internal.transport.Port] - got msg: IN:Cmd:0x63|rawX10:0xBE|X10Flag:0x00|ACK/NACK:0x06|
2025-01-04 18:52:13.915 [TRACE] [nsteon.internal.device.DeviceFeature] - L2:switch setting query status to: QUERY_ANSWERED
2025-01-04 18:52:13.919 [TRACE] [ding.insteon.internal.transport.Port] - signaling receipt of ack: true
2025-01-04 18:52:13.923 [TRACE] [ding.insteon.internal.transport.Port] - reader checking for input data
2025-01-04 18:52:13.924 [TRACE] [ding.insteon.internal.transport.Port] - got reply ack: true
2025-01-04 18:52:14.359 [TRACE] [ng.insteon.internal.device.X10Device] - request taken off direct for switch: OUT:Cmd:0x63|rawX10:0xB2|X10Flag:0x80|
2025-01-04 18:52:14.363 [TRACE] [nsteon.internal.device.DeviceFeature] - L2:switch setting query status to: QUERY_QUEUED
2025-01-04 18:52:14.367 [TRACE] [ding.insteon.internal.transport.Port] - enqueued msg (1): OUT:Cmd:0x63|rawX10:0xB2|X10Flag:0x80|
2025-01-04 18:52:14.371 [TRACE] [ng.insteon.internal.device.X10Device] - next request queue processed in 300 msec, quiettime 300 msec
2025-01-04 18:52:14.375 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 rescheduled in 300 msec
2025-01-04 18:52:14.379 [TRACE] [steon.internal.device.RequestManager] - request queue head: L2 must wait for 279 msec
2025-01-04 18:52:14.428 [TRACE] [ding.insteon.internal.transport.Port] - writer checking message queue
2025-01-04 18:52:14.433 [DEBUG] [ding.insteon.internal.transport.Port] - writing: OUT:Cmd:0x63|rawX10:0xB2|X10Flag:0x80|
2025-01-04 18:52:14.438 [TRACE] [nsteon.internal.device.DeviceFeature] - L2:switch setting query status to: QUERY_SENT
2025-01-04 18:52:14.442 [TRACE] [ding.insteon.internal.transport.Port] - waiting for reply ack
2025-01-04 18:52:14.484 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 5 data: 0263B28006
2025-01-04 18:52:14.488 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 2
2025-01-04 18:52:14.492 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 5 extended: false
2025-01-04 18:52:14.497 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-01-04 18:52:14.500 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 0 data:
2025-01-04 18:52:14.504 [DEBUG] [ding.insteon.internal.transport.Port] - got msg: IN:Cmd:0x63|rawX10:0xB2|X10Flag:0x80|ACK/NACK:0x06|
2025-01-04 18:52:14.509 [TRACE] [nsteon.internal.device.DeviceFeature] - L2:switch setting query status to: QUERY_ANSWERED
2025-01-04 18:52:14.512 [TRACE] [ding.insteon.internal.transport.Port] - signaling receipt of ack: true
2025-01-04 18:52:14.516 [TRACE] [ding.insteon.internal.transport.Port] - got reply ack: true
2025-01-04 18:52:14.516 [TRACE] [ding.insteon.internal.transport.Port] - reader checking for input data
2025-01-04 18:52:14.662 [TRACE] [steon.internal.device.RequestManager] - device queue for L2 is empty!
2025-01-04 18:52:14.666 [TRACE] [steon.internal.device.RequestManager] - waiting for request queues to fill
2025-01-04 18:52:15.019 [TRACE] [ding.insteon.internal.transport.Port] - writer checking message queue

------------- TRACE for receiving X10 from sensor (L15 OPEN & CLOSE) -------------

2025-01-04 18:57:12.877 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 4 data: 0252B400
2025-01-04 18:57:12.884 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 2
2025-01-04 18:57:12.890 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 4 extended: false
2025-01-04 18:57:12.895 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-01-04 18:57:12.899 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 0 data:
2025-01-04 18:57:12.904 [DEBUG] [ding.insteon.internal.transport.Port] - got msg: IN:Cmd:0x52|rawX10:0xB4|X10Flag:0x00|
2025-01-04 18:57:12.908 [TRACE] [nsteon.internal.device.DeviceFeature] - L15:contact handling message using dispatcher X10Dispatcher
2025-01-04 18:57:12.912 [TRACE] [ding.insteon.internal.transport.Port] - reader checking for input data
2025-01-04 18:57:13.374 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 4 data: 0252B280
2025-01-04 18:57:13.378 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 2
2025-01-04 18:57:13.382 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 4 extended: false
2025-01-04 18:57:13.386 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-01-04 18:57:13.391 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 0 data:
2025-01-04 18:57:13.396 [DEBUG] [ding.insteon.internal.transport.Port] - got msg: IN:Cmd:0x52|rawX10:0xB2|X10Flag:0x80|
2025-01-04 18:57:13.401 [TRACE] [nsteon.internal.device.DeviceFeature] - L15:contact handling message using dispatcher X10Dispatcher
2025-01-04 18:57:13.406 [DEBUG] [nal.device.feature.MessageDispatcher] - L15:contact->X10OpenHandler X10
2025-01-04 18:57:13.410 [DEBUG] [ternal.device.feature.MessageHandler] - X10OpenHandler: device L15 is OPEN
2025-01-04 18:57:13.414 [TRACE] [nsteon.internal.device.DeviceFeature] - L15:contact setting state to: OPEN
2025-01-04 18:57:13.418 [DEBUG] [on.internal.handler.X10DeviceHandler] - publishing state OPEN on insteon:x10:home:L15:contact
2025-01-04 18:57:13.423 [TRACE] [ding.insteon.internal.transport.Port] - reader checking for input data
2025-01-04 18:57:14.073 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 4 data: 0252B600
2025-01-04 18:57:14.077 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 2
2025-01-04 18:57:14.081 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 4 extended: false
2025-01-04 18:57:14.085 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-01-04 18:57:14.088 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 0 data:
2025-01-04 18:57:14.092 [DEBUG] [ding.insteon.internal.transport.Port] - got msg: IN:Cmd:0x52|rawX10:0xB6|X10Flag:0x00|
2025-01-04 18:57:14.096 [DEBUG] [insteon.internal.device.InsteonModem] - unknown device with address L1, dropping message
2025-01-04 18:57:14.100 [TRACE] [ding.insteon.internal.transport.Port] - reader checking for input data
2025-01-04 18:57:14.576 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 4 data: 0252B380
2025-01-04 18:57:14.579 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 2
2025-01-04 18:57:14.583 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 4 extended: false
2025-01-04 18:57:14.588 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-01-04 18:57:14.592 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 0 data:
2025-01-04 18:57:14.596 [DEBUG] [ding.insteon.internal.transport.Port] - got msg: IN:Cmd:0x52|rawX10:0xB3|X10Flag:0x80|
2025-01-04 18:57:14.600 [DEBUG] [insteon.internal.device.InsteonModem] - unknown device with address L1, dropping message
2025-01-04 18:57:14.603 [TRACE] [ding.insteon.internal.transport.Port] - reader checking for input data
2025-01-04 18:57:15.922 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 4 data: 0252B400
2025-01-04 18:57:15.926 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 2
2025-01-04 18:57:15.930 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 4 extended: false
2025-01-04 18:57:15.934 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-01-04 18:57:15.938 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 0 data:
2025-01-04 18:57:15.942 [DEBUG] [ding.insteon.internal.transport.Port] - got msg: IN:Cmd:0x52|rawX10:0xB4|X10Flag:0x00|
2025-01-04 18:57:15.946 [TRACE] [nsteon.internal.device.DeviceFeature] - L15:contact handling message using dispatcher X10Dispatcher
2025-01-04 18:57:15.949 [TRACE] [ding.insteon.internal.transport.Port] - reader checking for input data
2025-01-04 18:57:16.205 [TRACE] [nternal.transport.message.MsgFactory] - read buffer: len 4 data: 0252B380
2025-01-04 18:57:16.209 [TRACE] [nternal.transport.message.MsgFactory] - header length expected: 2
2025-01-04 18:57:16.213 [TRACE] [nternal.transport.message.MsgFactory] - msgLen expected: 4 extended: false
2025-01-04 18:57:16.217 [TRACE] [nternal.transport.message.MsgFactory] - done processing current buffer data
2025-01-04 18:57:16.221 [TRACE] [nternal.transport.message.MsgFactory] - keeping buffer len 0 data:
2025-01-04 18:57:16.225 [DEBUG] [ding.insteon.internal.transport.Port] - got msg: IN:Cmd:0x52|rawX10:0xB3|X10Flag:0x80|
2025-01-04 18:57:16.229 [TRACE] [nsteon.internal.device.DeviceFeature] - L15:contact handling message using dispatcher X10Dispatcher
2025-01-04 18:57:16.233 [DEBUG] [nal.device.feature.MessageDispatcher] - L15:contact->X10ClosedHandler X10
2025-01-04 18:57:16.237 [DEBUG] [ternal.device.feature.MessageHandler] - X10ClosedHandler: device L15 is CLOSED
2025-01-04 18:57:16.241 [TRACE] [nsteon.internal.device.DeviceFeature] - L15:contact setting state to: CLOSED
2025-01-04 18:57:16.245 [DEBUG] [on.internal.handler.X10DeviceHandler] - publishing state CLOSED on insteon:x10:home:L15:contact
2025-01-04 18:57:16.250 [TRACE] [ding.insteon.internal.transport.Port] - reader checking for input data

1 Like
10

Thanks for confirming. As a side note, you should use code fencing for including logs in your post.

11

Thanks for the tip.
I have tested the legacy version as well and found it to be working for my X10 and Insteon devices, except if the X10 address has 2 numbers. Example:

Thing legacy-device L2 [address=“L.2”, productKey=“X00.00.01”] - OK
Thing legacy-device AABBCC [address=“AA.BB.CC”, productKey=“F00.00.1B”] - OK

Thing legacy-device L15 [address=“L.15”, productKey=“X00.00.03”] - NOK

Device fails initialization with the following message:

**CONFIGURATION_ERROR**

Unable to start Insteon device, the Insteon or X10 address 'L.15' is invalid. It must be in the format 'AB.CD.EF' or 'H.U' (X10).

I haven’t been able to test reception of X10 commands from the sensor because it’s address has 2 numbers (L15).

12

Wow. I didn’t think x10 was still being used.
I sold all my x10 years ago.
It was slow and unreliable.
ZigBee is what I use now.

13

Thanks again. I can see an issue with how a full x10 address is parsed. This one is only related to the legacy implementation since the new one has separated house/unit configuration. I will fix it and provide an updated build.

14

@Runnerk I uploaded an updated build with the fix in the link above. Can you give it a try? Thanks again for doing the testing.

15

Thanks @jeshab.
All devices are online now. Also tested the sensor and its working as expected.
As far as I tested, everything is working as it was before the update to 4.3.1.
Thanks again for the support

1 Like
16

Not sure if you know the history here, but yes, X10 is ancient. Insteon came on the scene offering backwards compatibility to X10 to offer an easy path to upgrade, so most/all Insteon devices can both command and receive X10 protocol and hence the support needed from the Insteon binding. I was running X10 stuff 25 years ago and took that path, but have some old stuff laying around so I was happy to help test.

17

Ok, today I installed the latest .jar and confirmed that I was able to send commands from my CM11A (via the CM11A binding) and receive them on my Insteon PLM (via the Insteon binding) and also send from PLM and receive on CM11A.

  • I installed the latest binding
  • I created a CM11A thing for an X10 AM486 appliance module (Plug in On/Off module) as HC P5, and linked an item to it.
  • I created an Insteon PLM thing for the same X10 AM486 appliance module as HC P5 and linked an item to it.
  • I started TRACE logging
  • From the CM11A item, I turned on, off, on off with about a 2 or 3 second pause in between and saw the Insteon item was responding to this. Also noted that the appliance module was also turning on/off.
  • I then briefly changed to INFO logging then back to TRACE
  • From the PLM item I turned on, off, on off with about a 2 or 3 second pause in between and saw the CM11A item responding to this. Also noted that the appliance module was also turning on/off.
  • I stopped TRACE logging
  • I’ve posted the trace log @jeshab into the shared folder we’ve been using for other debug items and called it “CM11A-PLM Receive X10 Testing.log”
  • Next I disabled my PLM and created a legacy Insteon Network.
  • Then I created a legacy thing with product key X00.00.02 for X10 dimmer. (I realized after the testing that I had selected dimmer rather than switch) but I don’t think it mattered.
  • I linked a switch item to this new thing
  • I started TRACE logging
  • I commanded the switch on/off/on/off with short pauses between each.
  • I noted that the module respoonded to each with nealry no delay
  • I stopped TRACE logging
  • I’ve posted this log to the same shared drive as " PLM Legasy X10 Testing.log"

Extra thanks for this, it saved me from having to remove like 35 things from my inbox!

Let me know if you need anything else.

1 Like
18

Thanks very much for doing the testing. The PR related to this issue was merged and will be included in OH 4.3.2.

1 Like