Need help with insteonplm binding on latest OH 2 snapsot [SOLVED]

Hello,

I’m a new user here. I have openhabian installed on an rpi 3 running the latest apt-get upgrade as of 12/30/2016.

I’m having two separate problems with Openhap and the insteonplm binding.

I’m (unfortunately) using the 2245-222 (hub2) hub. My home has 58 insteon devices, mostly switchlinc dimmers but a few other things as well.

My first problem is that the insteonplm binding is not successrul downloading the modem database. It will fail for a very long time (hours), then eventually download a portion of the database, somewhere from 3 to 30 items or so.

Here’s a portion of a log:

02:02:23.886 [INFO ] [g.insteonplm.InsteonPLMActiveBinding] - config: port_0 -> /hub2/xxxxxxx:xxxxxxx@192.168.1.27:25105,poll_time=1000
02:02:23.907 [INFO ] [b.core.service.AbstractActiveService] - InsteonPLM has been started
02:04:18.243 [WARN ] [steonplm.internal.message.MsgFactory] - incoming message does not start with 0x02
02:04:18.246 [WARN ] [ding.insteonplm.internal.driver.Port] - bad data received: incoming message does not start with 0x02
02:04:18.248 [WARN ] [ding.insteonplm.internal.driver.Port] - got bad data back, must assume message was acked.
02:04:24.173 [WARN ] [onplm.internal.device.ModemDBBuilder] - modem database download unsuccessful, restarting!
02:06:24.175 [WARN ] [onplm.internal.device.ModemDBBuilder] - modem database download unsuccessful, restarting!
02:08:24.177 [WARN ] [onplm.internal.device.ModemDBBuilder] - modem database download unsuccessful, restarting!
02:10:24.179 [WARN ] [onplm.internal.device.ModemDBBuilder] - modem database download unsuccessful, restarting!
02:12:23.994 [INFO ] [g.insteonplm.InsteonPLMActiveBinding] - devices:   0 configured,   0 polling, msgs received:   594

It will continue like that for a long time. Always showing a large number of messages received. Once it gets a partial DB download, the message count goes way down and will only be a few every polling cycle unless I go around flipping switches.

I know the hub works fine as I can send curl messages to it to directly turn switches on and off etc. It also works fine with either the insteon app on an ipad or via an Amazon echo.

According to the resolution of bug #4630 ( https://github.com/openhab/openhab/issues/4630 ) I would think this should be functional.

My second question is much more simple. I’m having trouble creating properly formatted things for it.
a near copy of the switch example from the insteonplm wiki results in a “check not null” failure loading the thing.

Switch denLight "den light" { insteonplm="42.32.78:F00.00.02#switch" }

What’s wrong with this format?

Thanks,
Scott

Edit: The download problem was resolved by increasing the ModemDB download timeout. by adding an entry in the insteonplm.cfg file.

modem_db_retry_timeout=240000

The Switches and dimmers needed to be defined as “items”, not “things”.

1 Like

Hi, I can’t help you with your first problem, but for the item definition you have to use the corresponding channel which you can copy from the thing config.

Have a look in Paper UI -> Configuration -> Things an click on your insteon thing. There you can see the available channels, underneath the name of the channel you can see the channel identifier. Copy this string and insert it in your config file like this:

Switch name "name" { channel="COPIED_STRING" }

where COPIED_STRING is the identifier you copied from Paper UI

Christian

Just a guess did are you using OpenJDK? I know that the InsteonPLM binding requires Oracle Java. What do you see when you run the command “java -version”? I have Oracle Java and I’m getting:

$ java -version
java version "1.8.0_111"
Java(TM) SE Runtime Environment (build 1.8.0_111-b14)
Java HotSpot(TM) Client VM (build 25.111-b14, mixed mode) 

Where are you putting your item? It needs to be put in a items file. Here’s an example of one that works for me:

Switch kitchen "Kitchen"  {insteonplm="24.31.81:F00.00.12#switch"}

