All,
I have an Insteon network set up to control my lights and everything seems to be working fine, the lights and switches are responding fine and I get updates when I trigger them from OH. The issue I have is that when I start OH I never get status updates on my Insteon devices. They remain uninitialized until I trigger them. Is there a way I can get them to update on startup?
Thanks,
Matt
How do you have your devices linked with the plm or hub? Do you have something similar to this in your openhab.log file?
2016-11-04 15:20:39.951 [INFO ] [.o.b.i.InsteonPLMActiveBinding] - device 22.F8.74 found in the modem database and the modem controls groups [0xFE,0x03,0x04,0x05,0x06] and responds to groups [0x01,0x03,0x04,0x05,0x06].
2016-11-04 15:20:39.954 [INFO ] [.o.b.i.InsteonPLMActiveBinding] - device 23.9E.35 found in the modem database and the modem controls groups [0xFE] and responds to groups [0x01].
2016-11-04 15:20:39.958 [INFO ] [.o.b.i.InsteonPLMActiveBinding] - device 23.9D.94 found in the modem database and the modem controls groups [0xFE] and responds to groups [0x01].
2016-11-04 15:20:39.961 [INFO ] [.o.b.i.InsteonPLMActiveBinding] - device 24.2F.74 found in the modem database and the modem controls groups [0xFE] and responds to groups [0x01].
2016-11-04 15:20:39.965 [INFO ] [.o.b.i.InsteonPLMActiveBinding] - device 23.9F.D0 found in the modem database and the modem controls groups [0xFE] and responds to groups [0x01].
2016-11-04 15:20:39.969 [INFO ] [.o.b.i.InsteonPLMActiveBinding] - device 23.A0.73 found in the modem database and the modem controls groups [0xFE] and responds to groups [0x01].
2016-11-04 15:20:39.971 [INFO ] [.o.b.i.InsteonPLMActiveBinding] - device 24.31.81 found in the modem database and the modem controls groups [0xFE] and responds to groups [0x01].
2016-11-04 15:20:40.297 [INFO ] [.o.b.i.i.device.MessageHandler] - DimmerRequestReplyHandler: set device 23.9F.C9 to level 100
2016-11-04 15:20:45.005 [INFO ] [.o.b.i.i.device.MessageHandler] - SwitchRequestReplyHandler: set device 24.33.F7 to OFF
2016-11-04 15:20:45.626 [INFO ] [.o.b.i.i.device.MessageHandler] - DimmerRequestReplyHandler: set device 23.9F.55 to level 0
2016-11-04 15:20:46.226 [INFO ] [.o.b.i.i.device.MessageHandler] - DimmerRequestReplyHandler: set device 23.A0.D9 to level 100
2016-11-04 15:20:48.125 [INFO ] [.o.b.i.i.device.MessageHandler] - DimmerRequestReplyHandler: set device 23.A0.D9 to level 100
2016-11-04 15:20:50.121 [INFO ] [.o.b.i.i.device.MessageHandler] - DimmerRequestReplyHandler: set device 23.9F.82 to level 0
2016-11-04 15:20:50.943 [INFO ] [.o.b.i.i.device.MessageHandler] - DimmerRequestReplyHandler: set device 23.9F.C9 to level 100
Unless your device doesn’t support it you’ll want to see both controls and responds in the log file for each device.
I don’t see that in my Openhab.log file anywhere. I used the app on my android to link everything to my 2014 style hub. I’m noticing that hub and app are buggy though. Should I link another way? I looked in the insteonplm.log file and I don’t see it there either. This is what I get in the insteon log file:
2016-11-10 09:41:08 INFO o.o.b.i.InsteonPLMActivator[:34]- Insteon PLM binding has been started.
2016-11-10 09:41:08 DEBUG o.o.b.i.InsteonPLMActiveBinding[:158]- activating binding
2016-11-10 09:41:08 DEBUG o.o.b.i.InsteonPLMActiveBinding[:265]- global binding config has arrived.
2016-11-10 09:41:08 INFO o.o.b.i.InsteonPLMActiveBinding[:290]- poll interval set to 150000 per config file
2016-11-10 09:41:08 INFO o.o.b.i.InsteonPLMActiveBinding[:313]- dead device timeout set to 1500s
2016-11-10 09:41:08 DEBUG o.o.b.i.InsteonPLMActiveBinding[:269]- configuration update complete!
2016-11-10 09:41:08 DEBUG o.o.b.i.InsteonPLMActiveBinding[:352]- initializing…
2016-11-10 09:41:08 INFO o.o.b.i.InsteonPLMActiveBinding[:364]- config: poll_interval -> 150000
2016-11-10 09:41:08 INFO o.o.b.i.InsteonPLMActiveBinding[:364]- config: port_0 -> /hub2/Letholdu:tiib5ALW@192.168.1.9:25105,poll_time=1000
2016-11-10 09:41:08 DEBUG o.o.b.i.internal.driver.Poller[:176]- starting poll thread.
2016-11-10 09:41:08 INFO o.o.b.i.InsteonPLMActiveBinding[:670]- devices: 0 configured, 0 polling, msgs received: 0
2016-11-10 09:41:08 DEBUG o.o.b.i.internal.driver.Driver[:75]- added new port: port_0 /hub2/Letholdu:tiib5ALW@192.168.1.9:25105,poll_time=1000
2016-11-10 09:41:08 INFO o.o.b.i.InsteonPLMActiveBinding[:364]- config: service.pid -> org.openhab.insteonplm
2016-11-10 09:41:08 DEBUG o.o.b.i.InsteonPLMActiveBinding[:370]- setting driver listener
2016-11-10 09:41:08 DEBUG o.o.b.i.InsteonPLMActiveBinding[:372]- starting 0 ports
2016-11-10 09:41:08 DEBUG o.o.b.i.internal.driver.Port[:132]- starting port /hub2/Letholdu:tiib5ALW@192.168.1.9:25105,poll_time=1000
2016-11-10 09:41:08 DEBUG o.o.b.i.internal.driver.Port[:373]- starting writer…
2016-11-10 09:41:08 DEBUG o.o.b.i.internal.driver.Port[:239]- starting reader…
2016-11-10 09:41:08 DEBUG o.o.b.i.i.d.ModemDBBuilder[:50]- querying port for first link record
2016-11-10 09:41:08 DEBUG o.o.b.i.InsteonPLMActiveBinding[:374]- ports started
2016-11-10 09:41:08 DEBUG o.o.b.i.internal.driver.Port[:122]- clearing modem db!
2016-11-10 09:41:08 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x60|
2016-11-10 09:41:08 DEBUG o.o.b.i.InsteonPLMActiveBinding[:380]- initialization complete, found 1 port!
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:195]- loaded 41 devices:
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- 0x000041 ->pk:0x000041|model:2484DWH8|desc:KeypadLinc Countdown Timer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.0A ->pk:F00.00.0A|model:2852-222|desc:Leak Sensor|features:contact=LeakSensorContact:lastheardfrom=GenericLastTime|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.0D ->pk:F00.00.0D|model:2634-222|desc:On/Off Dual-Band Outdoor Module|features:lastheardfrom=GenericLastTime:switch=GenericSwitch|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- 0x000049 ->pk:0x000049|model:2843-222|desc:Wireless Open/Close Sensor|features:contact=GenericContact:lastheardfrom=GenericLastTime|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.0C ->pk:F00.00.0C|model:2476D|desc:SwitchLinc Dimmer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.0B ->pk:F00.00.0B|model:2672-422|desc:LED Dimmer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- 0x000068 ->pk:0x000068|model:2472D|desc:OutletLincDimmer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- 0x000045 ->pk:0x000045|model:2413U|desc:PowerLinc 2413U USB modem|features:broadcastonoff=GroupBroadcastOnOff|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- 0x00004A ->pk:0x00004A|model:2842-222|desc:Motion Sensor|features:data=MotionSensorData:contact=WirelessMotionSensorContact:lastheardfrom=GenericLastTime|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.01 ->pk:F00.00.01|model:2477D|desc:SwitchLinc Dimmer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.05 ->pk:F00.00.05|model:2456D3|desc:LampLinc V2|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.04 ->pk:F00.00.04|model:2876S|desc:ICON Switch|features:lastheardfrom=GenericLastTime:switch=GenericSwitch|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.03 ->pk:F00.00.03|model:2845-222|desc:Hidden Door Sensor|features:data=HiddenDoorSensorData:contact=WirelessMotionSensorContact:lastheardfrom=GenericLastTime|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.02 ->pk:F00.00.02|model:2477S|desc:SwitchLinc Switch|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:switch=GenericSwitch|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.09 ->pk:F00.00.09|model:2458-A1|desc:MorningLinc RF Lock Controller|features:switch=GenericSwitch|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.08 ->pk:F00.00.08|model:2452-222|desc:DIN Rail Dimmer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.07 ->pk:F00.00.07|model:2453-222|desc:DIN Rail On/Off|features:lastheardfrom=GenericLastTime:switch=GenericSwitch|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.06 ->pk:F00.00.06|model:2442-222|desc:Micro Dimmer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- 0x000051 ->pk:0x000051|model:2486DWH8|desc:KeypadLinc Dimmer - 8 Button|features:loaddimmer=LoadDimmerButton:fastonoff=LoadDimmerFastOnOff:keypadbuttonD=KeyPadButton4:keypadbuttonE=KeyPadButton5:keypadbuttonB=KeyPadButton2:keypadbuttonC=KeyPadButton3:keypadbuttonH=KeyPadButton8:lastheardfrom=GenericLastTime:keypadbuttonF=KeyPadButton6:keypadbuttonG=KeyPadButton7:manualchange=ManualChange:rampdimmer=LoadDimmerRamp|groups:button_group=keypadbuttonB,keypadbuttonC,keypadbuttonD,keypadbuttonE,keypadbuttonF,keypadbuttonG,keypadbuttonH
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- 0x000050 ->pk:0x000050|model:2486DWH6|desc:KeypadLinc Dimmer - 6 Button|features:loaddimmer=LoadDimmerButton:fastonoff=LoadDimmerFastOnOff:keypadbuttonA=KeyPadButton3:keypadbuttonD=KeyPadButton6:keypadbuttonB=KeyPadButton4:keypadbuttonC=KeyPadButton5:lastheardfrom=GenericLastTime:manualchange=ManualChange:rampdimmer=LoadDimmerRamp|groups:button_group=keypadbuttonA,keypadbuttonB,keypadbuttonC,keypadbuttonD
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.1B ->pk:F00.00.1B|model:2635-222|desc:On/Off Module|features:lastheardfrom=GenericLastTime:switch=GenericSwitch|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.1A ->pk:F00.00.1A|model:2475SDB|desc:In-LineLinc Relay|features:lastheardfrom=GenericLastTime:switch=GenericSwitch|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- 0x000039 ->pk:0x000039|model:2663-222|desc:On/Off Outlet|features:bottomoutlet=BottomOutlet:lastheardfrom=GenericLastTime:topoutlet=GenericSwitch|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.1E ->pk:F00.00.1E|model:2674-222|desc:LED Bulb (recessed)|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer:rampdimmer=RampDimmer|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.1D ->pk:F00.00.1D|model:2456S3|desc:ApplianceLinc|features:lastheardfrom=GenericLastTime:switch=GenericSwitch|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- 0x000037 ->pk:0x000037|model:2486D|desc:KeypadLinc Dimmer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.1C ->pk:F00.00.1C|model:2475F|desc:FanLinc Module|features:fan=FanLincFan:lightdimmer=GenericDimmer:lastheardfrom=GenericLastTime|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.12 ->pk:F00.00.12|model:2466S|desc:ToggleLinc Switch|features:lastheardfrom=GenericLastTime:switch=GenericSwitch|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.11 ->pk:F00.00.11|model:2466D|desc:ToggleLinc Dimmer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer:rampdimmer=RampDimmer|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.10 ->pk:F00.00.10|model:2342-2|desc:Mini Remote|features:buttonD=RemoteButtonD:buttonB=RemoteButtonB:buttonC=RemoteButtonC:lastheardfrom=GenericLastTime:buttonA=RemoteButtonA|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- X00.00.03 ->pk:X00.00.03|model:X10 motion sensor|desc:Generic X10 motion sensor|features:contact=X10Contact|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.16 ->pk:F00.00.16|model:2334-232|desc:Keypad Dimmer Switch, 8-Button |features:loaddimmer=LoadDimmerButton:fastonoff=LoadDimmerFastOnOff:keypadbuttonD=KeyPadButton4:keypadbuttonE=KeyPadButton5:keypadbuttonB=KeyPadButton2:keypadbuttonC=KeyPadButton3:keypadbuttonH=KeyPadButton8:lastheardfrom=GenericLastTime:keypadbuttonF=KeyPadButton6:keypadbuttonG=KeyPadButton7:manualchange=ManualChange:rampdimmer=LoadDimmerRamp|groups:button_group=keypadbuttonB,keypadbuttonC,keypadbuttonD,keypadbuttonE,keypadbuttonF,keypadbuttonG,keypadbuttonH
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- X00.00.02 ->pk:X00.00.02|model:X10 dimmer|desc:Generic X10 Dimmer without preset|features:dimmer=X10Dimmer:switch=X10Switch|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.15 ->pk:F00.00.15|model:2334-232|desc:Keypad Dimmer Switch, 6-Button |features:loaddimmer=LoadDimmerButton:fastonoff=LoadDimmerFastOnOff:keypadbuttonA=KeyPadButton3:keypadbuttonD=KeyPadButton6:keypadbuttonB=KeyPadButton4:keypadbuttonC=KeyPadButton5:lastheardfrom=GenericLastTime:manualchange=ManualChange:rampdimmer=LoadDimmerRamp|groups:button_group=keypadbuttonA,keypadbuttonB,keypadbuttonC,keypadbuttonD
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- X00.00.01 ->pk:X00.00.01|model:X10 switch|desc:any simple X10 switch|features:switch=X10Switch|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.14 ->pk:F00.00.14|model:2487S|desc:KeypadLinc On/Off 6-Button Scene Control |features:keypadbuttonA=KeyPadButton3:manualchangebuttonD=ManualChangeButton6:keypadbuttonD=KeyPadButton6:manualchangebuttonA=ManualChangeButton3:keypadbuttonB=KeyPadButton4:manualchangebuttonC=ManualChangeButton5:keypadbuttonC=KeyPadButton5:manualchangebuttonB=ManualChangeButton4:loadswitchmanualchange=LoadSwitchManualChange:loadswitchfastonoff=LoadSwitchFastOnOff:fastonoffbuttonB=FastOnOffButton4:fastonoffbuttonC=FastOnOffButton5:lastheardfrom=GenericLastTime:fastonoffbuttonD=FastOnOffButton6:loadswitch=LoadSwitchButton:fastonoffbuttonA=FastOnOffButton3|groups:manualchange_button_group=manualchangebuttonA,manualchangebuttonB,manualchangebuttonC,manualchangebuttonD:fastonoff_button_group=fastonoffbuttonA,fastonoffbuttonB,fastonoffbuttonC,fastonoffbuttonD:button_group=keypadbuttonA,keypadbuttonB,keypadbuttonC,keypadbuttonD
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.13 ->pk:F00.00.13|model:2672-222|desc:LED Bulb|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer:rampdimmer=RampDimmer_3435|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.19 ->pk:F00.00.19|model:2457D2|desc:LampLinc Dimmer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.18 ->pk:F00.00.18|model:2441TH|desc:Insteon Thermostat|features:tempcelsius=ThermostatTemperatureCelsius:humidityhigh=ThermostatHumidityHigh:tempfahrenheit=ThermostatTemperatureFahrenheit:stage1duration=ThermostatStage1Duration:humiditylow=ThermostatHumidityLow:systemmode=ThermostatSystemMode:isheating=ThermostatIsHeating:fanmode=ThermostatFanMode:iscooling=ThermostatIsCooling:heatsetpoint=ThermostatHeatSetPoint:coolsetpoint=ThermostatCoolSetPoint:humidity=ThermostatHumidity:lastheardfrom=GenericLastTime:acdelay=ThermostatACDelay:backlightduration=ThermostatBackLightDuration|groups:data1b_group=humidityhigh,humiditylow,stage1duration:data2_group=coolsetpoint,heatsetpoint,systemmode,fanmode,isheating,iscooling,tempcelsius,tempfahrenheit,humidity:data1_group=backlightduration,acdelay
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- 0x00001A ->pk:0x00001A|model:2450|desc:IO Link|features:contact=IOLincContact:lastheardfrom=GenericLastTime:switch=IOLincSwitch|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.i.d.DeviceTypeLoader[:175]- F00.00.17 ->pk:F00.00.17|model:2423A1|desc:iMeter Solo Power Meter|features:meter=PowerMeter:lastheardfrom=GenericLastTime|groups
2016-11-10 09:41:10 DEBUG o.o.b.i.internal.driver.Port[:436]- found modem 3C.D4.82 in device_types: 3C.D4.82|broadcastonoff->GroupBroadcastOnOff(0:1:0)
2016-11-10 09:41:10 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x69|
2016-11-10 09:41:11 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:3D.44.19|LinkData1:0x01|LinkData2:0x2A|LinkData3:0x45|
2016-11-10 09:41:11 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:12 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:3D.44.19|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2016-11-10 09:41:12 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:13 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:3D.88.42|LinkData1:0x01|LinkData2:0x42|LinkData3:0x45|
2016-11-10 09:41:17 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:18 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:3D.88.42|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2016-11-10 09:41:18 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:19 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:3D.91.6E|LinkData1:0x01|LinkData2:0x42|LinkData3:0x45|
2016-11-10 09:41:19 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:20 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:3D.91.6E|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2016-11-10 09:41:20 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:21 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:3D.C4.F4|LinkData1:0x01|LinkData2:0x41|LinkData3:0x45|
2016-11-10 09:41:21 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:22 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:3D.C4.F4|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2016-11-10 09:41:22 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:23 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:3F.8C.53|LinkData1:0x01|LinkData2:0x2E|LinkData3:0x45|
2016-11-10 09:41:23 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:24 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:3F.8C.C8|LinkData1:0x01|LinkData2:0x2E|LinkData3:0x45|
2016-11-10 09:41:24 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:25 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:41.A9.4E|LinkData1:0x01|LinkData2:0x20|LinkData3:0x45|
2016-11-10 09:41:25 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:25 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item FrontPorchLight binding changed: addr=3D.44.19|prodKey:F00.00.02|feature:switch
2016-11-10 09:41:25 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item OutdoorOutlet binding changed: addr=3B.A7.60|prodKey:F00.00.1A|feature:switch
2016-11-10 09:41:25 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item EntryLightKeypad binding changed: addr=3D.88.42|prodKey:F00.00.15|feature:loaddimmer
2016-11-10 09:41:25 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton3(0:1:6)
2016-11-10 09:41:25 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton4(0:1:6)
2016-11-10 09:41:25 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton5(0:1:6)
2016-11-10 09:41:25 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton6(0:1:6)
2016-11-10 09:41:25 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item EntryFanKeypad binding changed: addr=3D.91.6E|prodKey:F00.00.15|feature:loaddimmer
2016-11-10 09:41:25 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton3(0:1:6)
2016-11-10 09:41:25 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton4(0:1:6)
2016-11-10 09:41:25 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton5(0:1:6)
2016-11-10 09:41:25 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton6(0:1:6)
2016-11-10 09:41:25 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item LivingRoomKeypad binding changed: addr=3D.C4.F4|prodKey:F00.00.16|feature:loaddimmer
2016-11-10 09:41:25 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton2(0:1:6)
2016-11-10 09:41:25 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton3(0:1:6)
2016-11-10 09:41:25 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton4(0:1:6)
2016-11-10 09:41:25 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton5(0:1:6)
2016-11-10 09:41:25 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton6(0:1:6)
2016-11-10 09:41:25 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton7(0:1:6)
2016-11-10 09:41:25 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton8(0:1:6)
2016-11-10 09:41:25 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item FrontLivingRoomFanLight binding changed: addr=3F.8C.C8|prodKey:F00.00.1C|feature:lightdimmer
2016-11-10 09:41:25 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item FrontLivingRoomFanSpeed binding changed: addr=3F.8C.C8|prodKey:F00.00.1C|feature:fan
2016-11-10 09:41:25 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item RearLivingRoomFanLight binding changed: addr=3F.8C.53|prodKey:F00.00.1C|feature:lightdimmer
2016-11-10 09:41:25 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item RearLivingRoomFanSpeed binding changed: addr=3F.8C.53|prodKey:F00.00.1C|feature:fan
2016-11-10 09:41:25 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item DiningKeypadDimmer binding changed: addr=43.5D.5E|prodKey:F00.00.16|feature:loaddimmer
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton2(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton3(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton4(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton5(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton6(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton7(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton8(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item DiningFanLight binding changed: addr=3F.4C.7F|prodKey:F00.00.1C|feature:lightdimmer
2016-11-10 09:41:26 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item DiningFanSpeed binding changed: addr=3F.4C.7F|prodKey:F00.00.1C|feature:fan
2016-11-10 09:41:26 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item LaundryLightKeypadDimmer binding changed: addr=43.6A.A9|prodKey:F00.00.15|feature:loaddimmer
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton3(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton4(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton5(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton6(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item KitchenLightOnOffKeypad binding changed: addr=43.97.A4|prodKey:F00.00.14|feature:loadswitch
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- manualchange_button_group connected feature: ManualChangeButton3(0:1:2)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- manualchange_button_group connected feature: ManualChangeButton4(0:1:2)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- manualchange_button_group connected feature: ManualChangeButton5(0:1:2)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- manualchange_button_group connected feature: ManualChangeButton6(0:1:2)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- fastonoff_button_group connected feature: FastOnOffButton3(0:1:2)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- fastonoff_button_group connected feature: FastOnOffButton4(0:1:2)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- fastonoff_button_group connected feature: FastOnOffButton5(0:1:2)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- fastonoff_button_group connected feature: FastOnOffButton6(0:1:2)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton3(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton4(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton5(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton6(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item CounterLightDimmerKeypad binding changed: addr=43.63.96|prodKey:F00.00.15|feature:loaddimmer
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton3(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton4(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton5(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton6(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item BackdoorDimmerKeypad binding changed: addr=43.68.C0|prodKey:F00.00.15|feature:loaddimmer
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton3(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton4(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton5(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton6(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item StairwayDimmer binding changed: addr=41.A9.4E|prodKey:F00.00.01|feature:dimmer
2016-11-10 09:41:26 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item HallwayKeypad binding changed: addr=3D.80.E7|prodKey:F00.00.16|feature:loaddimmer
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton2(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton3(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton4(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton5(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton6(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton7(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton8(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item MasterBedroomKeypad binding changed: addr=40.CB.1D|prodKey:F00.00.16|feature:loaddimmer
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton2(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton3(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton4(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton5(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton6(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton7(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.i.device.InsteonDevice[:463]- button_group connected feature: KeyPadButton8(0:1:6)
2016-11-10 09:41:26 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item MasterBedroomFanLight binding changed: addr=28.2B.88|prodKey:F00.00.1C|feature:lightdimmer
2016-11-10 09:41:26 DEBUG o.o.b.i.InsteonPLMActiveBinding[:220]- item MasterBedroomFanSpeed binding changed: addr=28.2B.88|prodKey:F00.00.1C|feature:fan
2016-11-10 09:41:26 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:41.A9.4E|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2016-11-10 09:41:26 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:27 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:43.5D.5E|LinkData1:0x01|LinkData2:0x41|LinkData3:0x45|
2016-11-10 09:41:27 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:28 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:43.5D.5E|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2016-11-10 09:41:28 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:29 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:43.6A.A9|LinkData1:0x01|LinkData2:0x42|LinkData3:0x45|
2016-11-10 09:41:29 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:38 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:43.6A.A9|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2016-11-10 09:41:38 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:39 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x01|LinkAddr:43.97.A4|LinkData1:0x01|LinkData2:0x2C|LinkData3:0x44|
2016-11-10 09:41:39 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:40 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:43.97.A4|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2016-11-10 09:41:40 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:41 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:43.63.96|LinkData1:0x01|LinkData2:0x42|LinkData3:0x45|
2016-11-10 09:41:41 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:42 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:43.63.96|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
2016-11-10 09:41:48 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:48 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xE2|ALLLinkGroup:0x00|LinkAddr:43.68.C0|LinkData1:0x01|LinkData2:0x42|LinkData3:0x45|
2016-11-10 09:41:48 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (0): OUT:Cmd:0x6A|
2016-11-10 09:41:49 DEBUG o.o.b.i.InsteonPLMActiveBinding[:581]- got msg: IN:Cmd:0x57|RecordFlags:0xA2|ALLLinkGroup:0x01|LinkAddr:43.68.C0|LinkData1:0x00|LinkData2:0x00|LinkData3:0x00|
On a side note, how do you embed the log in the message like you did on your post? I can’t find the getting started topic for the forum.
I don’t have a hub, but from what i can tell, it looks like the binding is talking to the hub. Do you have devices paired? Here’s what shows up in my logs:
2016-11-04 15:20:31.739 [INFO ] [.o.b.i.InsteonPLMActiveBinding] - config: port_0 -> /dev/ttyUSB0
2016-11-04 15:20:31.747 [INFO ] [.service.AbstractActiveService] - InsteonPLM has been started
2016-11-04 15:20:31.809 [INFO ] [.o.b.i.InsteonPLMActiveBinding] - devices: 0 configured, 0 polling, msgs received: 0
2016-11-04 15:20:32.038 [INFO ] [.o.b.i.InsteonPLMActiveBinding] - config: service.pid -> org.openhab.insteonplm
2016-11-04 15:20:32.605 [INFO ] [.o.b.i.i.driver.SerialIOStream] - successfully opened port /dev/ttyUSB0
2016-11-04 15:20:39.722 [INFO ] [.o.b.i.InsteonPLMActiveBinding] - modem database has 61 entries!
2016-11-04 15:20:39.728 [INFO ] [.o.b.i.InsteonPLMActiveBinding] - device 23.9F.C9 found in the modem database and the modem controls groups [0xFE] and
responds to groups [0x01].
2016-11-04 15:20:39.738 [INFO ] [.o.b.i.InsteonPLMActiveBinding] - device 24.33.F7 found in the modem database and the modem controls groups [0xFE] and
responds to groups [0x01].
Maybe @Bernd_Pfrommer can help, but one of the first things he’ll ask is to turn off DEBUG. INFO is all that is needed.
BTW, I used the preformatted button, or you can put 4 spaces in front of a line for it to show up as preformatted
I’ll include both my OpenHAB.log and insteonPLM.log files to look through. It does keep saying it can’t get the modem database which seems concerning but I can still control things:
Openhab.log:
2016-11-10 10:50:22.562 [INFO ] [.DefaultJettyAtJettyHomeHelper] - Configuring the default jetty server with file:/usr/share/openhab/etc/jetty.xml
2016-11-10 10:50:22.898 [INFO ] [rg.eclipse.jetty.server.Server] - jetty-8.1.3.v20120522
2016-11-10 10:50:22.954 [INFO ] [.e.jetty.server.NCSARequestLog] - Opened /var/log/openhab/2016_11_10.request.log
2016-11-10 10:50:22.994 [INFO ] [o.e.j.d.p.ScanningAppProvider ] - Deployment monitor /etc/openhab/jetty/contexts at interval 5
2016-11-10 10:50:23.004 [INFO ] [o.e.j.d.p.ScanningAppProvider ] - Deployment monitor /usr/share/openhab/webapps at interval 5
2016-11-10 10:50:23.011 [INFO ] [jetty.deploy.DeploymentManager] - Deployable added: /usr/share/openhab/webapps/static
2016-11-10 10:50:23.274 [INFO ] [jetty.deploy.DeploymentManager] - Deployable added: /usr/share/openhab/webapps/images
2016-11-10 10:50:23.298 [INFO ] [o.e.j.d.p.ScanningAppProvider ] - Deployment monitor /etc/openhab/jetty/contexts at interval 5
2016-11-10 10:50:23.344 [INFO ] [jetty.server.AbstractConnector] - Started SelectChannelConnector@0.0.0.0:8080
2016-11-10 10:50:24.227 [INFO ] [tty.util.ssl.SslContextFactory] - Enabled Protocols [SSLv2Hello, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
2016-11-10 10:50:24.254 [INFO ] [jetty.server.AbstractConnector] - Started SslSelectChannelConnector@0.0.0.0:8443
2016-11-10 10:50:24.314 [INFO ] [jetty.deploy.DeploymentManager] - Deployable added: org.eclipse.jetty.osgi.httpservice-8.1.3.qualifier/contexts/httpservice.xml
2016-11-10 10:50:24.523 [INFO ] [uartz.impl.StdSchedulerFactory] - Using default implementation for ThreadExecutor
2016-11-10 10:50:24.592 [INFO ] [rtz.core.SchedulerSignalerImpl] - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2016-11-10 10:50:24.594 [INFO ] [rg.quartz.core.QuartzScheduler] - Quartz Scheduler v.2.1.7 created.
2016-11-10 10:50:24.600 [INFO ] [org.quartz.simpl.RAMJobStore ] - RAMJobStore initialized.
2016-11-10 10:50:24.605 [INFO ] [rg.quartz.core.QuartzScheduler] - 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.
2016-11-10 10:50:24.610 [INFO ] [uartz.impl.StdSchedulerFactory] - Quartz scheduler 'openHAB-job-scheduler' initialized from specified file: '/etc/openhab/quartz.properties'
2016-11-10 10:50:24.612 [INFO ] [uartz.impl.StdSchedulerFactory] - Quartz scheduler version: 2.1.7
2016-11-10 10:50:24.614 [INFO ] [rg.quartz.core.QuartzScheduler] - Scheduler openHAB-job-scheduler_$_NON_CLUSTERED started.
2016-11-10 10:50:26.383 [INFO ] [.o.core.internal.CoreActivator] - openHAB runtime has been started (v1.8.3).
2016-11-10 10:50:29.199 [INFO ] [o.o.i.s.i.DiscoveryServiceImpl] - mDNS service has been started
2016-11-10 10:50:29.317 [INFO ] [o.o.i.s.i.DiscoveryServiceImpl] - Service Discovery initialization completed.
2016-11-10 10:50:32.130 [INFO ] [org.atmosphere.util.IOUtils ] - META-INF/services/org.atmosphere.cpr.AtmosphereFramework not found in class loader
2016-11-10 10:50:32.449 [INFO ] [.a.h.ReflectorServletProcessor] - Installing Servlet com.sun.jersey.spi.container.servlet.ServletContainer
2016-11-10 10:50:32.753 [INFO ] [c.s.j.s.i.a.WebApplicationImpl] - Initiating Jersey application, version 'Jersey: 1.18.1 02/19/2014 03:28 AM'
2016-11-10 10:50:32.759 [INFO ] [c.s.j.s.i.a.WebApplicationImpl] - Adding the following classes declared in META-INF/services/jersey-server-components to the resource configuration:
class org.atmosphere.jersey.AtmosphereResourceConfigurator
2016-11-10 10:50:32.894 [INFO ] [j.s.i.a.DeferredResourceConfig] - Instantiated the Application class org.openhab.io.rest.RESTApplication
2016-11-10 10:50:34.595 [INFO ] [penhab.io.rest.RESTApplication] - Started REST API at /rest
2016-11-10 10:50:40.075 [INFO ] [.o.u.w.i.servlet.WebAppServlet] - Started Classic UI at /classicui/openhab.app
2016-11-10 10:50:44.863 [INFO ] [.b.a.internal.bus.AstroBinding] - AstroConfig[latitude=40.036262,longitude=-76.325031,interval=60,systemTimezone=America/New_York (EST -0500),daylightSavings=false]
2016-11-10 10:50:44.868 [INFO ] [.service.AbstractActiveService] - NTP Refresh Service has been started
2016-11-10 10:50:44.968 [WARN ] [.p.m.i.MysqlPersistenceService] - The SQL database URL is missing - please configure the sql:url parameter in openhab.cfg
2016-11-10 10:50:44.984 [INFO ] [.service.AbstractActiveService] - Nest Refresh Service has been started
2016-11-10 10:50:45.004 [INFO ] [.service.AbstractActiveService] - NetworkHealth Refresh Service has been started
2016-11-10 10:50:45.175 [INFO ] [.service.AbstractActiveService] - InsteonPLM has been started
2016-11-10 10:50:46.797 [INFO ] [.myopenhab.internal.MyOHClient] - Connected to my.openHAB service (UUID = ea566781-6bd1-4a68-828e-775964bcbfb9, local base URL = http://localhost:8080)
2016-11-10 10:50:47.923 [INFO ] [.b.a.internal.job.JobScheduler] - Scheduled a daily job at midnight for astro calculation
2016-11-10 10:50:48.313 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'default.sitemap'
2016-11-10 10:50:48.929 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'mysql.persist'
2016-11-10 10:50:48.969 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'myopenhab.persist'
2016-11-10 10:50:49.179 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'Hallway.rules'
2016-11-10 10:50:49.402 [WARN ] [c.internal.ModelRepositoryImpl] - Configuration model 'Hallway.rules' is either empty or cannot be parsed correctly!
2016-11-10 10:50:49.421 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'WhatsOn.rules'
2016-11-10 10:50:49.548 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'LivingRoom.rules'
2016-11-10 10:50:49.724 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'Presence.rules'
2016-11-10 10:50:49.850 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'HomeState.rules'
2016-11-10 10:50:49.855 [WARN ] [c.internal.ModelRepositoryImpl] - Configuration model 'HomeState.rules' is either empty or cannot be parsed correctly!
2016-11-10 10:50:49.860 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'Thermostat.rules'
2016-11-10 10:50:51.509 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'MasterBedroom.rules'
2016-11-10 10:50:51.512 [WARN ] [c.internal.ModelRepositoryImpl] - Configuration model 'MasterBedroom.rules' is either empty or cannot be parsed correctly!
2016-11-10 10:50:51.516 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'Startup.rules'
2016-11-10 10:50:51.589 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'LightsOnRefresh.script'
2016-11-10 10:50:51.829 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'Thermostat.items'
2016-11-10 10:50:51.905 [ERROR] [i.internal.GenericItemProvider] - Binding configuration of type 'nest' of item ‘NestTFamilyRoom_Time_To_Target‘ could not be parsed correctly.
org.openhab.model.item.binding.BindingConfigParseException: Config for item 'NestTFamilyRoom_Time_To_Target' could not be parsed.
at org.openhab.binding.nest.internal.NestGenericBindingProvider.validateItemType(NestGenericBindingProvider.java:155) ~[na:na]
at org.openhab.model.item.internal.GenericItemProvider.internalDispatchBindings(GenericItemProvider.java:347) [org.openhab.model.item_1.8.3.jar:na]
at org.openhab.model.item.internal.GenericItemProvider.internalDispatchBindings(GenericItemProvider.java:324) [org.openhab.model.item_1.8.3.jar:na]
at org.openhab.model.item.internal.GenericItemProvider.processBindingConfigsFromModel(GenericItemProvider.java:171) [org.openhab.model.item_1.8.3.jar:na]
at org.openhab.model.item.internal.GenericItemProvider.modelChanged(GenericItemProvider.java:390) [org.openhab.model.item_1.8.3.jar:na]
at org.openhab.model.core.internal.ModelRepositoryImpl.notifyListeners(ModelRepositoryImpl.java:159) [org.openhab.model.core_1.8.3.jar:na]
at org.openhab.model.core.internal.ModelRepositoryImpl.addOrRefreshModel(ModelRepositoryImpl.java:85) [org.openhab.model.core_1.8.3.jar:na]
at org.openhab.model.core.internal.folder.FolderObserver.checkFolder(FolderObserver.java:142) [org.openhab.model.core_1.8.3.jar:na]
at org.openhab.model.core.internal.folder.FolderObserver.run(FolderObserver.java:99) [org.openhab.model.core_1.8.3.jar:na]
2016-11-10 10:50:51.942 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'Home.items'
2016-11-10 10:50:55.144 [INFO ] [.b.a.internal.job.JobScheduler] - Deleting astro job: Season
2016-11-10 10:51:02.526 [INFO ] [.b.a.internal.job.JobScheduler] - Deleting astro job: DailyJob
2016-11-10 10:51:02.536 [INFO ] [.b.a.internal.job.JobScheduler] - Scheduled a daily job at midnight for astro calculation
2016-11-10 10:54:50.223 [WARN ] [inding.ntp.internal.NtpBinding] - couldn't establish network connection [host '0.us.pool.ntp.org'] -> returning current sytem time instead
instonplm.log:
2016-11-10 10:50:45 INFO o.o.b.i.InsteonPLMActivator[:34]- Insteon PLM binding has been started.
2016-11-10 10:50:45 INFO o.o.b.i.InsteonPLMActiveBinding[:290]- poll interval set to 150000 per config file
2016-11-10 10:50:45 INFO o.o.b.i.InsteonPLMActiveBinding[:313]- dead device timeout set to 1500s
2016-11-10 10:50:45 INFO o.o.b.i.InsteonPLMActiveBinding[:364]- config: poll_interval -> 150000
2016-11-10 10:50:45 INFO o.o.b.i.InsteonPLMActiveBinding[:364]- config: port_0 -> /hub2/Letholdu:tiib5ALW@192.168.1.9:25105,poll_time=1000
2016-11-10 10:50:45 INFO o.o.b.i.InsteonPLMActiveBinding[:670]- devices: 0 configured, 0 polling, msgs received: 0
2016-11-10 10:50:45 INFO o.o.b.i.InsteonPLMActiveBinding[:364]- config: service.pid -> org.openhab.insteonplm
2016-11-10 10:52:45 WARN o.o.b.i.i.d.ModemDBBuilder[:74]- modem database download unsuccessful, restarting!
2016-11-10 10:54:45 WARN o.o.b.i.i.d.ModemDBBuilder[:74]- modem database download unsuccessful, restarting!
2016-11-10 10:56:45 WARN o.o.b.i.i.d.ModemDBBuilder[:74]- modem database download unsuccessful, restarting!
2016-11-10 10:58:45 WARN o.o.b.i.i.d.ModemDBBuilder[:74]- modem database download unsuccessful, restarting!
2016-11-10 11:00:45 INFO o.o.b.i.InsteonPLMActiveBinding[:670]- devices: 17 configured, 0 polling, msgs received: 591
2016-11-10 11:00:45 WARN o.o.b.i.i.d.ModemDBBuilder[:74]- modem database download unsuccessful, restarting!Did you link the Insteon devices with the hub? http://www.insteon.com/support-knowledgebase/2015/1/28/understanding-linking. If not link the devices both way and restart OH.
I used the Android app to link all of the switches and lights into the hub. I assumed that app did the linking in both directions. Maybe I’m wrong about that but everything responds ok.
OK so I found out why it wasn’t updating. The database retry timeout was set too short, so I upped it to 300000 and now I’m pulling in the device data. The only issue I’m having is it’s SUPER slow. I only have 18 devices but it’s taking 8 seconds per device to update on startup. Is there any way to make this happen quicker? I know I could change the poll interval but I don’t want to modify it too much and increase the load. Any suggestions are appreciated.
Thanks
The way the poll works is to divide the interval by the number of devices. This was done to prevent a flood of messages at startup, as the Insteon protocol seems to really not like that. After that, devices should update OpenHAB on their own as toggled, but just to keep things consistent, they are re-polled as well, using the same interval trick. If you want them to be polled faster, decrease the time for polling and they will have less time between, but do this with the knowledge that you will increase the insteon traffic on your network when the binding repeats the cycle because every poll of all devices will be happening with that new interval.
Is there any fancy networking equipment between the hub and the host that is running openhab? Like a firewall or router? It shouldn’t be that slow. The old hub had an issue with larger modem databases, but with 18 devices yours is not that big. There is a small chance this could be some packet size mismatch between the hub and your openhab machine. Maybe run some tcpdump to see what the network traffic looks like.
The only thing I have is a netgear router. I’ll do some network analytics and see what’s happening on the network. As far as I know it’s just the raspberry pi -> router <-Insteon Hub. But I’ll verify. It might explain why my rules are not updating as well.