[SOLVED] Help with InsteonPLM

Hello,

I am running openHAB 1.8 on a BananaPro board running Raspbian. I have the BananaPro running an SSD and successfully moved the OS over to the SDD and boot off that now. From an OS/board perspective, everything is running great.

I have an Insteon USB PLM 2413U hardware rev 2.1 and a 2457D2 dimmer I’d like to get running on openHab. I’ve linked the Insteon gear manually and also tested it with HomeLinc on my Win10 machine. Everything works great on Win10 aside from the fact that HomeLinc appears to be a bit dated and took some hacking to detect my modem. (My PLM hardware revision seems to be too new for HomeLinc. I had read in another forum that HomeLinc was deprecated.)

I installed openHAB via apt-get, installed the Insteon binding, configured my sitemap and items and nothing works. I’m not seeing any errors in the logs. I’m hoping someone can give me some pointers of what to try next.

Here are some of the things I’ve looked at so far:

I verified that my PLM is on ttyUSB0. I didn’t create a symlink yet. I only have 1 USB device plugged in (the PLM) and it hasn’t changed on reboot.

bananapi@lemaker ~ $ dmesg | grep tty
[    0.000000] Kernel command line: console=ttyS0,115200 console=tty0 consoleblank=0 disp.screen0_output_mode=EDID:1280x720p60 hdmi.audio=EDID:0 root=/dev/sda1 rootfstype=ext4 elevator=deadline rootwait
[    0.000000] console [tty0] enabled
[    0.695641] sunxi-uart.0: ttyS0 at MMIO 0x1c28000 (irq = 33) is a U6_16550A
[    1.362597] console [ttyS0] enabled
[    1.402845] sunxi-uart.2: ttyS1 at MMIO 0x1c28800 (irq = 35) is a U6_16550A
[    1.446470] sunxi-uart.4: ttyS2 at MMIO 0x1c29000 (irq = 49) is a U6_16550A
[    1.490087] sunxi-uart.7: ttyS3 at MMIO 0x1c29c00 (irq = 52) is a U6_16550A
[   16.320377] usb 3-1: FTDI USB Serial Device converter now attached to ttyUSB0

bananapi@lemaker ~ $ grep 'usb 3-1' /var/log/syslog.1
Jan 28 15:51:20 lemaker kernel: [    2.434308] usb 3-1: new full-speed USB device number 2 using sw-ohci
Jan 28 15:51:20 lemaker kernel: [    2.704618] usb 3-1: New USB device found, idVendor=0403, idProduct=6001
Jan 28 15:51:20 lemaker kernel: [    2.781788] usb 3-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Jan 28 15:51:20 lemaker kernel: [    2.792265] usb 3-1: Product: FT232R USB UART
Jan 28 15:51:20 lemaker kernel: [    2.817635] usb 3-1: Manufacturer: FTDI
Jan 28 15:51:20 lemaker kernel: [    2.963012] usb 3-1: SerialNumber: A403KEYW
Jan 28 15:51:20 lemaker kernel: [   16.220940] usb 3-1: Detected FT232RL
Jan 28 15:51:20 lemaker kernel: [   16.261143] usb 3-1: Number of endpoints 2
Jan 28 15:51:20 lemaker kernel: [   16.320666] usb 3-1: Endpoint 1 MaxPacketSize 64
Jan 28 15:51:20 lemaker kernel: [   16.364157] usb 3-1: Endpoint 2 MaxPacketSize 64
Jan 28 15:51:20 lemaker kernel: [   16.382376] usb 3-1: Setting MaxPacketSize 64
Jan 28 15:51:20 lemaker kernel: [   16.415491] usb 3-1: FTDI USB Serial Device converter now attached to ttyUSB0

I think I am OK from an OS/driver spective. I ran the command below and hit some buttons on the dimmer and got some output.

