Insteon hub 2245 help - unable to control insteon dimmer switch

I have just started to configure OpenHAB 1.8 to control a Insteon hub model 2245-222 and have been unable to control my test Insteon Dimmer switch. Any help would be appreciated. My hub is at 192.168.109 and the device is ID 13.35.71.

Each time i toggle a device i see this error:
22:26:04.354 [ERROR] [b.i.internal.InsteonHubBinding:123 ] - InsteonHubBinding received command for unknown hub id ‘_default’

2 configs have been tried:
Config A:
insteonhub:port_0=/hub2/myhubname:hubpassword@myinsteonhub.mydomain:25105,poll_time=1000

Config B:
config: insteonplm:port_0=/hub/192.168.0.109:9761
insteonplm:poll_interval=300000
insteonplm:refresh=600000

My config seems to be working, this from the log (this from Config A):
0:05:36.153 [DEBUG] [i.internal.InsteonHubActivator:34 ] - InsteonHub binding has been started.
10:05:36.164 [DEBUG] [b.i.internal.InsteonHubBinding:243 ] - InsteonHubBinding activated
10:05:36.166 [DEBUG] [b.i.internal.InsteonHubBinding:201 ] - InsteonHubBinding updated

I mapped a few Items to try as a dimmer or switch on Insteon or x10 (got the x10 from a post in forum). I got the Insteon ID from my Insteon control app. The Insteon dimming switch is setup for both Insteon commands or X10 where the X10 ID is M5:

Dimmer Light_SF_BedDIM “BedDIM” (SF_Bedroom, Lights){insteonhub = “device=13.35.71, bindingType=dimmer”}

Switch Light_SF_BedSW “BedSW” (SF_Bedroom, Lights){insteonhub = “device=13.35.71, bindingType=switch”}

Switch Light_SF_BedSWX10 “BedSWx10” (SF_Bedroom, Lights){insteonplm=“m.5:X00.00.01#switch”}

I have tried to use the information from a 2015 topic “X10 devices through Insteon 2242-222 Hub VERY SLOW” where it seems that the userasjohnson9 was able to get X10 working on the same hub that I have. This is how I derived the B configuration.

@Bernd_Pfrommer, any suggestions?

You need to use the InsteonPLM configuration syntax in your items file, not the Insteon hub configuration.

We should remove the hub binding.

Agreed, I should have seen it was the wrong binding. @maintainer, FYI…

Do you mean org.openhab.binding.insteonhub should not be part of future distributions?

So i removed the Insteon Hub binding and added the Insteon PLM binding. I verified by Togglelink is 2466D which is F00.00.11

Changed config to:
insteonplm:port_0=/hub/192.168.0.109:9761 (I also tried port 25109)
insteonplm:poll_interval=300000
insteonplm:refresh=600000

Changed Item to:
Dimmer Light_SF_Bed1 “Bed2” (SF_Bedroom, Lights) {insteonplm = “device=13.35.71:F00.00.11#dimmer”}

Also tried this Item which was in use with the logs below:
Dimmer Light_SF_Bed1 “Bed1” (SF_Bedroom, Lights) {insteonplm=“13.35.71:F00.00.11#dimmer”}

From OpenHAB config log:
20:37:46.075 [INFO ] [insteonplm.InsteonPLMActivator:34 ] - Insteon PLM binding has been started.
20:37:46.083 [DEBUG] [i.internal.GenericItemProvider:341 ] - Start processing binding configuration of Item ‘Light_SF_Bed1 (Type=DimmerItem, State=Uninitialized)’ with ‘InsteonPLMGenericBindingProvider’ reader.
20:37:46.090 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:158 ] - activating binding
20:37:46.092 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:265 ] - global binding config has arrived.
20:37:46.092 [DEBUG] [.o.b.ntp.internal.NtpActivator:31 ] - NTP binding has been started.
20:37:46.093 [INFO ] [.o.b.i.InsteonPLMActiveBinding:281 ] - refresh interval set to 600s
20:37:46.094 [INFO ] [.o.b.i.InsteonPLMActiveBinding:290 ] - poll interval set to 300000 per config file
20:37:46.094 [INFO ] [.o.b.i.InsteonPLMActiveBinding:313 ] - dead device timeout set to 3000s
20:37:46.096 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:269 ] - configuration update complete!
20:37:46.097 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:352 ] - initializing…
20:37:46.098 [INFO ] [.service.AbstractActiveService:169 ] - InsteonPLM has been started
20:37:46.099 [INFO ] [.o.b.i.InsteonPLMActiveBinding:364 ] - config: poll_interval -> 300000
20:37:46.101 [DEBUG] [i.internal.GenericItemProvider:341 ] - Start processing binding configuration of Item ‘Date (Type=DateTimeItem, State=Uninitialized)’ with ‘NtpGenericBindingProvider’ reader.
20:37:46.105 [INFO ] [.o.b.i.InsteonPLMActiveBinding:670 ] - devices: 0 configured, 0 polling, msgs received: 0
20:37:46.107 [INFO ] [.o.b.i.InsteonPLMActiveBinding:364 ] - config: port_0 -> /hub/192.168.0.109:9761
20:37:46.112 [DEBUG] [o.o.b.i.internal.driver.Poller:176 ] - starting poll thread.
20:37:46.118 [DEBUG] [.i.LoggingPersistenceActivator:31 ] - Logging persistence bundle has been started.
20:37:46.125 [DEBUG] [o.o.b.i.internal.driver.Driver:75 ] - added new port: port_0 /hub/192.168.0.109:9761
20:37:46.128 [INFO ] [.o.b.i.InsteonPLMActiveBinding:364 ] - config: refresh -> 600000
20:37:46.140 [DEBUG] [.p.internal.PersistenceManager:146 ] - Initializing logging persistence service.
20:37:46.140 [INFO ] [.o.b.i.InsteonPLMActiveBinding:364 ] - config: service.pid -> org.openhab.insteonplm
20:37:46.141 [DEBUG] [c.internal.ModelRepositoryImpl:64 ] - Configuration model ‘logging.persist’ can not be found
20:37:46.141 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:370 ] - setting driver listener
20:37:46.148 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:372 ] - starting 0 ports
20:37:46.150 [DEBUG] [o.o.b.i.internal.driver.Port :132 ] - starting port /hub/192.168.0.109:9761

