Insteon HUB not showing devices

I have my 2245-222 configured as below. I have the debug logging enabled via the " homeassistant.components.insteon: debug" line added and I see it try to communicate in the logs. but I never see any devices. I know from the Insteon App on my phone that I have 5 switches up and running on the HUB.

any ideas why I can’t see those in HA?

insteon:
host: 10.1.1.28
ip_port: 25105
username: !secret insteon_user
password: !secret insteon_secret
hub_version: 2

2019-03-17 13:19:59 INFO (MainThread) [homeassistant.setup] Setup of domain insteon took 0.6 seconds.

2019-03-17 13:19:59 INFO (MainThread) [insteonplm] Insteon Hub reader started

2019-03-17 13:19:59 INFO (MainThread) [homeassistant.setup] Setup of domain config took 0.1 seconds.

2019-03-17 13:19:59 INFO (MainThread) [homeassistant.setup] Setup of domain tts took 0.1 seconds.

2019-03-17 13:19:59 INFO (MainThread) [insteonplm.plm] Connection established to Hub

2019-03-17 13:19:59 INFO (MainThread) [insteonplm.plm] Requesting Insteon Modem Info

2019-03-17 13:19:59 INFO (MainThread) [insteonplm.plm] Requesting ALL-Link Records

@p0lar did you ever get this working? I am sorry for the late reply here but I have started a new job recently so I have not had much time to work on this. Do you ever get anything following the “Requesting All-Link Records” message? Also, can you confirm you have this in debug mode as follows:

logger:
  logs:
    insteonplm: debug
    homeassistant.components.insteon: debug

I have debug mode on and I do now see things after that message… about 3 times. I dont ever see any of the devices that I have in the modem that I see and can control with the Insteon app on my phone.

2019-07-08 17:30:21 DEBUG (MainThread) [insteonplm.plm] TX: {'code': 0x62, 'address': 48.5D.56, 'flags': 0x00, 'cmd1': 0x19, 'cmd2': 0x00, 'acknak': 0xNone}
2019-07-08 17:30:21 DEBUG (MainThread) [insteonplm] ..................Writing a message..............
2019-07-08 17:30:21 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2019-07-08 17:30:21 DEBUG (MainThread) [insteonplm] Writing message: http://10.1.1.28:25105/3?0262485d56001900=I=3
2019-07-08 17:30:21 DEBUG (MainThread) [insteonplm] Post status: 200
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm] Buffer from 0 to 40
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm] New buffer: 0262485D56001900060250485D5639F45C200000
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.plm] Starting: data_received
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.plm] Received 20 bytes from PLM: b'0262485d56001900060250485d5639f45c200000'
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.plm] Finishing: data_received
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.plm] Total buffer: b'0262485d56001900060250485d5639f45c200000'
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.plm] Total buffer: b'0250485d5639f45c200000'
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.plm] Buffer too short to have a message
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.plm] Messages in queue: 2
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.plm] RX: {'code': 0x62, 'address': 48.5D.56, 'flags': 0x00, 'cmd1': 0x19, 'cmd2': 0x00, 'acknak': 0x06}
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.devices] Starting Device.receive_message
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.devices] Got Message ACK
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.devices] Look for direct ACK
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.devices] Ending Device.receive_message
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.plm] RX: {'code': 0x50, 'address': 48.5D.56, 'target': 39.F4.5C, 'flags': 0x20, 'cmd1': 0x00, 'cmd2': 0x00}
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.devices] Got Direct ACK message
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.plm] Last item in self._recv_queue reached.
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.plm] ACK or NAK received
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.devices] Starting Device._wait_for_direct_ACK
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.devices] Direct ACK: {'code': 0x50, 'address': 48.5D.56, 'target': 39.F4.5C, 'flags': 0x20, 'cmd1': 0x00, 'cmd2': 0x00}
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.devices] Releasing lock after processing direct ACK
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.devices] Device 48.5D.56 msg_lock unlocked
2019-07-08 17:30:22 DEBUG (MainThread) [homeassistant.components.insteon] Received update for device 48.5D.56 group 1 value 0
2019-07-08 17:30:22 DEBUG (MainThread) [insteonplm.devices] Ending Device._wait_for_direct_ACK

Can you show me the full log after startup?

Yes…