bananapi@lemaker ~ $ stty raw -echo < /dev/ttyUSB0; cat -vte /dev/ttyUSB0
^AM-D^M^@^KM-p^AM-D^M^@^KM-p^AM-DM-MM-^B^@M-p^AM-D^M^@+M-p^AM-D^M^@^KM-p^AM-D^M^@^KM-p^AM-DM-MM-^B^@M-p^AM-D^M^@+M-p^AM-D^M^@+M-p^AM-D^M^@+M-p^AM-DM-MM-^B M-p^AM-D-^@+M-p^AM-D^M^@^KM-p^AM-D^M^@^KM-p^AM-DM-MM-^B^@M-p^AM-D^M^@+M-p^AM-D^M^@+M-p^AM-D^M^@+M-p^AM-DM-MM-^B M-p^AM-D-^@+M-p^AM-D^M^@^KM-p^AM-D^M^@^KM-p^AM-DM-MM-^B^@M-p^AM-D^M^@+M-p^AM-D^M^@+M-p^AM-D^M^@+M-p^AM-DM-MM-^B M-p^AM-D-^@+M-p^C

I had read in other threads that premissions to /dev/ttyUSB0 could be a problem. I think don’t I have issues there.

bananapi@lemaker ~ $ ls -ld /dev/ttyUSB0
crw-rw---T 1 root dialout 188, 0 Jan 28 15:51 /dev/ttyUSB0

bananapi@lemaker ~ $ grep 'dialout' /etc/group
dialout:x:20:bananapi,openhab

I tried adding the SerialPort setting to the java args in the startup script:

bananapi@lemaker ~ $ less /etc/init.d/openhab 
...
JAVA_ARGS_DEFAULT="-Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0 \
 -Dosgi.clean=true \
 -Declipse.ignoreApp=true \
 -Dosgi.noShutdown=true \
 -Djetty.port=${HTTP_PORT} \
...

Here’s what I see in the openHAB and insteon logs:

bananapi@lemaker ~ $ less /var/log/openhab/openhab.log 
2016-01-28 15:56:15.128 [INFO ] [.o.core.internal.CoreActivator] - openHAB runtime has been started (v1.8.0).
2016-01-28 15:56:22.553 [INFO ] [o.o.i.s.i.DiscoveryServiceImpl] - mDNS service has been started
2016-01-28 15:56:22.758 [INFO ] [o.o.i.s.i.DiscoveryServiceImpl] - Service Discovery initialization completed.
2016-01-28 15:56:28.820 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'insteon.items'
2016-01-28 15:56:40.289 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'default.sitemap'
2016-01-28 15:56:40.289 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'default.sitemap'
2016-01-28 15:56:42.339 [INFO ] [penhab.io.rest.RESTApplication] - Started REST API at /rest
2016-01-28 15:56:47.923 [INFO ] [.o.u.w.i.servlet.WebAppServlet] - Started Classic UI at /classicui/openhab.app
2016-01-28 15:56:56.216 [INFO ] [.service.AbstractActiveService] - InsteonPLM has been started

