Insteon PLM - bad data received: got unknown command code 0x06

Hi,

I have recently started having trouble with my Insteon setup via OpenHAB2 (Release version).
I have debugging turned on and in the log I see bad data received: got unknown command code 0x06
Then a few seconds later I get modem database download unsuccessful, restarting!

Things I tried:

  • Using the latest snapshot binding org.openhab.binding.insteonplm-1.10.0-SNAPSHOT from 5/20/17
  • Factory resetting all 60+ devices and my PLM (2413S) then re-linking all devices
  • Restarting OH (multiple times)
  • Increasing the poll_interval to 600000 in the insteonplm.cfg
  • Adding modem_db_retry_timeout=240000 as per OH thread
  • Commanding devices via HouseLinc (I do not see the slowdown and lost messages which I assume is because the network is not flooded with poll messages)

After a restart things seem normal and if I command an Insteon device via OH then it works almost immediately, but then I look at the log and the problems begin, the ‘bad data’ seems to trigger a chain reaction which I think means the binding keeps commanding the PLM to restart the poll and the network becomes flooded. Commands are either lost or very slow to arrive at the devices and the log files just keep on growing as there are poll messages happening constantly.

The log snippet below is right after a restart and the usual startup messages have finished at 16:20. At 16:24 I command a fanlinc dimmer to 54, the physical light comes on almost immediately but then the problems begin.