2019-07-09 11:30:51 DEBUG (MainThread) [insteonplm] Test connection status is 200
2019-07-09 11:30:51 DEBUG (MainThread) [insteonplm] Starting the buffer reader
2019-07-09 11:30:51 DEBUG (MainThread) [insteonplm] ending Connection._connect
2019-07-09 11:30:51 DEBUG (MainThread) [insteonplm] ending Connection.reconnect
2019-07-09 11:30:51 DEBUG (MainThread) [insteonplm] Ending Connection.create
2019-07-09 11:30:51 DEBUG (MainThread) [insteonplm.linkedDevices] New override for 485690 cat is 2
2019-07-09 11:30:51 DEBUG (MainThread) [insteonplm.linkedDevices] New override for 485690 subcat is 42
2019-07-09 11:30:51 DEBUG (MainThread) [insteonplm.linkedDevices] New override for 48544d cat is 2
2019-07-09 11:30:51 DEBUG (MainThread) [insteonplm.linkedDevices] New override for 48544d subcat is 42
2019-07-09 11:30:51 DEBUG (MainThread) [insteonplm.linkedDevices] New override for 485d56 cat is 2
2019-07-09 11:30:51 DEBUG (MainThread) [insteonplm.linkedDevices] New override for 485d56 subcat is 42
2019-07-09 11:30:51 DEBUG (MainThread) [insteonplm.linkedDevices] Added new callback <function async_setup.<locals>.async_new_insteon_device at 0x7fcbaa541840>
2019-07-09 11:30:51 INFO (MainThread) [homeassistant.setup] Setup of domain insteon took 2.3 seconds.