bananapi@lemaker ~ $ less /var/log/openhab/insteonplm.log
2016-01-28 15:56:56.042 INFO  o.o.b.i.InsteonPLMActivator[:34] - Insteon PLM binding has been started.
2016-01-28 15:56:56.139 TRACE o.o.b.i.InsteonPLMGenericBindingProvider[:78] - processing item "TestDimmer" read from .items file with cfg string 35.38.F6:F00.00.19#dimmer
2016-01-28 15:56:56.192 DEBUG o.o.b.i.InsteonPLMActiveBinding[:158] - activating binding
2016-01-28 15:56:56.197 DEBUG o.o.b.i.InsteonPLMActiveBinding[:265] - global binding config has arrived.
2016-01-28 15:56:56.200 INFO  o.o.b.i.InsteonPLMActiveBinding[:290] - poll interval set to 300000 per config file
2016-01-28 15:56:56.202 INFO  o.o.b.i.InsteonPLMActiveBinding[:304] - setting modem db retry timeout to 120s
2016-01-28 15:56:56.204 INFO  o.o.b.i.InsteonPLMActiveBinding[:313] - dead device timeout set to 3000s
2016-01-28 15:56:56.205 DEBUG o.o.b.i.InsteonPLMActiveBinding[:269] - configuration update complete!
2016-01-28 15:56:56.209 DEBUG o.o.b.i.InsteonPLMActiveBinding[:352] - initializing...
2016-01-28 15:56:56.211 INFO  o.o.b.i.InsteonPLMActiveBinding[:364] - config: modem_db_retry_timeout -> 120000
2016-01-28 15:56:56.212 INFO  o.o.b.i.InsteonPLMActiveBinding[:364] - config: poll_interval -> 300000
2016-01-28 15:56:56.214 INFO  o.o.b.i.InsteonPLMActiveBinding[:364] - config: service.pid -> org.openhab.insteonplm
2016-01-28 15:56:56.219 INFO  o.o.b.i.InsteonPLMActiveBinding[:364] - config: port_0 -> /dev/ttyUSB0
2016-01-28 15:56:56.232 INFO  o.o.b.i.InsteonPLMActiveBinding[:670] - devices:   0 configured,   0 polling, msgs received:     0
2016-01-28 15:56:56.235 DEBUG o.o.b.i.internal.driver.Poller[:176] - starting poll thread.

And lastly, here is my openHAB config:

bananapi@lemaker ~ $ less /etc/openhab/configurations/openhab.cfg
...
insteonplm:port_0=/dev/ttyUSB0
insteonplm:poll_interval=300000
insteonplm:modem_db_retry_timeout=120000
...

bananapi@lemaker ~ $ less /etc/openhab/configurations/sitemaps/default.sitemap 
sitemap default label="Lions' Den"
{
   Frame {
      Group item=gTF label="Top Floor" icon="firstfloor"
      Group item=gMF label="Main Floor" icon="groundfloor"
      Group item=gBM label="Basement" icon="cellar"
      Group item=gOD label="Outdoors" icon="garden"
   }
}               

bananapi@lemaker ~ $ less /etc/openhab/configurations/items/insteon.items 
/* Group Definitions */
Group All
Group gTF       (All)
Group gMF       (All)
Group gBM       (All)
Group gOD       (All)

Group gTF_Office        "Office"        <office>        (gTF)

/* Office Group */
/* Insteon 2457D2 Lamp Dimmer */
Dimmer TestDimmer "Test Dimmer" (gTF_Office) {insteonplm="35.38.F6:F00.00.19#dimmer"}

On my openHab site, I can drill into Top Floor > Office and see my dimmer. The slider for the dimmer doesn’t move. Any suggestions for what to look at next?

Thanks!

Among the most qualified, detailed, and to-the-point requests for help I’ve ever seen, congratulations.

Unfortunately this means you’ve covered the usual bases. I can’t make sense of the debug log. There are some messages that I was hoping for but don’t see.

My instinct tells me you can read source code, so here’s what bugs me: some of your logging line numbers do not agree with the 1.8 source tree. I don’t see output from lines like this:

logger.debug("starting {} ports", m_driver.getNumberOfPorts());

Also the line numbers posted in your debug log don’t line up. Is it possible you are running some older version of the binding? Check that you have the right jar file, if all else fails download the latest from cloudbees.

private void initialize() {
        logger.debug("initializing...");

        HashSet<String> ports = new HashSet<String>();

        // Initialize ports
        for (Map.Entry<String, String> e : m_config.entrySet()) {
            String name = e.getKey();
            String port = e.getValue();
            if (ports.contains(port)) {
                logger.warn("port {} {} already in use, check config!", name, port);
                continue;
            }
            logger.info("config: {} -> {}", name, port);
            if (name.startsWith("port_")) {
                m_driver.addPort(name, port);
                m_driver.addMsgListener(m_portListener, port);
            }
        }
        logger.debug("setting driver listener");
        m_driver.setDriverListener(m_portListener);
        logger.debug("starting {} ports", m_driver.getNumberOfPorts());
        m_driver.startAllPorts();
        logger.debug("ports started");
        switch (m_driver.getNumberOfPorts()) {
            case 0:
                logger.error("initialization complete, but found no ports!");
                break;
            case 1:
                logger.debug("initialization complete, found 1 port!");
                break;
            default:
                logger.warn("initialization complete, found {} ports.", m_driver.getNumberOfPorts());
                break;
        }
    }