20:38:07.156 [ERROR] [.i.i.driver.hub.OldHubIOStream:55 ] - cannot open connection to 192.168.0.109 port 9761:

0:38:20.116 [DEBUG] [o.o.b.i.internal.driver.Port :137 ] - failed to open port /hub/192.168.0.109:9761
20:38:20.117 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:374 ] - ports started
20:38:20.117 [ERROR] [.o.b.i.InsteonPLMActiveBinding:377 ] - initialization complete, but found no ports!
20:38:20.118 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:220 ] - item Light_SF_Bed1 binding changed: addr=13.35.71|prodKey:F00.00.11|feature:dimmer

Any thoughts? Thanks!

1 Like

That’s what we mean: from all we can tell the Insteonhub binding has been abandoned. We cannot say if somebody is still using it. But it is no longer actively maintained for what seems several years now.

The InsteonPLM binding offers a superset of the Insteonhub features.

You have a 2014 hub (2245-222), meaning you should use the “hub2” syntax in the openhab.config file. This is what you called “Config A” in your original post. You seem to have used the config for the legacy hub (pre-2014) hub.

So Insteon config is now?:

insteonhub:port_0=/hub2/myhubname:hubpassword@myinsteonhub.mydomain:25105,poll_time=1000
insteonplm:port_0=/hub/192.168.0.109:9761
insteonplm:poll_interval=300000
insteonplm:refresh=600000

It seems like this is mixing the hub and PLM config.

Only this:
insteonhub:port_0=/hub2/myhubname:hubpassword@myinsteonhub.mydomain:25105,poll_time=1000

I made the change. No luck yet.

Error when trying Item command:
22:23:21.319 [INFO ] [.o.b.i.InsteonPLMActiveBinding:125 ] - Item: Light_SF_Bed1 got command ON
22:23:21.320 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:128 ] - not ready to handle commands yet, returning.

I see no other Insteon error in the log

do you see messages about it connecting? you should see the modem db being printed etc. please post more of the log, from the start

Here you go. Thanks!! I have been trimming out portions of the Demo which was cluttering the logs hope i didnt break anything.

Config: insteonhub:port_0=/hub2/name:pass@myinsteonhub.mydomain:25105,poll_time=1000