2019-07-09 11:30:51 INFO (MainThread) [insteonplm] Insteon Hub reader started
2019-07-09 11:30:51 DEBUG (MainThread) [insteonplm] ..................Clearing the buffer..............
2019-07-09 11:30:51 DEBUG (MainThread) [insteonplm] Writing message: http://10.1.1.28:25105/1?XB=M=1
2019-07-09 11:30:52 DEBUG (MainThread) [insteonplm] Post status: 200
2019-07-09 11:30:52 DEBUG (MainThread) [insteonplm] Calling connection made
2019-07-09 11:30:52 DEBUG (MainThread) [insteonplm] Protocol: <insteonplm.plm.Hub object at 0x7fcbaa617a90>
2019-07-09 11:30:52 INFO (MainThread) [insteonplm.plm] Connection established to Hub
2019-07-09 11:30:52 DEBUG (MainThread) [insteonplm.plm] Transport: <insteonplm.HttpTransport object at 0x7fcbaa449668>
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.plm] Starting Insteon Modem write message from send queue
2019-07-09 11:30:53 DEBUG (SyncWorker_8) [homeassistant.components.insteon] Insteon Services registered
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.plm] Aquiring write lock
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] Loading saved device info.
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] Really Loading saved device info.
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] Saved device file loaded
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] Found saved device with address 485cb1
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] Found saved device with address 49bfe8
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] Found saved device with address 485690
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] Found saved device with address 48544d
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] Found saved device with address 485d56
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.plm] Found 5 saved devices
2019-07-09 11:30:53 INFO (MainThread) [insteonplm.plm] Requesting Insteon Modem Info
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.plm] Queueing msg: {'code': 0x60, 'address': 00.00.00, 'category': 0xNone, 'subcategory': 0xNone, 'firmware': 0xNone, 'acknak': 0xNone}
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.devices] Registering messages for 48.5C.B1
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.devices] ID ACK: {'code': 0x62, 'address': 48.5C.B1, 'flags': 0x00, 'cmd1': 0x10, 'cmd2': 0x00, 'acknak': 0x06}
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] Device with id 485cb1 added to device list from saved device data.
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] New INSTEON Device '485cb1': SwitchLinc Relay (Dual-Band) (02:2a)
2019-07-09 11:30:53 INFO (MainThread) [homeassistant.components.insteon] New INSTEON device: 485cb1 (lightOnOff) switch
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.devices] Registering messages for 49.BF.E8
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.devices] ID ACK: {'code': 0x62, 'address': 49.BF.E8, 'flags': 0x00, 'cmd1': 0x10, 'cmd2': 0x00, 'acknak': 0x06}
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] Device with id 49bfe8 added to device list from saved device data.
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] New INSTEON Device '49bfe8': SwitchLinc Relay (Dual-Band) (02:2a)
2019-07-09 11:30:53 INFO (MainThread) [homeassistant.components.insteon] New INSTEON device: 49bfe8 (lightOnOff) switch
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.devices] Registering messages for 48.56.90
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.devices] ID ACK: {'code': 0x62, 'address': 48.56.90, 'flags': 0x00, 'cmd1': 0x10, 'cmd2': 0x00, 'acknak': 0x06}
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] Device with id 485690 added to device list from saved device data.
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] New INSTEON Device '485690': SwitchLinc Relay (Dual-Band) (02:2a)
2019-07-09 11:30:53 INFO (MainThread) [homeassistant.components.insteon] New INSTEON device: 485690 (lightOnOff) switch
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.devices] Registering messages for 48.54.4D
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.devices] ID ACK: {'code': 0x62, 'address': 48.54.4D, 'flags': 0x00, 'cmd1': 0x10, 'cmd2': 0x00, 'acknak': 0x06}
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] Device with id 48544d added to device list from saved device data.
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] New INSTEON Device '48544d': SwitchLinc Relay (Dual-Band) (02:2a)
2019-07-09 11:30:53 INFO (MainThread) [homeassistant.components.insteon] New INSTEON device: 48544d (lightOnOff) switch
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.devices] Registering messages for 48.5D.56
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.devices] ID ACK: {'code': 0x62, 'address': 48.5D.56, 'flags': 0x00, 'cmd1': 0x10, 'cmd2': 0x00, 'acknak': 0x06}
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] Device with id 485d56 added to device list from saved device data.
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.linkedDevices] New INSTEON Device '485d56': SwitchLinc Relay (Dual-Band) (02:2a)
2019-07-09 11:30:53 INFO (MainThread) [homeassistant.components.insteon] New INSTEON device: 485d56 (lightOnOff) switch
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.plm] Starting: _load_all_link_database
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.plm] Starting: _get_first_all_link_record
2019-07-09 11:30:53 INFO (MainThread) [insteonplm.plm] Requesting ALL-Link Records
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.plm] Queueing msg: {'code': 0x69, 'acknak': 0xNone}
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.plm] Ending: _get_first_all_link_record
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.plm] Ending: _load_all_link_database
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.plm] Ending _setup_devices in IM
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.plm] TX: {'code': 0x60, 'address': 00.00.00, 'category': 0xNone, 'subcategory': 0xNone, 'firmware': 0xNone, 'acknak': 0xNone}
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm] ..................Writing a message..............
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm] Writing message: http://10.1.1.28:25105/3?0260=I=3
2019-07-09 11:30:53 INFO (MainThread) [homeassistant.components.switch] Setting up switch.insteon
2019-07-09 11:30:53 INFO (MainThread) [homeassistant.components.switch] Setting up switch.insteon
2019-07-09 11:30:53 INFO (MainThread) [homeassistant.components.switch] Setting up switch.insteon
2019-07-09 11:30:53 INFO (MainThread) [homeassistant.components.switch] Setting up switch.insteon
2019-07-09 11:30:53 INFO (MainThread) [homeassistant.components.switch] Setting up switch.insteon
2019-07-09 11:30:53 DEBUG (MainThread) [homeassistant.components.insteon.switch] Adding device 485cb1 entity lightOnOff to Switch platform
2019-07-09 11:30:53 DEBUG (MainThread) [homeassistant.components.insteon.switch] Adding device 49bfe8 entity lightOnOff to Switch platform
2019-07-09 11:30:53 DEBUG (MainThread) [homeassistant.components.insteon.switch] Adding device 485690 entity lightOnOff to Switch platform
2019-07-09 11:30:53 DEBUG (MainThread) [homeassistant.components.insteon.switch] Adding device 48544d entity lightOnOff to Switch platform
2019-07-09 11:30:53 DEBUG (MainThread) [homeassistant.components.insteon.switch] Adding device 485d56 entity lightOnOff to Switch platform
2019-07-09 11:30:53 DEBUG (MainThread) [homeassistant.components.insteon] Tracking updates for device 48.5C.B1 group 1 statename lightOnOff
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.states] Registered callback for state: lightOnOff
2019-07-09 11:30:53 DEBUG (MainThread) [homeassistant.components.insteon] Tracking updates for device 49.BF.E8 group 1 statename lightOnOff
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.states] Registered callback for state: lightOnOff
2019-07-09 11:30:53 DEBUG (MainThread) [homeassistant.components.insteon] Tracking updates for device 48.56.90 group 1 statename lightOnOff
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.states] Registered callback for state: lightOnOff
2019-07-09 11:30:53 DEBUG (MainThread) [homeassistant.components.insteon] Tracking updates for device 48.54.4D group 1 statename lightOnOff
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.states] Registered callback for state: lightOnOff
2019-07-09 11:30:53 DEBUG (MainThread) [homeassistant.components.insteon] Tracking updates for device 48.5D.56 group 1 statename lightOnOff
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm.states] Registered callback for state: lightOnOff
2019-07-09 11:30:53 DEBUG (MainThread) [insteonplm] Post status: 200
2019-07-09 11:30:54 DEBUG (MainThread) [insteonplm] Buffer from 0 to 18
2019-07-09 11:30:54 DEBUG (MainThread) [insteonplm] New buffer: 026039F45C0333A406
2019-07-09 11:30:54 DEBUG (MainThread) [insteonplm.plm] Starting: data_received
2019-07-09 11:30:54 DEBUG (MainThread) [insteonplm.plm] Received 9 bytes from PLM: b'026039f45c0333a406'
2019-07-09 11:30:54 DEBUG (MainThread) [insteonplm.plm] Finishing: data_received
2019-07-09 11:30:54 DEBUG (MainThread) [insteonplm.plm] Total buffer: b'026039f45c0333a406'
2019-07-09 11:30:54 DEBUG (MainThread) [insteonplm.plm] Buffer too short to have a message
2019-07-09 11:30:54 DEBUG (MainThread) [insteonplm.plm] Messages in queue: 1
2019-07-09 11:30:54 DEBUG (MainThread) [insteonplm.plm] RX: {'code': 0x60, 'address': 39.F4.5C, 'category': 0x03, 'subcategory': 0x33, 'firmware': 0xa4, 'acknak': 0x06}
2019-07-09 11:30:54 DEBUG (MainThread) [insteonplm.plm] Last item in self._recv_queue reached.
2019-07-09 11:30:54 DEBUG (MainThread) [insteonplm.plm] ACK or NAK received
2019-07-09 11:30:54 DEBUG (MainThread) [insteonplm.plm] Starting _handle_get_plm_info
2019-07-09 11:30:54 DEBUG (MainThread) [insteonplm.plm] Ending _handle_get_plm_info
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] TX: {'code': 0x69, 'acknak': 0xNone}
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm] ..................Writing a message..............
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm] Writing message: http://10.1.1.28:25105/3?0269=I=3
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm] Post status: 200
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm] Buffer from 0 to 26
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm] New buffer: 0269060257E200485690012A45
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] Starting: data_received
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] Received 13 bytes from PLM: b'0269060257e200485690012a45'
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] Finishing: data_received
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] Total buffer: b'0269060257e200485690012a45'
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] Total buffer: b'0257e200485690012a45'
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] Buffer too short to have a message
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] Messages in queue: 2
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] RX: {'code': 0x69, 'acknak': 0x06}
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] RX: {'code': 0x57, 'controlFlags': 0xe2, 'group': 0x00, 'address': 48.56.90, 'linkdata1': 0x01, 'linkdata2': 0x2a, 'linkdata3': 0x45}
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.devices] Starting Device.receive_message
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.devices] Ending Device.receive_message
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] Last item in self._recv_queue reached.
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] ACK or NAK received
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] Found all link record for device 485690
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] Starting: _get_next_all_link_record
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] Requesting Next All-Link Record
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] Queueing msg: {'code': 0x6a, 'acknak': 0xNone}
2019-07-09 11:30:55 DEBUG (MainThread) [insteonplm.plm] Ending: _get_next_all_link_record
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] TX: {'code': 0x6a, 'acknak': 0xNone}
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm] ..................Writing a message..............
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm] Writing message: http://10.1.1.28:25105/3?026a=I=3
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm] Post status: 200
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm] Buffer from 0 to 26
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm] New buffer: 026A060257A201485690000000
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] Starting: data_received
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] Received 13 bytes from PLM: b'026a060257a201485690000000'
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] Finishing: data_received
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] Total buffer: b'026a060257a201485690000000'
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] Total buffer: b'0257a201485690000000'
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] Buffer too short to have a message
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] Messages in queue: 2
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] RX: {'code': 0x6a, 'acknak': 0x06}
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] RX: {'code': 0x57, 'controlFlags': 0xa2, 'group': 0x01, 'address': 48.56.90, 'linkdata1': 0x00, 'linkdata2': 0x00, 'linkdata3': 0x00}
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.devices] Starting Device.receive_message
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.devices] Ending Device.receive_message
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] Last item in self._recv_queue reached.
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] ACK or NAK received
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] Found all link record for device 485690
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] Starting: _get_next_all_link_record
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] Requesting Next All-Link Record
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] Queueing msg: {'code': 0x6a, 'acknak': 0xNone}
2019-07-09 11:30:56 DEBUG (MainThread) [insteonplm.plm] Ending: _get_next_all_link_record
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] TX: {'code': 0x6a, 'acknak': 0xNone}
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm] ..................Writing a message..............
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm] Writing message: http://10.1.1.28:25105/3?026a=I=3
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm] Post status: 200
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm] Buffer from 0 to 26
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm] New buffer: 026A060257E208485690012A45
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] Starting: data_received
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] Received 13 bytes from PLM: b'026a060257e208485690012a45'
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] Finishing: data_received
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] Total buffer: b'026a060257e208485690012a45'
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] Total buffer: b'0257e208485690012a45'
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] Buffer too short to have a message
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] Messages in queue: 2
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] RX: {'code': 0x6a, 'acknak': 0x06}
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] RX: {'code': 0x57, 'controlFlags': 0xe2, 'group': 0x08, 'address': 48.56.90, 'linkdata1': 0x01, 'linkdata2': 0x2a, 'linkdata3': 0x45}
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.devices] Starting Device.receive_message
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.devices] Ending Device.receive_message
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] Last item in self._recv_queue reached.
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] ACK or NAK received
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] Found all link record for device 485690
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] Starting: _get_next_all_link_record
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] Requesting Next All-Link Record
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] Queueing msg: {'code': 0x6a, 'acknak': 0xNone}
2019-07-09 11:30:57 DEBUG (MainThread) [insteonplm.plm] Ending: _get_next_all_link_record
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm.plm] TX: {'code': 0x6a, 'acknak': 0xNone}
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm] ..................Writing a message..............
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm] Writing message: http://10.1.1.28:25105/3?026a=I=3
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm] Post status: 200
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm] Buffer from 0 to 6
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm] New buffer: 026A15
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm.plm] Starting: data_received
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm.plm] Received 3 bytes from PLM: b'026a15'
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm.plm] Finishing: data_received
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm.plm] Total buffer: b'026a15'
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm.plm] Buffer too short to have a message
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm.plm] Messages in queue: 1
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm.plm] RX: {'code': 0x6a, 'acknak': 0x15}
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm.plm] Last item in self._recv_queue reached.
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm.plm] ACK or NAK received
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm.plm] Starting: _get_next_all_link_record
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm.plm] Requesting Next All-Link Record
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm.plm] Queueing msg: {'code': 0x6a, 'acknak': 0xNone}
2019-07-09 11:30:58 DEBUG (MainThread) [insteonplm.plm] Ending: _get_next_all_link_record
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm.plm] TX: {'code': 0x6a, 'acknak': 0xNone}
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm] ..................Writing a message..............
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm] Writing message: http://10.1.1.28:25105/3?026a=I=3
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm] Post status: 200
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm] Buffer from 0 to 6
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm] New buffer: 026A15
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm.plm] Starting: data_received
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm.plm] Received 3 bytes from PLM: b'026a15'
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm.plm] Finishing: data_received
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm.plm] Total buffer: b'026a15'
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm.plm] Buffer too short to have a message
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm.plm] Messages in queue: 1
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm.plm] RX: {'code': 0x6a, 'acknak': 0x15}
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm.plm] Last item in self._recv_queue reached.
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm.plm] ACK or NAK received
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm.plm] Starting: _get_next_all_link_record
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm.plm] Requesting Next All-Link Record
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm.plm] Queueing msg: {'code': 0x6a, 'acknak': 0xNone}
2019-07-09 11:30:59 DEBUG (MainThread) [insteonplm.plm] Ending: _get_next_all_link_record
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm.plm] TX: {'code': 0x6a, 'acknak': 0xNone}
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm] ..................Writing a message..............
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm] Writing message: http://10.1.1.28:25105/3?026a=I=3
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm] Post status: 200
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm] Buffer from 0 to 6
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm] New buffer: 026A15
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm.plm] Starting: data_received
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm.plm] Received 3 bytes from PLM: b'026a15'
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm.plm] Finishing: data_received
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm.plm] Total buffer: b'026a15'
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm.plm] Buffer too short to have a message
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm.plm] Messages in queue: 1
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm.plm] RX: {'code': 0x6a, 'acknak': 0x15}
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm.plm] Last item in self._recv_queue reached.
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm.plm] ACK or NAK received
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm.plm] Starting: _get_next_all_link_record
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm.plm] Requesting Next All-Link Record
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm.plm] Queueing msg: {'code': 0x6a, 'acknak': 0xNone}
2019-07-09 11:31:00 DEBUG (MainThread) [insteonplm.plm] Ending: _get_next_all_link_record
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] TX: {'code': 0x6a, 'acknak': 0xNone}
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm] ..................Writing a message..............
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm] Writing message: http://10.1.1.28:25105/3?026a=I=3
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm] Post status: 200
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm] Buffer from 0 to 6
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm] New buffer: 026A15
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Starting: data_received
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Received 3 bytes from PLM: b'026a15'
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Finishing: data_received
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Total buffer: b'026a15'
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Buffer too short to have a message
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Messages in queue: 1
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] RX: {'code': 0x6a, 'acknak': 0x15}
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Last item in self._recv_queue reached.
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] ACK or NAK received
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] All-Link device records found in ALDB: 0
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Starting _get_device_info
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Device 485cb1 not in ALDB device list
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] ALDB device count: 0
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Device 49bfe8 not in ALDB device list
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] ALDB device count: 0
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Device 485690 not in ALDB device list
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] ALDB device count: 0
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Device 48544d not in ALDB device list
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] ALDB device count: 0
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Device 485d56 not in ALDB device list
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] ALDB device count: 0
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.linkedDevices] Added new callback <bound method IM._new_device_added of <insteonplm.plm.Hub object at 0x7fcbaa617a90>>
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Ending _get_device_info
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.linkedDevices] Writing 5 devices to save file
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Starting Device._send_msg
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Ending Device._send_msg
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Starting Device._send_msg
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Ending Device._send_msg
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Starting Device._send_msg
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Ending Device._send_msg
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Starting Device._send_msg
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Ending Device._send_msg
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Starting Device._send_msg
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Ending Device._send_msg
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Starting 48.5C.B1 Device._process_send_queue
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Lock is locked from yield from
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Queueing msg: {'code': 0x62, 'address': 48.5C.B1, 'flags': 0x00, 'cmd1': 0x19, 'cmd2': 0x00, 'acknak': 0xNone}
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Ending 48.5C.B1 Device._process_send_queue
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Starting 49.BF.E8 Device._process_send_queue
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Lock is locked from yield from
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Queueing msg: {'code': 0x62, 'address': 49.BF.E8, 'flags': 0x00, 'cmd1': 0x19, 'cmd2': 0x00, 'acknak': 0xNone}
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Ending 49.BF.E8 Device._process_send_queue
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Starting 48.56.90 Device._process_send_queue
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Lock is locked from yield from
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Queueing msg: {'code': 0x62, 'address': 48.56.90, 'flags': 0x00, 'cmd1': 0x19, 'cmd2': 0x00, 'acknak': 0xNone}
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Ending 48.56.90 Device._process_send_queue
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Starting 48.54.4D Device._process_send_queue
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Lock is locked from yield from
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Queueing msg: {'code': 0x62, 'address': 48.54.4D, 'flags': 0x00, 'cmd1': 0x19, 'cmd2': 0x00, 'acknak': 0xNone}
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Ending 48.54.4D Device._process_send_queue
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Starting 48.5D.56 Device._process_send_queue
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Lock is locked from yield from
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.plm] Queueing msg: {'code': 0x62, 'address': 48.5D.56, 'flags': 0x00, 'cmd1': 0x19, 'cmd2': 0x00, 'acknak': 0xNone}
2019-07-09 11:31:01 DEBUG (MainThread) [insteonplm.devices] Ending 48.5D.56 Device._process_send_queue
2019-07-09 11:31:02 DEBUG (MainThread) [insteonplm.plm] TX: {'code': 0x62, 'address': 48.5C.B1, 'flags': 0x00, 'cmd1': 0x19, 'cmd2': 0x00, 'acknak': 0xNone}


