Insteon_plm queue does not empty after timeout

Every now and again, it seems that if I restart hass, the PLM does not clear its queue, even after the timeout expires.
Here, running hass 0.56.2 with everything insteon I could find set to debug:

2017-11-04 22:02:57 DEBUG (MainThread) [insteonplm.protocol] _timeout_reached invoked
2017-11-04 22:02:57 DEBUG (MainThread) [insteonplm.protocol] _clear_wait invoked
2017-11-04 22:02:57 DEBUG (MainThread) [insteonplm.protocol] Send queue contains 1 items
2017-11-04 22:03:26 DEBUG (MainThread) [insteonplm.protocol] turn_on '12b026' 2456D3
2017-11-04 22:03:26 DEBUG (MainThread) [insteonplm.protocol] Still waiting on last_command.
2017-11-04 22:03:26 DEBUG (MainThread) [insteonplm.protocol] Adding command to queue: 026212b0260011ff

As you can see, after the timeout is reached and the clear invoked, the send queue is not emptied of the one remaining item. I have no idea if there’s a way to print the queue out, or manually try to flush it. If those options are available, I’d appreciate a pointer. If they’re not available, does it make sense to have a way to flush the queue without having to kill hass?

Now and again is lucky. This happens to me every single time HA is loaded. Probably some device that the insteonplm doesn’t understand.

I forget all the changes I’ve made to protocol.py, but I’ve sort of hacked in my own timeout and if it’s reached, it basically erases whatever it’s “Waiting for” so it just moves on to the next item on the list.

    def _process_queue(self):
        self.log.debug('Send queue contains %d items', len(self._send_queue))
        if time.time() - self._wait_time > 1:
          #junk it
          self.log.debug('Junking it')
          self._last_command = None
          self._wait_for = {}
          self._buffer = bytearray()
          #self._process_queue()

        if self._clear_to_send() is True:
            command, wait_for = self._send_queue[0]
            self._send_hex(command, wait_for=wait_for)
            self._send_queue.remove([command, wait_for])

Then I added some extra debug messages so it says what “last_command” actually is and looks like that’s also where I attached the time to the command.

    def _send_hex(self, message, wait_for=None):
        if wait_for is None:
            wait_for = {}

        if self._last_command or self._wait_for:
            self.log.debug('Still waiting on last_command.')
            self.log.debug('Which is :%s',self._last_command)
            self.log.debug('Wait :%s',self._wait_for)
            self._queue_hex(message, wait_for)
        else:
            self._send_raw(binascii.unhexlify(message))
            self._schedule_wait(wait_for)
            self._wait_time = time.time()

If it gets a new command and it’s been longer than a second since the command it’s waiting for, then just throw it out and keep going. With how fragile this plugin is, it’s better to miss a delayed command response than tie up the whole system.

Well, I’m sufficiently happy that support for the PLM was added that I don’t want to appear ungrateful, but yes, it’s more often than not.
It also appears to be behaving more erratically now. Perhaps it’s angry with me. The last few times I restarted hass, I have seen:
2017-11-09 09:49:58 DEBUG (MainThread) [insteonplm.protocol] Send queue contains 0 items 2017-11-09 10:55:33 DEBUG (MainThread) [insteonplm.protocol] turn_on '12aac6' 2456D3 2017-11-09 10:55:33 DEBUG (MainThread) [insteonplm.protocol] Still waiting on last_command. 2017-11-09 10:55:33 DEBUG (MainThread) [insteonplm.protocol] Adding command to queue: 026212aac60011ff

Which just makes no sense.
I am wondering if it’s just you and I, since nobody else has mentioned anything similar. My Insteon gear was all working pretty well with the old automation system I was using. After I moved, I decided I wanted to start over with another project, as the old one seemed to be losing steam.
I say that to say this- is everyone else that is using the inteonplm component starting with a virgin clean plm, and I’m experiencing this angst because the plm already has a bunch of devices linked to it?

I’ve basically given up on Insteon.

They make great hardware. Combo fan/light controllers, switches with beeps and chips and adjustable ramp rates, a basic input/output module with a outlet pass though.