Item: Dimmer Light_SF_Bed1 “Bed1” (SF_Bedroom, Lights) {insteonplm=“13.35.71:F00.00.11#dimmer”}

22:35:10.335 [DEBUG] [.s.internal.SchedulerActivator:36 ] - Scheduler has been started.
22:35:10.386 [INFO ] [uartz.impl.StdSchedulerFactory:1175 ] - Using default implementation for ThreadExecutor
22:35:10.408 [INFO ] [rtz.core.SchedulerSignalerImpl:61 ] - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
22:35:10.409 [INFO ] [rg.quartz.core.QuartzScheduler:243 ] - Quartz Scheduler v.2.1.7 created.
22:35:10.410 [INFO ] [org.quartz.simpl.RAMJobStore :154 ] - RAMJobStore initialized.
22:35:10.412 [INFO ] [rg.quartz.core.QuartzScheduler:268 ] - Scheduler meta-data: Quartz Scheduler (v2.1.7) ‘openHAB-job-scheduler’ with instanceId 'NON_CLUSTERED’
Scheduler class: ‘org.quartz.core.QuartzScheduler’ - running locally.
NOT STARTED.
Currently in standby mode.
Number of jobs executed: 0
Using thread pool ‘org.quartz.simpl.SimpleThreadPool’ - with 2 threads.
Using job-store ‘org.quartz.simpl.RAMJobStore’ - which does not support persistence. and is not clustered.

22:35:10.413 [INFO ] [uartz.impl.StdSchedulerFactory:1324 ] - Quartz scheduler ‘openHAB-job-scheduler’ initialized from specified file: './etc/quartz.properties’
22:35:10.414 [INFO ] [uartz.impl.StdSchedulerFactory:1328 ] - Quartz scheduler version: 2.1.7
22:35:10.415 [INFO ] [rg.quartz.core.QuartzScheduler:534 ] - Scheduler openHAB-job-scheduler_$_NON_CLUSTERED started.
22:35:10.417 [DEBUG] [o.config.core.ConfigDispatcher:146 ] - Processing openHAB default configuration file ‘D:\OpenHAB\configurations\openhab_default.cfg’.
22:35:10.418 [DEBUG] [o.config.core.ConfigDispatcher:168 ] - Processing openHAB main configuration file ‘D:\OpenHAB\configurations\openhab.cfg’.
22:35:10.765 [DEBUG] [.o.core.internal.CoreActivator:93 ] - UUID file already exists at ‘D:\OpenHAB\webapps\static\uuid’ with content 'be542fe0-aa00-4fe5-bd30-35cce018206c’
22:35:10.766 [DEBUG] [.o.core.internal.CoreActivator:115 ] - Created file ‘D:\OpenHAB\webapps\static\version’ with content '1.8.3’
22:35:10.767 [INFO ] [.o.core.internal.CoreActivator:61 ] - openHAB runtime has been started (v1.8.3).
22:35:10.796 [DEBUG] [a.internal.AutoUpdateActivator:31 ] - AutoUpdate binding has been started.
22:35:11.520 [DEBUG] [.p.i.PersistenceModelActivator:23 ] - Registered ‘persistence’ configuration parser
22:35:11.559 [DEBUG] [.c.t.i.TransformationActivator:38 ] - Transformation Service has been started.
22:35:11.595 [DEBUG] [m.internal.MultimediaActivator:34 ] - Multimedia I/O bundle has been started.
22:35:11.621 [DEBUG] [.s.i.DiscoveryServiceActivator:27 ] - Discovery service has been started.
22:35:11.627 [INFO ] [o.o.i.s.i.DiscoveryServiceImpl:93 ] - mDNS service has been started
22:35:11.649 [DEBUG] [.io.transport.mqtt.MqttService:123 ] - Starting MQTT Service…
22:35:11.743 [INFO ] [o.o.i.s.i.DiscoveryServiceImpl:53 ] - Service Discovery initialization completed.
22:35:11.787 [DEBUG] [.i.internal.ItemModelActivator:24 ] - Registered ‘item’ configuration parser
22:35:11.843 [DEBUG] [o.o.c.i.items.ItemRegistryImpl:137 ] - Item provider ‘GenericItemProvider’ has been added.
22:35:12.319 [DEBUG] [.o.m.s.i.SitemapModelActivator:23 ] - Registered ‘sitemap’ configuration parser
22:35:12.987 [DEBUG] [io.rest.internal.RESTActivator:33 ] - REST API has been started.
22:35:13.052 [INFO ] [org.atmosphere.util.IOUtils :370 ] - META-INF/services/org.atmosphere.cpr.AtmosphereFramework not found in class loader
22:35:13.074 [INFO ] [sphere.cpr.AtmosphereFramework:2601 ] - Atmosphere is using org.atmosphere.cpr.DefaultAnnotationProcessor for processing annotation
22:35:13.076 [INFO ] [cpr.DefaultAnnotationProcessor:138 ] - AnnotationProcessor class org.atmosphere.cpr.DefaultAnnotationProcessor$BytecodeBasedAnnotationProcessor being used
22:35:13.093 [WARN ] [cpr.DefaultAnnotationProcessor:178 ] - Unable to detect annotations. Application may fail to deploy.
22:35:13.110 [INFO ] [sphere.cpr.AtmosphereFramework:1891 ] - Auto detecting atmosphere handlers /WEB-INF/classes/
22:35:13.124 [INFO ] [sphere.cpr.AtmosphereFramework:639 ] - Installed AtmosphereHandler org.atmosphere.handler.ReflectorServletProcessor mapped to context-path /* and Broadcaster Class org.atmosphere.jersey.JerseyBroadcaster
22:35:13.125 [INFO ] [sphere.cpr.AtmosphereFramework:1945 ] - Auto detecting WebSocketHandler in /WEB-INF/classes/
22:35:13.126 [INFO ] [sphere.cpr.AtmosphereFramework:1602 ] - Installed WebSocketProtocol org.atmosphere.websocket.protocol.SimpleHttpProtocol
22:35:13.163 [INFO ] [.a.h.ReflectorServletProcessor:103 ] - Installing Servlet com.sun.jersey.spi.container.servlet.ServletContainer
22:35:13.241 [INFO ] [c.s.j.s.i.a.WebApplicationImpl:815 ] - Initiating Jersey application, version 'Jersey: 1.18.1 02/19/2014 03:28 AM’
22:35:13.243 [INFO ] [c.s.j.s.i.a.WebApplicationImpl:826 ] - Adding the following classes declared in META-INF/services/jersey-server-components to the resource configuration:
class org.atmosphere.jersey.AtmosphereResourceConfigurator
22:35:13.280 [INFO ] [j.s.i.a.DeferredResourceConfig:101 ] - Instantiated the Application class org.openhab.io.rest.RESTApplication
22:35:13.859 [INFO ] [sphere.cpr.AtmosphereFramework:2435 ] - AtmosphereInterceptor CORS Interceptor Support will always be executed first
22:35:13.860 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor CORS Interceptor Support with priority FIRST_BEFORE_DEFAULT
22:35:13.861 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor Default Response’s Headers Interceptor with priority AFTER_DEFAULT
22:35:13.862 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor Android Interceptor Support with priority AFTER_DEFAULT
22:35:13.863 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor SSE Interceptor Support with priority AFTER_DEFAULT
22:35:13.864 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor JSONP Interceptor Support with priority AFTER_DEFAULT
22:35:13.865 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor Atmosphere JavaScript Protocol with priority AFTER_DEFAULT
22:35:13.866 [INFO ] [sphere.cpr.AtmosphereFramework:2404 ] - Installed AtmosphereInterceptor Browser disconnection detection with priority AFTER_DEFAULT
22:35:13.869 [INFO ] [sphere.cpr.AtmosphereFramework:935 ] - Using EndpointMapper class org.atmosphere.util.DefaultEndpointMapper
22:35:13.871 [WARN ] [sphere.cpr.AtmosphereFramework:941 ] - No BroadcasterCache configured. Broadcasted message between client reconnection will be LOST. It is recommended to configure the org.atmosphere.cache.UUIDBroadcasterCache
22:35:13.871 [INFO ] [sphere.cpr.AtmosphereFramework:949 ] - Default Broadcaster Class: org.atmosphere.jersey.JerseyBroadcaster
22:35:13.872 [INFO ] [sphere.cpr.AtmosphereFramework:950 ] - Broadcaster Polling Wait Time 100
22:35:13.872 [INFO ] [sphere.cpr.AtmosphereFramework:951 ] - Shared ExecutorService supported: true
22:35:13.872 [INFO ] [sphere.cpr.AtmosphereFramework:958 ] - Messaging Thread Pool Size: 10
22:35:13.873 [INFO ] [sphere.cpr.AtmosphereFramework:968 ] - Async I/O Thread Pool Size: 10
22:35:13.873 [INFO ] [sphere.cpr.AtmosphereFramework:979 ] - Using BroadcasterFactory: org.atmosphere.cpr.DefaultBroadcasterFactory
22:35:13.874 [INFO ] [sphere.cpr.AtmosphereFramework:980 ] - Using WebSocketProcessor: org.atmosphere.websocket.DefaultWebSocketProcessor
22:35:13.875 [INFO ] [sphere.cpr.AtmosphereFramework:990 ] - Invoke AtmosphereInterceptor on WebSocket message true
22:35:13.876 [INFO ] [sphere.cpr.AtmosphereFramework:991 ] - HttpSession supported: false
22:35:13.877 [INFO ] [sphere.cpr.AtmosphereFramework:993 ] - Atmosphere is using DefaultAtmosphereObjectFactory for dependency injection and object creation
22:35:13.877 [INFO ] [sphere.cpr.AtmosphereFramework:994 ] - Atmosphere is using async support: org.atmosphere.container.JettyAsyncSupportWithWebSocket running under container: jetty/8.1.3.v20120522 with WebSocket enabled.
22:35:13.878 [INFO ] [sphere.cpr.AtmosphereFramework:996 ] - Atmosphere Framework 2.2.5 started.
22:35:13.879 [INFO ] [sphere.cpr.AtmosphereFramework:998 ] -

For Atmosphere Framework Commercial Support, visit 
http://www.async-io.org/ or send an email to support@async-io.org

22:35:13.880 [INFO ] [penhab.io.rest.RESTApplication:144 ] - Started REST API at /rest
22:35:13.884 [DEBUG] [o.o.i.s.i.DiscoveryServiceImpl:66 ] - Registering new service _openhab-server._tcp.local. at port 8080
22:35:19.307 [DEBUG] [o.o.i.s.i.DiscoveryServiceImpl:66 ] - Registering new service _openhab-server-ssl._tcp.local. at port 8443
22:35:21.473 [INFO ] [c.internal.ModelRepositoryImpl:80 ] - Loading model 'demo.sitemap’
22:35:21.586 [INFO ] [c.internal.ModelRepositoryImpl:80 ] - Loading model 'exec.persist’
22:35:21.600 [INFO ] [c.internal.ModelRepositoryImpl:80 ] - Loading model 'logging.persist’
22:35:21.645 [INFO ] [c.internal.ModelRepositoryImpl:80 ] - Loading model 'demo.script’
22:35:21.714 [INFO ] [c.internal.ModelRepositoryImpl:80 ] - Loading model 'demo.items’
22:35:21.739 [DEBUG] [i.internal.GenericItemProvider:154 ] - Processing binding configs for items from model 'demo.items’
22:35:21.745 [DEBUG] [i.internal.GenericItemProvider:133 ] - Read items from model 'demo.items’
22:35:21.993 [INFO ] [.o.u.w.i.servlet.WebAppServlet:80 ] - Started Classic UI at /classicui/openhab.app
22:35:22.159 [DEBUG] [.r.internal.RuleModelActivator:42 ] - Registered ‘rules’ configuration parser
22:35:22.170 [DEBUG] [m.r.internal.engine.RuleEngine:77 ] - Started rule engine
22:35:25.664 [DEBUG] [.a.xmpp.internal.XMPPActivator:34 ] - XMPP action has been started.
22:35:25.690 [DEBUG] [.a.xbmc.internal.XBMCActivator:34 ] - XBMC action has been started.
22:35:25.720 [DEBUG] [.rrd4j.internal.RRD4jActivator:31 ] - RRD4j persistence bundle has been started.
22:35:25.732 [DEBUG] [.p.rrd4j.internal.RRD4jService:395 ] - Unknown property name : org.openhab.persistence.rrd4j
22:35:25.733 [DEBUG] [.p.rrd4j.internal.RRD4jService:364 ] - config ‘objectClass’ should have the format 'name.configkey’
22:35:25.734 [INFO ] [.p.rrd4j.internal.RRD4jService:407 ] - Removing invalid defintion component = null heartbeat = 0 min/max = 0.0/0.0 step = 0 0 archives(s) = [] 0 items(s) = []
22:35:25.738 [DEBUG] [.p.rrd4j.internal.RRD4jService:405 ] - Created default_other = GAUGE heartbeat = 3600 min/max = NaN/NaN step = 1 6 archives(s) = [ MAX xff = 0.999 steps = 1 rows = 3600 MAX xff = 0.999 steps = 10 rows = 1440 MAX xff = 0.999 steps = 60 rows = 1440 MAX xff = 0.999 steps = 900 rows = 2880 MAX xff = 0.999 steps = 21600 rows = 1460 MAX xff = 0.999 steps = 86400 rows = 3650] 0 items(s) = []
22:35:25.743 [DEBUG] [.p.rrd4j.internal.RRD4jService:405 ] - Created default_numeric = GAUGE heartbeat = 60 min/max = NaN/NaN step = 60 6 archives(s) = [ AVERAGE xff = 0.5 steps = 1 rows = 480 AVERAGE xff = 0.5 steps = 4 rows = 360 AVERAGE xff = 0.5 steps = 14 rows = 644 AVERAGE xff = 0.5 steps = 60 rows = 720 AVERAGE xff = 0.5 steps = 720 rows = 730 AVERAGE xff = 0.5 steps = 10080 rows = 520] 0 items(s) = []
22:35:25.747 [DEBUG] [.p.internal.PersistenceManager:146 ] - Initializing rrd4j persistence service.
22:35:25.753 [DEBUG] [c.internal.ModelRepositoryImpl:64 ] - Configuration model ‘rrd4j.persist’ can not be found
22:35:25.762 [DEBUG] [p.r.i.charts.RRD4jChartServlet:118 ] - Starting up rrd chart servlet at /rrdchart.png
22:35:25.765 [DEBUG] [xecPersistenceServiceActivator:33 ] - Exec persistence bundle has been started.
22:35:25.773 [DEBUG] [.p.internal.PersistenceManager:146 ] - Initializing exec persistence service.
22:35:25.789 [DEBUG] [.p.internal.PersistenceManager:428 ] - Scheduled strategy exec.everyMinute with cron expression 0 * * * * ?
22:35:25.791 [DEBUG] [.i.LoggingPersistenceActivator:31 ] - Logging persistence bundle has been started.
22:35:25.797 [DEBUG] [.p.internal.PersistenceManager:146 ] - Initializing logging persistence service.
22:35:25.811 [DEBUG] [.b.http.internal.HttpActivator:34 ] - HTTP binding has been started.
22:35:25.824 [INFO ] [.service.AbstractActiveService:169 ] - HTTP Refresh Service has been started
22:35:25.826 [DEBUG] [i.internal.InsteonHubActivator:34 ] - InsteonHub binding has been started.
22:35:25.839 [DEBUG] [b.i.internal.InsteonHubBinding:243 ] - InsteonHubBinding activated
22:35:25.840 [DEBUG] [b.i.internal.InsteonHubBinding:201 ] - InsteonHubBinding updated
22:35:25.842 [DEBUG] [.o.b.ntp.internal.NtpActivator:31 ] - NTP binding has been started.
22:35:25.843 [INFO ] [.service.AbstractActiveService:169 ] - InsteonHub Refresh Service has been started
22:35:25.847 [DEBUG] [b.i.internal.InsteonHubBinding:82 ] - InsteonHubBinding execute
22:35:25.870 [DEBUG] [b.i.internal.InsteonHubBinding:97 ] - InsteonHubBinding execute complete
22:35:25.871 [DEBUG] [i.internal.GenericItemProvider:341 ] - Start processing binding configuration of Item ‘Date (Type=DateTimeItem, State=Uninitialized)’ with ‘NtpGenericBindingProvider’ reader.
22:35:25.877 [INFO ] [.service.AbstractActiveService:169 ] - NTP Refresh Service has been started
22:35:25.878 [INFO ] [insteonplm.InsteonPLMActivator:34 ] - Insteon PLM binding has been started.
22:35:25.889 [DEBUG] [i.internal.GenericItemProvider:341 ] - Start processing binding configuration of Item ‘Light_SF_Bed1 (Type=DimmerItem, State=Uninitialized)’ with ‘InsteonPLMGenericBindingProvider’ reader.
22:35:25.897 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:158 ] - activating binding
22:35:25.898 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:243 ] - seems like our configuration has been erased, will reset everything!
22:35:25.899 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:254 ] - config has not changed, done.
22:35:25.942 [DEBUG] [inding.ntp.internal.NtpBinding:84 ] - Got time from nist1-macon.macon.ga.us: Monday, September 26, 2016 10:35:25 PM EDT
22:35:31.801 [INFO ] [c.internal.ModelRepositoryImpl:80 ] - Loading model 'demo.rules’
22:36:25.871 [DEBUG] [b.i.internal.InsteonHubBinding:82 ] - InsteonHubBinding execute
22:36:25.872 [DEBUG] [b.i.internal.InsteonHubBinding:97 ] - InsteonHubBinding execute complete
22:37:25.874 [DEBUG] [b.i.internal.InsteonHubBinding:82 ] - InsteonHubBinding execute
22:37:25.874 [DEBUG] [b.i.internal.InsteonHubBinding:97 ] - InsteonHubBinding execute complete
22:37:35.755 [INFO ] [.o.b.i.InsteonPLMActiveBinding:125 ] - Item: Light_SF_Bed1 got command ON
22:37:35.756 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:128 ] - not ready to handle commands yet, returning.

You still have the InsteonHub binding running. Remove it from the addons folder. You only want the InsteonPLM binding there, not both.

Second, have the insteonplm binding log to a separate file as described in the insteonplm wiki. that makes the log more readable.

I removed the hub binding and will check the Wiki out as you indicated. Will have to get back to this tomorrow. Thanks again.

Is the insteonhub part of this correct, since you only want the insteonplm binding running?

You are right, I didn’t catch that. As a matter of fact, I copied the error from @Weebs

So here is how the line should read.

insteonplm:port_0=/hub2/my_user_name:my_password@myinsteonhub.mydomain:25105,poll_time=1000

This is straight out of the openhab_default.cfg.
Note the insteonplm instead of insteonhub at the beginning of the line.

No luck yet :frowning:

I made the change to the config to:
insteonPLM:port_0=/hub2/myname:mypass@myinsteonhub.mydomain:25105,poll_time=1000
where myname and pass are replaced with the info on the hub sticker.

Ive added Insteon binding log and here are the results:

6-09-27 19:09:23 INFO o.o.b.i.InsteonPLMActivator[:34]- Insteon PLM binding has been started.
2016-09-27 19:09:23 DEBUG o.o.b.i.InsteonPLMActiveBinding[:158]- activating binding
2016-09-27 19:09:23 DEBUG o.o.b.i.InsteonPLMActiveBinding[:243]- seems like our configuration has been erased, will reset everything!
2016-09-27 19:09:23 DEBUG o.o.b.i.InsteonPLMActiveBinding[:254]- config has not changed, done.
2016-09-27 19:10:30 INFO o.o.b.i.InsteonPLMActiveBinding[:125]- Item: Light_SF_Bed1 got command ON
2016-09-27 19:10:30 DEBUG o.o.b.i.InsteonPLMActiveBinding[:128]- not ready to handle commands yet, returning.
2016-09-27 19:10:31 INFO o.o.b.i.InsteonPLMActiveBinding[:125]- Item: Light_SF_Bed1 got command ON
2016-09-27 19:10:31 DEBUG o.o.b.i.InsteonPLMActiveBinding[:128]- not ready to handle commands yet, returning.
2016-09-27 19:10:31 INFO o.o.b.i.InsteonPLMActiveBinding[:125]- Item: Light_SF_Bed1 got command ON
2016-09-27 19:10:31 DEBUG o.o.b.i.InsteonPLMActiveBinding[:128]- not ready to handle commands yet, returning.
2016-09-27 19:10:31 INFO o.o.b.i.InsteonPLMActiveBinding[:125]- Item: Light_SF_Bed1 got command ON
2016-09-27 19:10:31 DEBUG o.o.b.i.InsteonPLMActiveBinding[:128]- not ready to handle commands yet, returning.

[quote=“Weebs, post:19, topic:14451, full:true”]
insteonPLM:port_0=/hub2/myname:mypass@myinsteonhub.mydomain:25105,poll_time=1000
[/quote]

The insteonPLM should be insteonplm (lowercase). Also you mention the myname:mypass was from the bottom of the hub which is correct, but you don’t mention if you changed my insteonhub.mydomain. This should be the IP of your hub.

Example:

insteonplm:port_0=/hub2/Horm1:Catctus2@192.168.0.109:25105,poll_time=1000