I see 5 devices in there… let me see if I can find them in HA

From the logs it appears you have 5 devices that are all on/off switches but your Hub only knows about one of the devices. The one it knows about is 48.56.90. The other devices don’t appear to be linked correctly to the Hub. This is confusing because you say you can control all 5 devices from the Hub app.

Did you use the device_override configuration settings to configure these devices?

Tried to get this working today. From what I can tell it connects to the hub okay but doesn’t pull back any devices. I have 5 devices which I configured in the Insteon App (did that by discovery vs manual).

Any thoughts on what I might be missing. Thanks in advance.

My Configuration YAML

Hub 2242-222 configuration variables

insteon:
host: 192.168.1.209
ip_port: 25105
username: abcdefg
password: abcdefg
hub_version: 2

logger:
default: warn
logs:
insteonplm: debug
homeassistant.components.insteon: debug

My Log File;

2020-01-20 17:03:42 DEBUG (MainThread) [insteonplm] Starting Modified Connection.create
2020-01-20 17:03:42 DEBUG (MainThread) [insteonplm.devices] Registering messages for 00.00.00
2020-01-20 17:03:42 DEBUG (MainThread) [insteonplm.devices] ID ACK: {‘code’: 0x62, ‘address’: 00.00.00, ‘flags’: 0x00, ‘cmd1’: 0x10, ‘cmd2’: 0x00, ‘acknak’: 0x06}
2020-01-20 17:03:42 DEBUG (MainThread) [insteonplm] starting Connection.reconnect
2020-01-20 17:03:42 DEBUG (MainThread) [insteonplm] starting Connection._connect
2020-01-20 17:03:42 INFO (MainThread) [insteonplm] Connecting to Insteon Hub on 192.168.1.209
2020-01-20 17:03:42 DEBUG (MainThread) [insteonplm] Creating http connection
2020-01-20 17:03:42 DEBUG (MainThread) [insteonplm] Starting the reader in HttpTrasnport init
2020-01-20 17:03:42 DEBUG (MainThread) [insteonplm] create_http_connection Finished creating connection
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm] Test connection status is 200
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm] Starting the buffer reader
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm] ending Connection._connect
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm] ending Connection.reconnect
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm] Ending Connection.create
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm.linkedDevices] Added new callback <function async_setup..async_new_insteon_device at 0xb24c2588>
2020-01-20 17:03:44 INFO (MainThread) [insteonplm] Insteon Hub reader started
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm] …Clearing the buffer…
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm] Writing message: http://192.168.1.209:25105/1?XB=M=1
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm] Post status: 200
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm] Calling connection made
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm] Protocol: <insteonplm.plm.Hub object at 0xb23e5db0>
2020-01-20 17:03:44 INFO (MainThread) [insteonplm.plm] Connection established to Hub
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm.plm] Transport: <insteonplm.HttpTransport object at 0xb23f4eb0>
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm.plm] Starting Insteon Modem write message from send queue
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm.plm] Aquiring write lock
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm.linkedDevices] Loading saved device info.
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm.linkedDevices] Really Loading saved device info.
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm.linkedDevices] Saved device file not found
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm.plm] Found 0 saved devices
2020-01-20 17:03:44 INFO (MainThread) [insteonplm.plm] Requesting Insteon Modem Info
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm.plm] Queueing msg: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm.plm] Starting: _load_all_link_database
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm.plm] Starting: _get_first_all_link_record
2020-01-20 17:03:44 INFO (MainThread) [insteonplm.plm] Requesting ALL-Link Records
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm.plm] Queueing msg: {‘code’: 0x69, ‘acknak’: 0xNone}
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm.plm] Ending: _get_first_all_link_record
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm.plm] Ending: _load_all_link_database
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm.plm] Ending _setup_devices in IM
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm] …Writing a message…
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-01-20 17:03:44 DEBUG (MainThread) [insteonplm] Writing message: http://192.168.1.209:25105/3?0260=I=3
2020-01-20 17:03:46 DEBUG (MainThread) [insteonplm] Stop reading due to too many values to unpack (expected 2)
2020-01-20 17:03:46 DEBUG (MainThread) [insteonplm] Stopping the reader and reconnect is False
2020-01-20 17:03:47 INFO (MainThread) [insteonplm.plm] Stopping Insteon Modem writer due to CancelledError
2020-01-20 17:03:47 DEBUG (MainThread) [insteonplm.plm] Ending Insteon Modem write message from send queue
2020-01-20 17:03:47 INFO (MainThread) [insteonplm] Insteon Hub reader stopped