Full source file is here:

Thank you. I saw that you had posted in many of the other Insteon threads and was hoping you’d see this one.

Yes, I am a software engineer by day although I haven’t written Java professional for about 10 years. I will try to compile my own binding and report back in a few days.

Also, another clue: I couldn’t get Insteon Terminal to compile on my system. I’m wondering if I have an issue with Java.

bananapi@lemaker ~ $ java -version
java version "1.6.0_36"
OpenJDK Runtime Environment (IcedTea6 1.13.8) (6b36-1.13.8-1~deb7u1+rpi1)
OpenJDK Zero VM (build 23.25-b01, mixed mode)

root@lemaker:/opt/insteon-terminal# ant compile
Buildfile: /opt/insteon-terminal/build.xml

compile:
    [javac] Compiling 51 source files to /opt/insteon-terminal/bin
    [javac] /opt/insteon-terminal/src/us/pfrommer/insteon/emulator/network/modem/ModemSE.java:200:
')' expected
    [javac]                                     byte flag = (byte) (0b10000010 & 0xFF);
    [javac]                                                          ^
    [javac] /opt/insteon-terminal/src/us/pfrommer/insteon/emulator/network/modem/ModemSE.java:200:
illegal start of expression
    [javac]                                     byte flag = (byte) (0b10000010 & 0xFF);
    [javac]                                                                    ^
    [javac] /opt/insteon-terminal/src/us/pfrommer/insteon/emulator/network/modem/ModemSE.java:200:
';' expected
    [javac]                                     byte flag = (byte) (0b10000010 & 0xFF);
    [javac]                                                                     ^
    [javac] /opt/insteon-terminal/src/us/pfrommer/insteon/emulator/network/modem/ModemSE.java:200:
illegal start of expression
    [javac]                                     byte flag = (byte) (0b10000010 & 0xFF);
    [javac]                                                                          ^
    [javac] /opt/insteon-terminal/src/us/pfrommer/insteon/emulator/network/modem/ModemSE.java:202:
';' expected
    [javac]                                             flag |= 0b01000000;
    [javac]                                                      ^
    [javac] /opt/insteon-terminal/src/us/pfrommer/insteon/emulator/network/modem/ModemSE.java:236:
')' expected
    [javac]                                     byte flag = (byte) (0b10000010 & 0xFF);
    [javac]                                                          ^
    [javac] /opt/insteon-terminal/src/us/pfrommer/insteon/emulator/network/modem/ModemSE.java:236:
illegal start of expression
    [javac]                                     byte flag = (byte) (0b10000010 & 0xFF);
    [javac]                                                                    ^
    [javac] /opt/insteon-terminal/src/us/pfrommer/insteon/emulator/network/modem/ModemSE.java:236:
';' expected
    [javac]                                     byte flag = (byte) (0b10000010 & 0xFF);
    [javac]                                                                     ^
    [javac] /opt/insteon-terminal/src/us/pfrommer/insteon/emulator/network/modem/ModemSE.java:236:
illegal start of expression
    [javac]                                     byte flag = (byte) (0b10000010 & 0xFF);
    [javac]                                                                          ^
    [javac] /opt/insteon-terminal/src/us/pfrommer/insteon/emulator/network/modem/ModemSE.java:238:
';' expected
    [javac]                                             flag |= 0b01000000;
    [javac]                                                      ^
    [javac] 10 errors