A simpler way to determine if Oracle Java is “$ java -XshowSettings:properties -version 2>&1 | grep ‘java.vendor’”. Here’s what I get:

$ java -XshowSettings:properties -version 2>&1 | grep 'java.vendor'
    java.vendor = Oracle Corporation
    java.vendor.url = http://java.oracle.com/
    java.vendor.url.bug = http://bugreport.sun.com/bugreport/

Thanks for your help guys.

I verified that I have oracle Java. It’s the same 1.8.0_111 -b14 version as you have Rob.

I installed the insteonplm binding using Paper, but it doesn’t show up as a binding under Paper->Configuration->Bindings or Paper->Configuration->Things->+

It does show up as installed under Paper->Add-Ons

It seems I need to do something more to properly install the binding.

Is it possible to try OH 1 and make sure it works there? @Bernd_Pfrommer, do you have any suggestions?

This is really weird. Is it the number of devices? I have a hub, but since I’m running off the PLM modem for “production” use, and only use the hub2 for testing, I don’t think I ever linked more than 10 devices. I don’t recall getting any mangled messages for the hub2 (this was a problem for the old hub, but shouldn’t happen with hub2).

Scott, you may want to go low level and use the InsteonTerminal (search for that on github). It’s what I use to debug at the device level. It is much more primitive than openhab. If that doesn’t work then something is really screwed up at the communication level already.

I am having the same issues that Scott is having on my rpi3 running the latest snapshot.

My hub works properly using OH1 with the 1.8.3 binding. I haven’t tried putting the 1.9.0-SNAPSHOT binding on my OH1 server for testing. Once I do, I will post my results.

I installed InsteonTerminal on my main linux server (running ubuntu 16.04), and configured it for the Hub2.

It’s able to correctly download the full modem database. I used modem.saveDB() to save that to a file, then went through and verified that all devices are present.

I’m glad to hear that someone else is having the same issue.

To configure the modem in InsteonTerminal, I needed to enter the insteon ID for the hub itself, but I have not entered that anywhere for the the insteonplm binding. Perhaps that’s the missing link.

Scott,

After you install the InsteonPLM binding OH2 creates the /conf/services/insteonplm.cfg . In the file you input your hub IP and username and password.

Right, I’ve done that. What I’m talking about is the insteon ID for the modem in the hub (3 pairs of hex digits).

I’m still using OH 1 for my production env, but I tried the latest OH2 beta and it runs with no issues with a PLM with 60 devices. I also fixed 4630, and all this did was fix a runtime issue by bundling in the same apache httpclient jar file that OH 1 uses.

I just tried using the 1.9.0 binding in my OH1 instance. It worked for me there. Oddly, after I tried that, my OH2 started to download the database from the hub without problem.

I think my issue may have been a conflict of running OH1 and OH2 on the same server with different versions of the binding. I’ve shutdown the OH1 and restarted OH2 and no longer having an issue.

Yeah, no idea what will happen if you run two bindings at the same time. They will be sending polls to the same hub … shudder.

I used the InsteonTerminal to remove a stale device from the modem’s table, but that didn’t resolve anything.

It seems like the binding is running while it’s trying to download the modem database, because I get sequences like this:

16:03:52.644 [WARN ] [onplm.internal.device.ModemDBBuilder] - modem database download unsuccessful, restarting!
16:05:52.647 [WARN ] [onplm.internal.device.ModemDBBuilder] - modem database download unsuccessful, restarting!
16:07:52.649 [WARN ] [onplm.internal.device.ModemDBBuilder] - modem database download unsuccessful, restarting!
16:09:52.651 [WARN ] [onplm.internal.device.ModemDBBuilder] - modem database download unsuccessful, restarting!
16:11:52.377 [INFO ] [g.insteonplm.InsteonPLMActiveBinding] - devices:   0 configured,   0 polling, msgs received:   616
16:11:52.653 [WARN ] [onplm.internal.device.ModemDBBuilder] - modem database download unsuccessful, restarting!
16:13:52.655 [WARN ] [onplm.internal.device.ModemDBBuilder] - modem database download unsuccessful, restarting!
16:15:52.657 [WARN ] [onplm.internal.device.ModemDBBuilder] - modem database download unsuccessful, restarting!
16:17:52.660 [WARN ] [onplm.internal.device.ModemDBBuilder] - modem database download unsuccessful, restarting!
16:19:52.662 [WARN ] [onplm.internal.device.ModemDBBuilder] - modem database download unsuccessful, restarting!
16:21:52.380 [INFO ] [g.insteonplm.InsteonPLMActiveBinding] - devices:   0 configured,   0 polling, msgs received:   616
16:21:52.664 [WARN ] [onplm.internal.device.ModemDBBuilder] - modem database download unsuccessful, restarting!   

Under InsteonTerminal, it takes a couple of minutes to download the database but it succeeds every time. It’s like the version in the binding is doing about the same but fails. Is there any additional debug available for modem database download phase?

Is it perhaps hitting a timeout?

Edit: this time, after about 35 minutes it succeeded in a complete download.

Later, I’ll try starting openhab up with my echos powered off.

In the source, file: ModemDBBuilder.java I found the following which would completely explain my problem:

private int m_timeoutMillis = 120000;

Doubling that timeout would almost certainly work for me as the insteonTerminal program completes the download in about 2 minutes and 13 seconds on my 4.4GHz Ivy bridge server. I would guess a system with more devices would take even longer though.

How difficult is it to set up an environment to do test builds? It looks like the code is pre-compiled, as I can’t see a file of that name on my target system.

By the way, powering down my Amazon Echos doesn’t seem to make any significant difference as to how long this takes.

Although I’m an experienced kernel guy, I know nothing about java.

1 Like

Nice find. The simplest approach would be clone the git repo (https://github.com/openhab/openhab), make sure you have maven installed, go to openhab/bundles/binding/org.openhab.binding.insteonplm and run ‘mvn clean install’, and you should have a jar file in the target directory.

If you want an IDE set up, you can follow the instructions at: http://docs.openhab.org/developers/contributing/contributing

Thank you! I was able to compile the code, but better yet, it turns out there’s a built-in config setting for this:

I put the following in my insteonplm.cfg file and the DB successfully downloads first time.

modem_db_retry_timeout=240000

Now I can move on to the task of configuring my items.

1 Like

Good news, @Bernd_Pfrommer do you think the default timeout should be increased? BTW, I’m surprised that the message modem db builder thread interrupted isn’t in the log file. If you look at https://github.com/openhab/openhab/blob/master/bundles/binding/org.openhab.binding.insteonplm/src/main/java/org/openhab/binding/insteonplm/internal/device/ModemDBBuilder.java#L65 it has:

@Override
public void run() {
    logger.trace("starting modem db builder thread");
    while (!isComplete()) {
        startDownload();
        try {
            Thread.sleep(m_timeoutMillis); // wait for download to complete
        } catch (InterruptedException e) {
            logger.warn("modem db builder thread interrupted");
            break;
        }
        if (!isComplete()) {
            logger.warn("modem database download unsuccessful, restarting!");
        }
    }
    logger.trace("exiting modem db builder thread");
}

I think the InterruptedException will only kick in when the thread is really interrupted, not when the timeout expires (which is what evidently happens here).

Should we bump the default timeout? I don’t know. I’m not sure the rest of Scott’s setup is correct, and I don’t want to bump the default timeout, thereby masking other setup problems (although I have no idea what possibly could cause such a slowdown). My sense is that it should easily download the full database in a few seconds. Why does it take so long? Maybe Scott can investigate using the InsteonTerminal. What is the bottleneck? I should also compare this to the download speed I’m seeing with my hub but I know that’s not gonna happen because I’m too busy.