This is the issue but I have no idea why it would respond that way. Let me take a look. Can you confirm that you are using a hub version 2?

I am using a 2242-222 hub. I have tried resetting the hub but that has not changed the result. If I change to hub_version 1, I get the following. But, I don’t see any entities created for the devices.

2020-02-02 12:03:15 DEBUG (MainThread) [insteonplm] Starting Modified Connection.create
2020-02-02 12:03:15 DEBUG (MainThread) [insteonplm.devices] Registering messages for 00.00.00
2020-02-02 12:03:15 DEBUG (MainThread) [insteonplm.devices] ID ACK: {‘code’: 0x62, ‘address’: 00.00.00, ‘flags’: 0x00, ‘cmd1’: 0x10, ‘cmd2’: 0x00, ‘acknak’: 0x06}
2020-02-02 12:03:15 DEBUG (MainThread) [insteonplm] starting Connection.reconnect
2020-02-02 12:03:15 DEBUG (MainThread) [insteonplm] starting Connection._connect
2020-02-02 12:03:15 INFO (MainThread) [insteonplm] Connecting to Insteon Hub v1 on socket://192.168.1.209:25105
2020-02-02 12:03:15 DEBUG (MainThread) [insteonplm] ending Connection._connect
2020-02-02 12:03:15 DEBUG (MainThread) [insteonplm] ending Connection.reconnect
2020-02-02 12:03:15 DEBUG (MainThread) [insteonplm] Ending Connection.create
2020-02-02 12:03:15 DEBUG (MainThread) [insteonplm.linkedDevices] Added new callback <function async_setup..async_new_insteon_device at 0xb263e780>
2020-02-02 12:03:16 INFO (MainThread) [insteonplm.plm] Connection established to PLM
2020-02-02 12:03:17 DEBUG (MainThread) [insteonplm.plm] Starting Insteon Modem write message from send queue
2020-02-02 12:03:17 DEBUG (MainThread) [insteonplm.plm] Aquiring write lock
2020-02-02 12:03:17 DEBUG (MainThread) [insteonplm.linkedDevices] Loading saved device info.
2020-02-02 12:03:17 DEBUG (MainThread) [insteonplm.linkedDevices] Really Loading saved device info.
2020-02-02 12:03:17 DEBUG (MainThread) [insteonplm.linkedDevices] Saved device file not found
2020-02-02 12:03:17 DEBUG (MainThread) [insteonplm.plm] Found 0 saved devices
2020-02-02 12:03:17 INFO (MainThread) [insteonplm.plm] Requesting Insteon Modem Info
2020-02-02 12:03:17 DEBUG (MainThread) [insteonplm.plm] Queueing msg: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:17 DEBUG (MainThread) [insteonplm.plm] Starting: _load_all_link_database
2020-02-02 12:03:17 DEBUG (MainThread) [insteonplm.plm] Starting: _get_first_all_link_record
2020-02-02 12:03:17 INFO (MainThread) [insteonplm.plm] Requesting ALL-Link Records
2020-02-02 12:03:17 DEBUG (MainThread) [insteonplm.plm] Queueing msg: {‘code’: 0x69, ‘acknak’: 0xNone}
2020-02-02 12:03:17 DEBUG (MainThread) [insteonplm.plm] Ending: _get_first_all_link_record
2020-02-02 12:03:17 DEBUG (MainThread) [insteonplm.plm] Ending: _load_all_link_database
2020-02-02 12:03:17 DEBUG (MainThread) [insteonplm.plm] Ending _setup_devices in IM
2020-02-02 12:03:17 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:17 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:19 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:19 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:19 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:22 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:22 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:22 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:24 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:24 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:24 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:26 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:26 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:26 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:28 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:28 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:28 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:30 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:30 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:30 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:31 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
File “/usr/src/homeassistant/homeassistant/helpers/entity_platform.py”, line 355, in _async_add_entity
capabilities=entity.capability_attributes,
File “/usr/src/homeassistant/homeassistant/components/climate/init.py”, line 181, in capability_attributes
self.hass, self.min_temp, self.temperature_unit, self.precision
File “/usr/src/homeassistant/homeassistant/components/climate/init.py”, line 490, in min_temp
DEFAULT_MIN_TEMP, TEMP_CELSIUS, self.temperature_unit
File “/usr/src/homeassistant/homeassistant/util/temperature.py”, line 31, in convert
raise ValueError(UNIT_NOT_RECOGNIZED_TEMPLATE.format(to_unit, TEMPERATURE))
ValueError: None is not a recognized temperature unit.
2020-02-02 12:03:32 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:32 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:32 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:34 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:34 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:34 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:36 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:36 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:36 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:38 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:38 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:38 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:40 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:40 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:40 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:42 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:42 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:42 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:44 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:44 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:44 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:46 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:46 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:46 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:48 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:48 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:48 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:50 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:50 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:50 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:52 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:52 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:52 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message
2020-02-02 12:03:54 DEBUG (MainThread) [insteonplm.plm] No ACK or NAK message received.
2020-02-02 12:03:54 DEBUG (MainThread) [insteonplm.plm] TX: {‘code’: 0x60, ‘address’: 00.00.00, ‘category’: 0xNone, ‘subcategory’: 0xNone, ‘firmware’: 0xNone, ‘acknak’: 0xNone}
2020-02-02 12:03:54 DEBUG (MainThread) [insteonplm.plm] Waiting for ACK or NAK message

