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?
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âŠ
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?
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.
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
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.
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?
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?