BUILD FAILED
/opt/insteon-terminal/build.xml:45: Compile failed; see the compiler
error output for details.

Total time: 5 seconds
root@lemaker:/opt/insteon-terminal# java -version
java version "1.6.0_36"
OpenJDK Runtime Environment (IcedTea6 1.13.8) (6b36-1.13.8-1~deb7u1+rpi1)
OpenJDK Zero VM (build 23.25-b01, mixed mode)
root@lemaker:/opt/insteon-terminal#

Hi,
I probably should’ve mentioned it in the insteon terminal docs, but the insteon terminal requires Java 7+ to compile (the 0b* syntax is a binary literal, which was introduced in Java 7). I plan to make the program Java 6 compatible, but, for the moment, upgrading to Java 7 should do the trick.

(Also: Thanks for providing the java -version printout)

Hi @MrGoose404, I have the original Banana Pi, and use Bananian (https://www.bananian.org/), with no problems, also with an ssd drive. A month or two ago, somebody else was having problems with Raspbian and I think they solved their problem by switching to Bananian.

Rob

Here’s some of my notes that might help:

Installing Java (as root):

   echo "deb http://ppa.launchpad.net/webupd8team/java/ubuntu wily main" > /etc/apt/sources.list.d/webupd8team-java.list
   apt-key adv --keyserver hkp://keyserver.ubuntu.com:80 --recv-keys EEA14886
   apt-get update
   apt-get install oracle-java8-installer

I also added the user who runs openhab the dialout group:

crw-rw---- 1 root dialout 188, 0 Jan 29 17:44 /dev/ttyUSB0

You don’t really have to compile the code yourself, although that will make sure you know what source code goes with your binary. Downloading and installing the insteonplm jar file from cloudbees should be sufficient. Because the line numbers in the log file are off, I’m almost certain you are not running the prescribed binary.
There is also a chance that an exception is happening and somehow it does not end up in the insteonplm log, but in the openhab log instead, may want to check that one as well.

I made some progress!

First, Java 1.8 was already installed. I installed my own copy in /opt but when I ran update-alternatives --config, I saw it was already loaded elsewhere so I abandoned my /opt installation and just pointed the system at the existing 1.8.

$ sudo update-alternatives --config javac
$ sudo update-alternatives --config java

Then I followed this post and created a librxtxSerial.so symlink.

At that point, my insteon.log file was generating tons of output. My dimmer still wasn’t responding though.

I grabbed the latest stable binding from here. I hope that is the right place!

I shut down the openhab service, removed the 1.8 binding I was using, and swapped in the new binding I downloaded. I started up the openhab service, went to my site, and still nothing.

Here is a dump of the service starting. I tried the site but the dimmer slider control still did not move. I also hit some buttons on the dimmer as a sanity check. I’m not sure what to look for but it looks like the binding is talking to the modem as it was able to download the modem db and display the manual links I had made previously.

Also, I got Insteon Terminal to compile and run but haven’t looked at it in depth yet.

Not sure what did the trick, but you are pretty much there.
(going forward, please drop the log level from trace -> debug to make the log more readable.)
I can see that the device is now being polled, and you should get status updates. The modem link database also looks o.k., you should be getting status updates when you operate the device manually.
But nowhere in the log do I see the binding getting a command from openhab to change the dimmer level. The problem is now at a higher layer, somewhere on the path (GUI -> openhab -> binding).

Try a sitemap entry like this:

 Frame label="Dimmers" {
              Slider item=TestDimmer switchSupport
        }

and a items entry like this:

Dimmer TestDimmer     "test dimmer [%d %%]"      (gTF_Office)             {insteonplm="35.38.f6:F00.00.19#dimmer"}

Thank you for all of your help, I am up and running now!

Mind posting what the problem was, and how you got things to work?

I think the key for me was the Java upgrade and the librxtxSerial.so symlink. Even after that though, there must have been something up with my items definition. Once I copied your items entry, everything came together.