Your model is a hub version 2 so don’t bother with the version 1 config.

Try this:

  1. Open a web browser and open two tabs.
  2. In the first tab enter the following url:
    http://<hub_ip_address>:25105//buffstatus.xml
    When you see the login pop up enter the local username and password. Once that is accepted you should see something like this:
<?xml version="1.0" encoding="ISO-8859-1"?>
<response>
<BS>45E515313E1E2B0000027F0206027F0006027F0206027F00061E2100FF026214627A05190006025014627A313E1E2600000262133696051900060250133696313E1E2600FF0262470147051900060250470147313E1E2100FF026245E51505190006025032</BS>
</response>
  1. In the second tab enter the following URL:
    http://<hub_ip_address>:25105/3?0269=I=3
    You should not need to log in again. This tab will only display a blank page.

  2. Go back to the first tab and hit refresh. Send me what you see on this page after hitting refresh.

It appears we are hung up on step 2. I was prompted for the userid and password, entered those with no negative response. I was then presented with the following.

404: File not found
Use MPFS Upload to program web pages into EEPROM

Some additional info I pulled from the App.

Bin Version - Alert 2.6 YF
PLM Version - 9C
Hub Version - 4.8A Build Feb 08 2013

I suspect I am not on the latest version, but other than doing a restore and multiple taps of the reset button I can’t find a way to update it.

I think you may need to call SmartHome. That looks like you may have a corrupt firmware (But I am not really sure of this). My Hub app gives me this:

Bin Version: Hub2-V04-20140904
PLM Version: A4
Hub Version: 1018

The only other thing I can think of is to “force upgrade” your hub to the latest firmware. This can be done in the app by going to the Edit Settings screen and selecting:
House -> Update Hub2 -> Force Update

That’s the frustrating part. The App doesn’t give the option to update the device. I guess a call is required.