Their documentation and protocol though is sparse and frequently wrong. All theory and no examples. There’s one bug in the I/O Linc where you can’t get the sensor output because it returns the relay output instead, and they probably can’t fix it because if they do they’ll break existing implementations.

Anyway, besides their internal HouseLinc software, I’ve only ever seen halfway decent Insteon projects before the programmer just abandons the project. I figure they get it working well enough for their case, or get frustrated.

What I’m doing is replacing any critical components that need to be automated with Z-Wave stuff and keep the Insteon stuff for when using the little remote to control a light or when two light switches control each other directly is good enough.

Right, so now that I’ve gotten that out of my system, here are all the changes I’ve done to my own copy of Insteon_plm.

I’ll also say that I recall some point in time where it worked without all these hacks, and I don’t think the Insteon module was updated during that time so it very well could be some link inside the PLM that it’s choking on.

 insteonplm/ipdb.py     | 21 +++++++++-------
 insteonplm/plm.py      |  3 ---
 insteonplm/protocol.py | 68 ++++++++++++++++----------------------------------
 3 files changed, 34 insertions(+), 58 deletions(-)

diff --git a/insteonplm/ipdb.py b/insteonplm/ipdb.py
index e098a4b..7b3b176 100644
--- a/insteonplm/ipdb.py
+++ b/insteonplm/ipdb.py
@@ -12,21 +12,24 @@ class IPDB(object):
     """Embodies the INSTEON Product Database static data and access methods."""
 
     products = [
-        Product(0x01, 0x00, None, 'LampLinc 3-pin', '2456D3', ['light', 'dimmer']),
-        Product(0x01, 0x01, None, 'SwitchLinc Dimmer (600W)', '2476D', ['light', 'dimmer']),
-        Product(0x01, 0x02, None, 'In-LineLinc Dimmer', '2475D', ['light', 'dimmer']),
-        Product(0x01, 0x03, None, 'Icon Switch Dimmer', '2476D', ['light', 'dimmer']),
+
+        Product(0x00, 0x12, None, 'Remote', '2444A2WH8', ['switch']),
+        Product(0x01, 0x00, None, 'LampLinc 3-pin', '2456D3', ['light', 'dimmable']),
+        Product(0x01, 0x01, None, 'SwitchLinc Dimmer (600W)', '2476D', ['light', 'dimmable']),
+        Product(0x01, 0x02, None, 'In-LineLinc Dimmer', '2475D', ['light', 'dimmable']),
+        Product(0x01, 0x03, None, 'Icon Switch Dimmer', '2476D', ['light', 'dimmable']),
         Product(0x01, 0x04, None, 'SwitchLinc Dimmer (1000W)', '2476DH', ['light', 'dimmable']),
-        Product(0x01, 0x06, None, 'LampLinc 2-pin', '2456D2', ['light', 'dimmer']),
+        Product(0x01, 0x06, None, 'LampLinc 2-pin', '2456D2', ['light', 'dimmable']),
         Product(0x01, 0x07, None, 'LampLinc Dimmer V2 2-pin', '2856D2', ['light', 'dimmable']),
         Product(0x01, 0x0d, None, 'SocketLinc Dimmer', '2454D', ['light', 'dimmable']),
         Product(0x01, 0x0e, None, 'LampLinc Dual Band 2-pin', '2457D2', ['light', 'dimmable']),
         Product(0x01, 0x13, 0x000032, 'SwitchLinc Dimmer (Lixar)', '2676D-B', ['light', 'dimmer']),
         Product(0x01, 0x17, None, 'ToggleLinc Dimmer', '2466D', ['light', 'dimmer']),
-        Product(0x01, 0x18, 0x00003F, 'Icon SwitchLinc Dimmer Inline Companiion', '2474D', ['light', 'dimmer']),
+        Product(0x01, 0x18, 0x00003F, 'Icon SwitchLinc Dimmer Inline Companiion', '2474D', ['light', 'dimmable']),
+        Product(0x01, 0x19, None, 'SwitchLinc Dimmer', '2474D', ['light', 'dimmable']),
         Product(0x01, 0x1a, 0x00004F, 'In-LineLinc Dimmer', '2475DA1', ['light', 'dimmable']),
         Product(0x01, 0x1b, 0x000050, 'KeypadLinc Dimmer, 6-button', '2486DWH6', ['light', 'dimmable']),
-        Product(0x01, 0x1b, 0x000051, 'KeypadLinc Dimmer, 8-button', '2486DWH8', ['light', 'dimmable']),
+#        Product(0x01, 0x1b, 0x000051, 'KeypadLinc Dimmer, 8-button', '2486DWH8', ['light', 'dimmable']),
         Product(0x01, 0x1d, None, 'SwitchLinc Dimmer (1200W)', '2476D', ['light', 'dimmable']),
         Product(0x01, 0x1e, None, 'Icon Switch Dimmer i2', '2476DB', ['light', 'dimmer']),
         Product(0x01, 0x1f, None, 'ToggleLinc Dimmer', '2466D', ['light', 'dimmer']),
@@ -68,9 +71,9 @@ class IPDB(object):
         Product(0x02, 0x37, None, 'On/Off Module', '2635-222', ['switch']),
         Product(0x02, 0x38, None, 'On/Off Outdoor Module', '2634-222', ['switch']),
         Product(0x02, 0x39, None, 'On/Off Outlet', '2663-222', ['switch']),
+        Product(0x02, 0x1e, None, 'KeypadLinc Dimmer, 6-button', '2486S', ['light', 'dimmable']),
 
-        Product(0x03, 0x15, None, 'PowerLinc Modem (USB)', '2413U', ['plm']),
-        Product(0x03, 0x20, None, 'USB Adapter', '2448A7', ['plm']),
+        Product(0x03, 0x15, None, 'Modem', '2413U', ['switch']),
 
         Product(0x05, 0x0b, None, 'Thermostat', '2441TH', ['climate']), #<- Coming Soon!
 
diff --git a/insteonplm/plm.py b/insteonplm/plm.py
index 1704a5c..0cc0e0f 100644
--- a/insteonplm/plm.py
+++ b/insteonplm/plm.py
@@ -88,9 +88,6 @@ class PLMProtocol(object):
         self.add(0x60, name='Get IM Info', size=2, rsize=9)
         self.add(0x61, name='Send ALL-Link Command', size=5, rsize=6)
         self.add(0x62, name='INSTEON Fragmented Message', size=8, rsize=9)
-        self.add(0x64, name='Start ALL-Linking', size=4, rsize=5)
-        self.add(0x65, name='Cancel ALL-Linking', size=4)
-        self.add(0x67, name='Reset the IM', size=2, rsize=3)
         self.add(0x69, name='Get First ALL-Link Record', size=2)
         self.add(0x6a, name='Get Next ALL-Link Record', size=2)
         self.add(0x73, name='Get IM Configuration', size=2, rsize=6)
diff --git a/insteonplm/protocol.py b/insteonplm/protocol.py
index b13415f..21f3390 100755
--- a/insteonplm/protocol.py
+++ b/insteonplm/protocol.py
@@ -2,6 +2,7 @@
 import asyncio
 import logging
 import binascii
+import time
 
 from .ipdb import IPDB
 from .plm import Address, PLMProtocol, Message
@@ -185,20 +186,20 @@ class PLM(asyncio.Protocol):
         self._message_callbacks = []
         self._insteon_callbacks = []
 
+        self._me = None
         self._buffer = bytearray()
         self._last_message = None
         self._last_command = None
         self._wait_for = {}
         self._recv_queue = []
         self._send_queue = []
+        self._wait_time = 0
 
         self.devices = ALDB()
 
         self.log = logging.getLogger(__name__)
         self.transport = None
 
-        self._me = {}
-
         self._userdefineddevices = {}
 
         for userdevice in userdefineddevices:
@@ -352,9 +353,8 @@ class PLM(asyncio.Protocol):
                         if 'cat' in device and device['cat'] > 0:
                             self.log.debug('I know the category for %s (0x%x)',
                                            address, device['cat'])
-                            self.product_data_request(address)
                         else:
-                            self.product_data_request(address)
+                            self.product_data_request(device)
                     for userdevice in self._userdefineddevices:
                         if self._userdefineddevices[userdevice]["status"] == "notfound":
                             self.log.info("Failed to discover device %r.", userdevice)
@@ -423,6 +423,14 @@ class PLM(asyncio.Protocol):
 
     def _process_queue(self):
         self.log.debug('Send queue contains %d items', len(self._send_queue))
+        if time.time() - self._wait_time > 1:
+          #junk it
+          self.log.debug('Junking it')
+          self._last_command = None
+          self._wait_for = {}
+          self._buffer = bytearray()
+          #self._process_queue()
+
         if self._clear_to_send() is True:
             command, wait_for = self._send_queue[0]
             self._send_hex(command, wait_for=wait_for)
@@ -449,7 +457,7 @@ class PLM(asyncio.Protocol):
 
         msg = Message(rawmessage)
 
-        # if hasattr(msg, 'target') and msg.target != self._me['address']:
+        # if hasattr(msg, 'target') and msg.target != self._me:
         #     self.log.info('Ignoring message that is not for me')
         #     return
 
@@ -521,9 +529,6 @@ class PLM(asyncio.Protocol):
                                callback, criteria)
                 self._loop.call_soon(callback, msg, device)
 