2017-05-21 16:20:59 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0xF8|LinkAddr:33.0F.1C|LinkData1:0x01|LinkData2:0x00|LinkData3:0xF8|
2017-05-21 16:20:59 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-21 16:24:50 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.internalReceiveCommand(InsteonPLMActiveBinding.java:121) - Item: MainFloor_FamilyRoom__Fanlinc__Dimmer got command 54
2017-05-21 16:24:50 org.openhab.binding.insteonplm.internal.device.InsteonDevice.processCommand(InsteonDevice.java:241) - processing command 54 features: 3
2017-05-21 16:24:50 org.openhab.binding.insteonplm.internal.device.CommandHandler$PercentHandler.handleCommand(CommandHandler.java:557) - changing level of 2E.2B.13 to 54
2017-05-21 16:24:50 org.openhab.binding.insteonplm.internal.device.CommandHandler$PercentHandler.handleCommand(CommandHandler.java:563) - PercentHandler: sent msg to set 2E.2B.13 to 138
2017-05-21 16:24:50 org.openhab.binding.insteonplm.internal.device.RequestQueueManager$RequestQueueReader.run(RequestQueueManager.java:101) - starting request queue thread
2017-05-21 16:24:50 org.openhab.binding.insteonplm.internal.device.InsteonDevice.processRequestQueue(InsteonDevice.java:460) - qe taken off direct: GenericDimmer(1:3:8) OUT:Cmd:0x62|toAddress:2E.2B.13|messageFlags:0x0F=DIRECT:3:3|command1:0x11|command2:0x8A|
2017-05-21 16:24:50 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (500): OUT:Cmd:0x62|toAddress:2E.2B.13|messageFlags:0x0F=DIRECT:3:3|command1:0x11|command2:0x8A|
2017-05-21 16:24:50 org.openhab.binding.insteonplm.internal.device.InsteonDevice.processRequestQueue(InsteonDevice.java:480) - next request queue processed in 2000 msec, quiettime = 2000
2017-05-21 16:24:50 org.openhab.binding.insteonplm.internal.message.MsgFactory.bail(MsgFactory.java:125) - got unknown command code 0x06
2017-05-21 16:24:50 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamReader.processMessages(Port.java:295) - bad data received: got unknown command code 0x06
2017-05-21 16:24:50 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamReader.processMessages(Port.java:298) - got bad data back, must assume message was acked.
2017-05-21 16:24:51 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x50|fromAddress:2E.2B.13|toAddress:44.31.A5|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x11|command2:0x8A|
2017-05-21 16:24:51 org.openhab.binding.insteonplm.internal.device.InsteonDevice.handleMessage(InsteonDevice.java:306) - ----- applying message to feature: FanLincFan
2017-05-21 16:24:51 org.openhab.binding.insteonplm.internal.device.InsteonDevice.handleMessage(InsteonDevice.java:306) - ----- applying message to feature: GenericDimmer
2017-05-21 16:24:51 org.openhab.binding.insteonplm.internal.device.MessageDispatcher$DefaultDispatcher.dispatch(MessageDispatcher.java:154) - 2E.2B.13:GenericDimmer DIRECT_ACK: q:QUERY_PENDING cmd: 80
2017-05-21 16:24:51 org.openhab.binding.insteonplm.internal.device.MessageDispatcher$DefaultDispatcher.dispatch(MessageDispatcher.java:159) - changing key to 0x19 for msg IN:Cmd:0x50|fromAddress:2E.2B.13|toAddress:44.31.A5|messageFlags:0x2B=ACK_OF_DIRECT:3:2|command1:0x11|command2:0x8A|
2017-05-21 16:24:51 org.openhab.binding.insteonplm.internal.device.MessageHandler$DimmerRequestReplyHandler.handleMessage(MessageHandler.java:588) - DimmerRequestReplyHandler: set device 2E.2B.13 to level 54
2017-05-21 16:24:51 org.openhab.binding.insteonplm.internal.device.DeviceFeature.publish(DeviceFeature.java:321) - 2E.2B.13:GenericDimmer publishing: 54
2017-05-21 16:24:51 org.openhab.binding.insteonplm.internal.device.MessageDispatcher$DefaultDispatcher.dispatch(MessageDispatcher.java:181) - defdisp: 2E.2B.13:GenericDimmer set status to: QUERY_ANSWERED
2017-05-21 16:24:51 org.openhab.binding.insteonplm.internal.device.DeviceFeature.publish(DeviceFeature.java:321) - 2E.2B.13:GenericLastTime publishing: 2017-05-21T16:24:51
2017-05-21 16:24:52 org.openhab.binding.insteonplm.internal.device.RequestQueueManager$RequestQueueReader.run(RequestQueueManager.java:137) - device queue for 2E.2B.13 is empty!
2017-05-21 16:24:56 org.openhab.binding.insteonplm.internal.device.ModemDBBuilder.run(ModemDBBuilder.java:76) - modem database download unsuccessful, restarting!
2017-05-21 16:24:56 org.openhab.binding.insteonplm.internal.driver.Port.clearModemDB(Port.java:139) - clearing modem db!
2017-05-21 16:24:56 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x69|
2017-05-21 16:24:56 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:3D.F3.8C|LinkData1:0x01|LinkData2:0x00|LinkData3:0x00|

I am totally out of ideas, any help is greatly appreciated.
Thanks!

I’m most confused by the fact that the binding starts to operate before even the modem database download has finished? What gives? For a locally connected device such as the 2413S, the database download should happen within a few seconds.
Is it possible you are running two binding instances?

I don’t think I am… I checked PaperUI and the 1.9.0 InsteonPLM binding listed there shows uninstalled.
In my OpenHAB2\addons directory I have org.openhab.binding.insteonplm-1.10.0-SNAPSHOT.jar along with two other .jar files, one for the myQ binding and one for the zwave binding.

@Bernd_Pfrommer Is there any way to know for sure if there is more than one binding connected?

Have you tried using insteonterminal to just download the modem database?
Does that work?

I have been using houselinc for admin and testing. I will install Insteon terminal and report back…

hmm, well after much experimentation and fruitless googling, I have concluded that I have no idea how to get Insteon Terminal working on my Windows machine. I am clueless about Python and hopeless with Linux. All of the documentation is referring to Linux setups so I can’t even get it to run. I got as far as installing python, downloading Insteon-Terminal and creating an init.py (although I’m not sure what to put in the connectToSerial("/dev/insteon") function).
I can’t figure out how to even run ‘insteon-terminal’ since it isn’t a .py file… :confused:

I know this isn’t a support forum for the Insteon terminal so I’m back to being stuck again.

Since everything works fine in HouseLinc does that tell us anything useful or do I really need to somehow figure out how to get Insteon Terminal working for us to get any further?

1 Like

Not sure what data point I would get from InsteonTerminal working or not. The hope was that because it has much fewer moving parts than OH, you’d discover what the problem is in the process of getting InsteonTerminal to work.

Usually on Windows machines instead of “/dev/foo” you specify something like “COM5” or whatever port your modem is on.

Sorry that InsteonTerminal is not more user friendly, but it’s meant to be a developer tool, so some working knowledge of python is necessary.

Oh and here’s another test: Can you remove all items from all files (make a copy of your .items files first) and post the startup log? There should be no polling visible. I want to see the modem database download finish first.

Items deleted, OH restarted, log below - same bad data issue.
(had to clip parts of the log to fit the char limit on this forum, denoted by ‘…’)

2017-05-23 08:56:04  - BundleEvent STARTING - org.openhab.binding.insteonplm
2017-05-23 08:56:04 org.openhab.binding.insteonplm.InsteonPLMActivator.start(InsteonPLMActivator.java:37) - Insteon PLM binding has been started.
2017-05-23 08:56:04  - BundleEvent STARTED - org.openhab.binding.insteonplm
2017-05-23 08:56:04  - ServiceEvent REGISTERED - {org.openhab.model.item.binding.BindingConfigReader, org.openhab.binding.insteonplm.InsteonPLMBindingProvider}={component.name=org.openhab.binding.insteonplm.genericbindingprovider, component.id=248, service.id=426, service.bundleid=257, service.scope=bundle} - org.openhab.binding.insteonplm
2017-05-23 08:56:04 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.activate(InsteonPLMActiveBinding.java:154) - activating binding
2017-05-23 08:56:04 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.updated(InsteonPLMActiveBinding.java:269) - global binding config has arrived.
2017-05-23 08:56:04 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.processBindingConfiguration(InsteonPLMActiveBinding.java:287) - refresh interval set to 600s
2017-05-23 08:56:04 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.processBindingConfiguration(InsteonPLMActiveBinding.java:296) - poll interval set to 600000 per config file
2017-05-23 08:56:04  - ServiceEvent REGISTERED - {org.osgi.service.event.EventHandler, org.osgi.service.cm.ManagedService}={event.topics=openhab/command/*, service.pid=org.openhab.insteonplm, component.name=org.openhab.binding.insteonplm.activebinding, component.id=247, service.id=427, service.bundleid=257, service.scope=bundle} - org.openhab.binding.insteonplm
2017-05-23 08:56:04 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.s_instance(DeviceTypeLoader.java:205) - loaded 45 devices: 
2017-05-23 08:56:04 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.logDeviceTypes(DeviceTypeLoader.java:183) - 0x000041  ->pk:0x000041|model:2484DWH8|desc:KeypadLinc Countdown Timer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
2017-05-23 08:56:04 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.logDeviceTypes(DeviceTypeLoader.java:183) - F00.00.0A ->pk:F00.00.0A|model:2852-222|desc:Leak Sensor|features:contact=LeakSensorContact:lastheardfrom=GenericLastTime|groups
2017-05-23 08:56:04 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.logDeviceTypes(DeviceTypeLoader.java:183) - F00.00.0D ->pk:F00.00.0D|model:2634-222|desc:On/Off Dual-Band Outdoor Module|features:lastheardfrom=GenericLastTime:switch=GenericSwitch|groups
2017-05-23 08:56:04 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.logDeviceTypes(DeviceTypeLoader.java:183) - 0x000049  ->pk:0x000049|model:2843-222|desc:Wireless Open/Close Sensor|features:contact=GenericContact:lastheardfrom=GenericLastTime|groups
...
2017-05-23 08:56:04 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.logDeviceTypes(DeviceTypeLoader.java:183) - 0x00001A  ->pk:0x00001A|model:2450|desc:IO Link|features:contact=IOLincContact:lastheardfrom=GenericLastTime:switch=IOLincSwitch|groups
2017-05-23 08:56:04 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.logDeviceTypes(DeviceTypeLoader.java:183) - F00.00.17 ->pk:F00.00.17|model:2423A1|desc:iMeter Solo Power Meter|features:meter=PowerMeter:lastheardfrom=GenericLastTime|groups
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.processDevice(DeviceTypeLoader.java:113) - overwriting previous definition of device F00.00.01
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.processDevice(DeviceTypeLoader.java:113) - overwriting previous definition of device F00.00.02
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.processDevice(DeviceTypeLoader.java:113) - overwriting previous definition of device F00.00.03
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.processDevice(DeviceTypeLoader.java:113) - overwriting previous definition of device F00.00.1C
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.processDevice(DeviceTypeLoader.java:113) - overwriting previous definition of device F00.00.16
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.processBindingConfiguration(InsteonPLMActiveBinding.java:302) - read additional device definitions from C:\openHAB2\addons\insteonplm\more_devices.xml
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.processBindingConfiguration(InsteonPLMActiveBinding.java:310) - setting modem db retry timeout to 240s
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.processBindingConfiguration(InsteonPLMActiveBinding.java:315) - reading additional feature templates from C:\openHAB2\addons\insteonplm\more_features.xml
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.processBindingConfiguration(InsteonPLMActiveBinding.java:319) - dead device timeout set to 6000s
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.updated(InsteonPLMActiveBinding.java:273) - configuration update complete!
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:358) - initializing...
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:370) - config: poll_interval -> 600000
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:370) - config: modem_db_retry_timeout -> 240000
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:370) - config: port_0 -> COM3
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Driver.addPort(Driver.java:83) - added new port: port_0 COM3
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:370) - config: more_features -> C:\openHAB2\addons\insteonplm\more_features.xml
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:370) - config: refresh -> 600000
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:370) - config: more_devices -> C:\openHAB2\addons\insteonplm\more_devices.xml
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:370) - config: service.pid -> org.openhab.insteonplm
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:376) - setting driver listener
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:378) - starting 0 ports
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Port.start(Port.java:149) - starting port COM3
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.logDeviceStatistics(InsteonPLMActiveBinding.java:684) - devices:   0 configured,   0 polling, msgs received:     0
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Poller$PollQueueReader.run(Poller.java:188) - starting poll thread.
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.SerialIOStream.open(SerialIOStream.java:58) - setting port speed to 19200
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.SerialIOStream.open(SerialIOStream.java:65) - successfully opened port COM3
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.device.ModemDBBuilder.start(ModemDBBuilder.java:51) - querying port for first link record
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:380) - ports started
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:386) - initialization complete, found 1 port!
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Port.clearModemDB(Port.java:139) - clearing modem db!
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:406) - starting writer...
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x60|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamReader.run(Port.java:268) - starting reader...
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Port$Modem.msg(Port.java:479) - found modem 44.31.A5 in device_types: 44.31.A5|broadcastonoff->GroupBroadcastOnOff(0:1:0)
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x69|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:3D.F3.8C|LinkData1:0x01|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:3D.F3.8C|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:3D.F9.31|LinkData1:0x01|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:3D.F9.31|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:33.D4.8E|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x03|LinkAddr:33.D4.8E|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x04|LinkAddr:33.D4.8E|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x05|LinkAddr:33.D4.8E|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x06|LinkAddr:33.D4.8E|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0xF2|LinkAddr:33.D4.8E|LinkData1:0x01|LinkData2:0x00|LinkData3:0xF2|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0xF3|LinkAddr:33.D4.8E|LinkData1:0x01|LinkData2:0x00|LinkData3:0xF3|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0xF4|LinkAddr:33.D4.8E|LinkData1:0x01|LinkData2:0x00|LinkData3:0xF4|
...
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0xF6|LinkAddr:38.FC.C1|LinkData1:0x01|LinkData2:0x00|LinkData3:0xF6|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0xF7|LinkAddr:38.FC.C1|LinkData1:0x01|LinkData2:0x00|LinkData3:0xF7|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0xF8|LinkAddr:38.FC.C1|LinkData1:0x01|LinkData2:0x00|LinkData3:0xF8|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:32.33.C3|LinkData1:0x01|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:3C.DE.F7|LinkData1:0x01|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:3C.DE.F7|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:38.FD.00|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x03|LinkAddr:38.FD.00|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x04|LinkAddr:38.FD.00|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x05|LinkAddr:38.FD.00|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x06|LinkAddr:38.FD.00|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0xF2|LinkAddr:38.FD.00|LinkData1:0x01|LinkData2:0x00|LinkData3:0xF2|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0xF3|LinkAddr:38.FD.00|LinkData1:0x01|LinkData2:0x00|LinkData3:0xF3|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0xF4|LinkAddr:38.FD.00|LinkData1:0x01|LinkData2:0x00|LinkData3:0xF4|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0xF5|LinkAddr:38.FD.00|LinkData1:0x01|LinkData2:0x00|LinkData3:0xF5|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0xF6|LinkAddr:38.FD.00|LinkData1:0x01|LinkData2:0x00|LinkData3:0xF6|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0xF7|LinkAddr:38.FD.00|LinkData1:0x01|LinkData2:0x00|LinkData3:0xF7|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0xF8|LinkAddr:38.FD.00|LinkData1:0x01|LinkData2:0x00|LinkData3:0xF8|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:38.83.2A|LinkData1:0x01|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:38.83.2A|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:06 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:07 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:32.35.D9|LinkData1:0x01|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:07 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:07 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:3D.F9.D8|LinkData1:0x01|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:07 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:07 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:3D.F9.D8|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:07 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:07 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:34.D7.66|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:07 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:07 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x03|LinkAddr:34.D7.66|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:07 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:07 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x04|LinkAddr:34.D7.66|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:07 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 08:56:07 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x05|LinkAddr:34.D7.66|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:07 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 09:00:05 org.openhab.binding.insteonplm.internal.device.ModemDBBuilder.run(ModemDBBuilder.java:76) - modem database download unsuccessful, restarting!
2017-05-23 09:00:05 org.openhab.binding.insteonplm.internal.driver.Port.clearModemDB(Port.java:139) - clearing modem db!
2017-05-23 09:00:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x69|
2017-05-23 09:00:05 org.openhab.binding.insteonplm.internal.message.MsgFactory.bail(MsgFactory.java:125) - got unknown command code 0x06
2017-05-23 09:00:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamReader.processMessages(Port.java:295) - bad data received: got unknown command code 0x06
2017-05-23 09:00:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamReader.processMessages(Port.java:298) - got bad data back, must assume message was acked.
2017-05-23 09:00:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:3D.F3.8C|LinkData1:0x01|LinkData2:0x00|LinkData3:0x00|
2017-05-23 09:00:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 09:00:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:3D.F3.8C|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 09:00:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 09:00:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:3D.F9.31|LinkData1:0x01|LinkData2:0x00|LinkData3:0x00|
2017-05-23 09:00:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 09:00:05 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:3D.F9.31|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 09:00:05 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
...

Also, I was thinking about what you said about two bindings, after switching to the nightly build of the InsteonPLM binding and as per this post: Unresolved requirement: Import-Package: gnu.io

I had the serial binding installed. I uninstalled it and the InsteonPLM log showed 2017-05-23 08:23:43 - FrameworkEvent ERROR - org.openhab.binding.insteonplm org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.insteonplm [257] Unresolved requirement: Import-Package: gnu.io

This time I installed the Modbus binding just to see if that made any difference. That resolved the dependency issue but as you can see form the log above it didn’t solve the modem download issue.

Sorry if this is all unrelated fluff, I’m just trying to give as much info as possible :slight_smile:

Ok, so this log is significantly easier to understand.

I see the binding sending out 0x6A, then all of a sudden the modem does not respond to it anymore:

2017-05-23 08:56:07 org.openhab.binding.insteonplm.InsteonPLMActiveBinding$PortListener.msg(InsteonPLMActiveBinding.java:591) - got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x05|LinkAddr:34.D7.66|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2017-05-23 08:56:07 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x6A|
2017-05-23 09:00:05 org.openh

For 4 minutes the modem sends nothing back. That is unlikely to be a binding issue. Could well be hardware (I know, swapping out hardware is expensive and the last option because by Murphy’s law it later turns out to be software after a ll). Could the cable be bad or marginal? How old is the modem?

Modem is only 3 months old. I had another PLM that was on borrowed time so got this new one, unfortunately the old one is long gone
It has been working fine until this issue started a week or so ago. Still seems to work fine in Houslinc and even worked fine on my ISY for a couple of weeks before I kicked the ISY out of my life.

If you think it could be hardware then I can see about getting a replacement. Any theories on why it seems to only be a problem in openHAB? Maybe Houslinc is just masking the problem? I have done quite a bit of testing with houelinc and didn’t see any evidence of slowdown or lost messages.

I don’t know how houselinc manages the modem database. It may not be downloading it from the modem. In fact I know it has a tendency to overwrite whatever is on the modem with its own data (presumably stored on the PC’s hard drive).

There is also a chance that a single record of the modem is bad, and somehow that’s why it hangs during download. Does it always return exactly the same number of records before it hangs? But even if that is so, how can it be fixed. You said you completely reset the modem and it didn’t help.

This should not matter, but out of curiosity: why are you running on a serial port rather than using a usb-based PLM?

I did reset the modem and relink everything, after a few more experiments it looks like it is not always the same record that causes the problem. Also I had a couple of times where it would successfully download the modem DB. It worked ok for a while and them would get bad data or an ‘unexpected’ message.
Also during my experiments it has worked ok for a good period of time, downloading the DB ok and then controlling devices quickly. I then restarted OH and tried again only to have it fail on the modem DB download.

I think you may be right that it could be a hardware fault. I ordered a new PLM but it won’t be here for another week. I tried wiggling the connector cable into different positions, I don’t have a spare to test unfortunately.
I also tried a different USB to serial adapter, tried on different USB ports on the same machine and even tried on a different PC running a copy of the OH installation code, all showed similar erratic results eventually.

Since I couldn’t see a strong case for one vs the other, I went with another serial modem because I know it is compatible with the ISY and also I had a coupe of spare USB to serial adapters anyway. Is there an advantage to the USB over the Serial PLM?

USB vs serial shouldn’t make much difference, but it’s simpler to just have USB, eliminates the converter as a point of failure.

Come to think of it, another option could be that there is so much traffic on your insteon network (why?) that while the modem database download happens, another insteon message comes over the network and disrupts the download. Usually that’s not an issue because the download happens so fast.
You can test that hypothesis by powering your PLM with a battery backup (UPS) that is not connected to shoreline power.

Tried with my PML connected to my UPS. Pulled the plug from the wall socket and with UPS beeping and flashing started OH.

I tried twice and both times I got this in the log:

2017-05-25 09:52:13.173 [INFO ] [g.insteonplm.InsteonPLMActiveBinding] - config: service.pid -> org.openhab.insteonplm
2017-05-25 09:52:13.173 [INFO ] [b.core.service.AbstractActiveService] - InsteonPLM has been started
2017-05-25 09:52:13.188 [INFO ] [g.insteonplm.InsteonPLMActiveBinding] - devices:   3 configured,   0 polling, msgs received:     0
2017-05-25 09:52:13.376 [INFO ] [nding.insteonplm.InsteonPLMActivator] - Insteon PLM binding has been started.
2017-05-25 09:52:14.667 [INFO ] [onplm.internal.driver.SerialIOStream] - successfully opened port COM3
2017-05-25 09:52:19.796 [ERROR] [ding.insteonplm.internal.driver.Port] - reader thread exiting!
2017-05-25 09:54:14.684 [WARN ] [onplm.internal.device.ModemDBBuilder] - modem database download unsuccessful, restarting!

So still a failure but does this tell you anything new?

Why is the reader thread exiting? That didn’t happen before. Do you have debug logging switched on?

I messed up folder locations when I moved the install to a different server for testing and broke the debuggin, sorry.

Debugging reinstated. Tested with PLM connected to house power and validated that the same model DB download error occurred.

Tested again with PLM connected to UPS and UPS disconnected from mains power.

2017-05-25 10:13:52  - BundleEvent STARTING - org.openhab.binding.insteonplm
2017-05-25 10:13:52 org.openhab.binding.insteonplm.InsteonPLMActivator.start(InsteonPLMActivator.java:37) - Insteon PLM binding has been started.
2017-05-25 10:13:52  - BundleEvent STARTED - org.openhab.binding.insteonplm
2017-05-25 10:13:52  - ServiceEvent REGISTERED - {org.openhab.model.item.binding.BindingConfigReader, org.openhab.binding.insteonplm.InsteonPLMBindingProvider}={component.name=org.openhab.binding.insteonplm.genericbindingprovider, component.id=248, service.id=421, service.bundleid=257, service.scope=bundle} - org.openhab.binding.insteonplm
2017-05-25 10:13:52  - ServiceEvent REGISTERED - {org.osgi.service.event.EventHandler, org.osgi.service.cm.ManagedService}={event.topics=openhab/command/*, service.pid=org.openhab.insteonplm, component.name=org.openhab.binding.insteonplm.activebinding, component.id=247, service.id=423, service.bundleid=257, service.scope=bundle} - org.openhab.binding.insteonplm
2017-05-25 10:13:52 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.activate(InsteonPLMActiveBinding.java:154) - activating binding
2017-05-25 10:13:52 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.updated(InsteonPLMActiveBinding.java:269) - global binding config has arrived.
2017-05-25 10:13:52 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.processBindingConfiguration(InsteonPLMActiveBinding.java:287) - refresh interval set to 600s
2017-05-25 10:13:52 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.processBindingConfiguration(InsteonPLMActiveBinding.java:296) - poll interval set to 600000 per config file
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.s_instance(DeviceTypeLoader.java:205) - loaded 45 devices: 
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.logDeviceTypes(DeviceTypeLoader.java:183) - 0x000041  ->pk:0x000041|model:2484DWH8|desc:KeypadLinc Countdown Timer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.logDeviceTypes(DeviceTypeLoader.java:183) - F00.00.0A ->pk:F00.00.0A|model:2852-222|desc:Leak Sensor|features:contact=LeakSensorContact:lastheardfrom=GenericLastTime|groups
...
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.logDeviceTypes(DeviceTypeLoader.java:183) - F00.00.17 ->pk:F00.00.17|model:2423A1|desc:iMeter Solo Power Meter|features:meter=PowerMeter:lastheardfrom=GenericLastTime|groups
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.processDevice(DeviceTypeLoader.java:113) - overwriting previous definition of device F00.00.01
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.processDevice(DeviceTypeLoader.java:113) - overwriting previous definition of device F00.00.02
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.processDevice(DeviceTypeLoader.java:113) - overwriting previous definition of device F00.00.03
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.processDevice(DeviceTypeLoader.java:113) - overwriting previous definition of device F00.00.1C
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.device.DeviceTypeLoader.processDevice(DeviceTypeLoader.java:113) - overwriting previous definition of device F00.00.16
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.processBindingConfiguration(InsteonPLMActiveBinding.java:302) - read additional device definitions from C:\openHAB2\addons\insteonplm\more_devices.xml
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.processBindingConfiguration(InsteonPLMActiveBinding.java:310) - setting modem db retry timeout to 240s
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.processBindingConfiguration(InsteonPLMActiveBinding.java:315) - reading additional feature templates from C:\openHAB2\addons\insteonplm\more_features.xml
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.processBindingConfiguration(InsteonPLMActiveBinding.java:319) - dead device timeout set to 6000s
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.updated(InsteonPLMActiveBinding.java:273) - configuration update complete!
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:358) - initializing...
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:370) - config: poll_interval -> 600000
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:370) - config: modem_db_retry_timeout -> 240000
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:370) - config: port_0 -> COM3
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.logDeviceStatistics(InsteonPLMActiveBinding.java:684) - devices:   0 configured,   0 polling, msgs received:     0
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.driver.Poller$PollQueueReader.run(Poller.java:188) - starting poll thread.
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.driver.Driver.addPort(Driver.java:83) - added new port: port_0 COM3
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:370) - config: more_features -> C:\openHAB2\addons\insteonplm\more_features.xml
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:370) - config: refresh -> 600000
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:370) - config: more_devices -> C:\openHAB2\addons\insteonplm\more_devices.xml
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:370) - config: service.pid -> org.openhab.insteonplm
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:376) - setting driver listener
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:378) - starting 0 ports
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.driver.Port.start(Port.java:149) - starting port COM3
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.driver.SerialIOStream.open(SerialIOStream.java:58) - setting port speed to 19200
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.driver.SerialIOStream.open(SerialIOStream.java:65) - successfully opened port COM3
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamReader.run(Port.java:268) - starting reader...
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:406) - starting writer...
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.device.ModemDBBuilder.start(ModemDBBuilder.java:51) - querying port for first link record
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:380) - ports started
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.driver.Port$IOStreamWriter.run(Port.java:415) - writing (0): OUT:Cmd:0x60|
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.initialize(InsteonPLMActiveBinding.java:386) - initialization complete, found 1 port!
2017-05-25 10:13:53 org.openhab.binding.insteonplm.internal.driver.Port.clearModemDB(Port.java:139) - clearing modem db!
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.bindingChanged(InsteonPLMActiveBinding.java:215) - item MainFloor_Kitchen_South__Keypad_ButtonF__Switch binding changed: addr=33.0F.3F|prodKey:F00.00.16|feature:keypadbuttonF|params:group=0xD6
...
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.bindingChanged(InsteonPLMActiveBinding.java:215) - item MainFloor_BathroomMaster_BankMiddle_Bay1__Keypad_ButtonB__Switch binding changed: addr=34.D7.66|prodKey:F00.00.14|feature:keypadbuttonB|params:group=0xE2
2017-05-25 10:13:53 org.openhab.binding.insteonplm.InsteonPLMActiveBinding.bindingChanged(InsteonPLMActiveBinding.java:215) - item TopFloor_BedroomSide__LampLinc__FastOnOff binding changed: addr=26.94.7D|prodKey:F00.00.19|feature:fastonoff

Not sure if this means it worked?
I tried twice and got the same results.

Also, slightly unrelated, since the PLM is dual-band, why is it unable to communicate when not connected tot he mains power? Can’t it use the wireless connection in this case?

This doesn’t look good. I don’t see any reply from the modem.

At this point I am sort of hoping it is a hardware problem.

Pretty disappointing since I ditched my old PLM for this new one to try to avoid the impending capacitor 2.5 year lifespan curse, but at least it would explain this seemingly unexplainable behaviour.

The new PLM is supposed to arrive next Wednesday although they still haven’t shipped it yet. Are you thinking it is best to wait for that to arrive and hopefully eliminate the hardware variable before continuing with the investigation?

Yeah, I don’t know either how to make progress.