-        if msg.cmd1 == 0x03 and msg.cmd2 == 0x00:
-            self._parse_product_data_response(msg.address, msg.userdata)
-
     def _parse_insteon_extended(self, msg):
         device = self.devices[msg.address.hex]
 
@@ -652,11 +657,7 @@ class PLM(asyncio.Protocol):
     def _parse_get_plm_info(self, msg):
         self.log.info('PLM Info from %r: category:%02x subcat:%02x firmware:%02x',
                       msg.address, msg.category, msg.subcategory, msg.firmware)
-
-        self._me['address'] = msg.address
-        self._me['category'] = msg.category
-        self._me['subcategory'] = msg.subcategory
-        self._me['firmware'] = msg.firmware
+        self._me = msg.address
 
     def _parse_get_plm_config(self, msg):
         self.log.info('PLM Config: flags:%02x spare:%02x spare:%02x',
@@ -666,30 +667,17 @@ class PLM(asyncio.Protocol):
         self.log.info('ALL-Link Record for %r: flags:%02x group:%02x data:%02x/%02x/%02x',
                       msg.address, msg.flagsval, msg.group,
                       msg.linkdata1, msg.linkdata2, msg.linkdata3)
-
-        if self._me['subcategory'] == 0x20:
-            # USB Stick has a different ALDB message format.  I don't actually
-            # think that linkdata1 is firmware, but whatever.  Shouldn't have
-            # any effect storing the value there anyway.
-            category = msg.linkdata2
-            subcategory = msg.linkdata3
-            firmware = msg.linkdata1
-        else:
-            # Regular PLM format
-            category = msg.linkdata1
-            subcategory = msg.linkdata2
-            firmware = msg.linkdata3
-
-
+        
         if msg.address.hex in self.devices:
             self.log.info("Device %r is already added manually.", msg.address.hex)
             if msg.address.hex in self._userdefineddevices:
                 self._userdefineddevices[msg.address.hex]["status"] = "found"
         else:
             self.log.info("Auto Discovering device %r.", msg.address.hex)
-            self.devices[msg.address.hex] = {'cat': category,
-                                         'subcat': subcategory,
-                                         'firmware': firmware}
+            if not msg.linkdata1 == 0x00:
+              self.devices[msg.address.hex] = {'cat': msg.linkdata1,
+                                         'subcat': msg.linkdata2,
+                                         'firmware': msg.linkdata3}
 
         if self.devices.state == 'loading':
             self.get_next_all_link_record()
@@ -726,10 +714,13 @@ class PLM(asyncio.Protocol):
 
         if self._last_command or self._wait_for:
             self.log.debug('Still waiting on last_command.')
+            self.log.debug('Which is :%s',self._last_command) 
+            self.log.debug('Wait :%s',self._wait_for) 
             self._queue_hex(message, wait_for)
         else:
             self._send_raw(binascii.unhexlify(message))
             self._schedule_wait(wait_for)
+            self._wait_time = time.time()
 
     def _send_raw(self, message):
         self.log.debug('Sending %d byte message: %s',
@@ -787,21 +778,6 @@ class PLM(asyncio.Protocol):
         self.log.info('Requesting PLM Config')
         self._send_hex('0273')
 
-    def factory_reset(self):
-        """Reset the IM and clear the All-Link Database."""
-        self.log.info('Nuking from orbit')
-        self._send_hex('0267')
-
-    def start_all_linking(self):
-        """Puts the IM into ALL-Linking mode without using the SET Button."""
-        self.log.info('Start ALL-Linking')
-        self._send_hex('02640101')
-
-    def cancel_all_linking(self):
-        """Cancels the ALL-Linking started previously."""
-        self.log.info('Cancel ALL-Linking')
-        self._send_hex('0265')
-
     def get_first_all_link_record(self):
         """Request first ALL-Link record."""
         self.log.info('Requesting First ALL-Link Record')

I had a lot of similar problems. I like the insteon hardware so I’m going to try and get it working. I took a look at as many of the Python (and non-python) insteon modules I could and never found one that really does what I want. I know it’s “yet another insteon project”, but I’ve started a Python 3 project to build an Insteon to/from MQTT bridge package. I’d like to make something is robust and works at keeping the state of everything correctly synced especially for multiple linked devices. Additionally, I’m adding many of the nice features in the insteon-terminal for managing the device databases and automatically linking more complicated devices together (like the smoke bridge). I have something that’s working - the basic architecture seems to be sound (I can interrupt commands with other commands and it still works) and it should be pretty easy to add new devices. I’ve also isolated the MQTT code via signal/slots so it should be usable without MQTT in other apps if needed. Part of the reason I’m building it outside of HA right now is to avoid having multiple insteon modules available but with MQTT it should work with anything. It’s only at about a 0.1 version level at this point but I can modify devices with MQTT messages and they will send out updates over MQTT whenever their state changes. I still need to do a lot of docs, unit tests, make it easier to run and use, etc, etc. Here’s the repo, feel free to keep watching there for updates and I’ll post something when I think it has enough docs to be usable by others.

1 Like

FYI the first version of my alternative system for integration Insteon PLM modems using MQTT as a bridge is now available in this respository. It’s working well for my Insteon/HASS set up and has an initial cut at user’s guide and setup docs. The sample config.yaml file in that repository includes examples of how to configure HASS components to work with the MQTT topics and payloads that are defined. Feel free to try it and report any problems or suggestions as github issues if you’re interested.

2 Likes

I haven’t tried your mqtt bridge yet, but looking over the docs i feel you’ve made a great choice in going for a mqtt bridge! I made a choice to switch most of my easy stuff (lamplinc dimmers and what not) over to z-wave as it seems to be a first class citizen in HA (vs the current insteon state). But your project gives me hope for some of my more embedded insteon devices (wall switches, door sensors (i know the doc says you havent gotten to these yet), etc ). so thanks for putting in the time here!

@redparchel Regular on/off and dimmer wall switches work great, I just don’t have the keypad switch yet. I took a look at the door sensors and they basically operate the same as motion sensors (group 1 = on/off, group 3 = battery) so I’d bet if you put them in as motion sensors, they will work as is. I’ll open an issue to add a “real” set of inputs for them to make that clearer (or maybe I’ll just make the motion sensors more general). Feel free to subscribe at that issue and we can iterate on testing the results (I don’t own any of those sensors help testing them is greatly appreciated).

1 Like

FYI, the insteon_plm module has been signficiantly updated as of 0.65.0. This fixes a lot of the issues with the old version including better auto discovery, and hanging when the network is chatty. It also adds support for FanLinc, I/O linc, SmokeBridge. Currently working on Keypadlinc and Thermostat.