[SOLVED] Insteon 1.8 Thermostat reports high temp

I have downloaded the latest 1.8 build for OpenHAB and InsteonPLM binding now when I look at my temperature log I have erroneous reading from both thermostats almost 100 degrees f above actual sometimes it reads right. The humidity is reading correctly every time. When I was on the 1.7 binding this never happened. Here is a image of the graph. Has anyone else ran into this problem?

Did you change the syntax of the .items file? It has changed (see insteonplm wiki).

Yes I have updated the items file. before the update it would not read at all.

    /* Climate items */

Number  FF_Temperature     "Downstairs Temperature [%.2f °F]"   	    <temperature>	(Insteon, Weather_Chart,  Climate, Temperature, FF_Living, FF_T)	{ insteonplm="20.46.59:F00.00.18#tempfahrenheit" }
Number  FF_Humidity        "Downstairs Humidity [%d %%]"     		<humidity>			    (Insteon, Humidity_Chart,  Climate ,Humidity, FF_Living, FF_H)		{ insteonplm="20.46.59:F00.00.18#humidity" }
Number  FF_Cool_SetPoint   "Cool SetPoint [%.1f°F]" 					(Insteon, Climate ,FF_Living)				{ insteonplm="20.46.59:F00.00.18#coolsetpoint" }
Number  FF_Heat_SetPoint   "Heat SetPoint [%.1f°F]"  					(Insteon, Climate ,FF_Living)				{ insteonplm="20.46.59:F00.00.18#heatsetpoint" }
Number  FF_Thermostat_FanMode       "Fan"          					    (Insteon, FF_Living)				{ insteonplm="20.46.59:F00.00.18#fanmode" }
Number  FF_Thermostat_OpMode        "Mode"         					    (Insteon, FF_Living)				{ insteonplm="20.46.59:F00.00.18#systemmode" }
//Number  FF_Thermostat_MasterMode    "Master Mode"   					(Insteon, FF_Living)				{ insteonplm="20.46.59:F00.00.18#mastercontrol" }

Number  SF_Temperature     "Upstairs Temperature [%.2f °F]"       	 <temperature>	(Insteon, Weather_Chart, Climate ,Temperature, SF_Corridor, SF_T)	{ insteonplm="2F.81.31:F00.00.18#tempfahrenheit" }
Number  SF_Humidity        "Upstairs Humidity [%d %%]"         	<humidity>				(Insteon, Humidity_Chart, Climate ,Humidity, SF_Corridor, SF_H)	{ insteonplm="2F.81.31:F00.00.18#humidity" }
Number  SF_Cool_SetPoint   "Cool SetPoint [%.1f°F]"  					(Insteon, Climate ,SF_Corridor)				{ insteonplm="2F.81.31:F00.00.18#coolsetpoint" }
Number  SF_Heat_SetPoint   "Heat SetPoint [%.1f°F]"						(Insteon, Climate ,SF_Corridor)				{ insteonplm="2F.81.31:F00.00.18#heatsetpoint" }
Number  SF_Thermostat_FanMode       "Fan"    					        (Insteon, SF_Corridor)				{ insteonplm="2F.81.31:F00.00.18#fanmode" }
Number  SF_Thermostat_OpMode        "Mode" 						        (Insteon, SF_Corridor)				{ insteonplm="2F.81.31:F00.00.18#systemmode" }
//Number  SF_Thermostat_MasterMode    "Master Mode"  						(Insteon, SF_Corridor)				{ insteonplm="2F.81.31:F00.00.18#mastercontrol" }

I assume you have the 2441TH thermostat. I’ve been using that for weeks now without any outlier data in either temp or humidity.
Please switch on debug logging and post the section of the log where the offending numbers are published to the openhab bus (look at events.log first to find the exact time stamp when the bad data came in). I need to see the insteon message that triggered it.

I think I see it is receiving the F value as Celsius and converting it to F again.

10:27:08.699 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:522  ] - got msg: IN:Cmd:0x50|fromAddress:20.46.59|toAddress:1E.4C.C5|messageFlags:0x01=DIRECT:1:0|command1:0x6E|command2:0x8E|
10:27:08.699 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatTemperatureCelsius->NumberMsgHandler DIRECT
10:27:08.715 [DEBUG] [o.o.b.i.i.device.DeviceFeature:263  ] - 20.46.59:ThermostatTemperatureCelsius publishing: 71
10:27:08.715 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatHumidityHigh->NoOpMsgHandler DIRECT
10:27:08.730 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatTemperatureFahrenheit->NumberMsgHandler DIRECT
10:27:08.746 [DEBUG] [o.o.b.i.i.device.DeviceFeature:263  ] - 20.46.59:ThermostatTemperatureFahrenheit publishing: 159.80000000000001136868377216160297393798828125
10:27:08.746 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatStage1Duration->NoOpMsgHandler DIRECT
10:27:08.761 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatHumidityLow->NoOpMsgHandler DIRECT
10:27:08.761 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatSystemMode->NoOpMsgHandler DIRECT
10:27:08.777 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatIsHeating->NoOpMsgHandler DIRECT
10:27:08.793 [DEBUG] [.p.m.i.MysqlPersistenceService:409  ] - mySQL: Stored item 'Temperature' as '114.8000000000000042632564145606011152267456054688'[114.8000000000000042632564145606011152267456054688] in SQL database at Wed Oct 21 10:27:08 CDT 2015.
10:27:08.793 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatFanMode->NoOpMsgHandler DIRECT
10:27:08.808 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatIsCooling->NoOpMsgHandler DIRECT
10:27:08.808 [DEBUG] [.p.m.i.MysqlPersistenceService:411  ] - mySQL: query: INSERT INTO Item19 (TIME, VALUE) VALUES(NOW(),?) ON DUPLICATE KEY UPDATE VALUE=?;
10:27:08.839 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatHeatSetPoint->NoOpMsgHandler DIRECT
10:27:08.839 [DEBUG] [.p.m.i.MysqlPersistenceService:409  ] - mySQL: Stored item 'FF_T' as '159.80000000000001136868377216160297393798828125'[159.80000000000001136868377216160297393798828125] in SQL database at Wed Oct 21 10:27:08 CDT 2015.
10:27:08.855 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatCoolSetPoint->NoOpMsgHandler DIRECT
10:27:08.855 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatHumidity->NoOpMsgHandler DIRECT
10:27:08.871 [DEBUG] [.p.m.i.MysqlPersistenceService:411  ] - mySQL: query: INSERT INTO Item55 (TIME, VALUE) VALUES(NOW(),?) ON DUPLICATE KEY UPDATE VALUE=?;
10:27:08.886 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatACDelay->NoOpMsgHandler DIRECT
10:27:08.886 [DEBUG] [.p.m.i.MysqlPersistenceService:409  ] - mySQL: Stored item 'FF_Temperature' as '159.80000000000001136868377216160297393798828125'[159.80000000000001136868377216160297393798828125] in SQL database at Wed Oct 21 10:27:08 CDT 2015.

here is a good command recieved.

09:35:34.942 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:522  ] - got msg: IN:Cmd:0x51|fromAddress:20.46.59|toAddress:1E.4C.C5|messageFlags:0x11=DIRECT:1:0|command1:0x2E|command2:0x02|userData1:0x01|userData2:0x03|userData3:0x09|userData4:0x2F|userData5:0x26|userData6:0x11|userData7:0x48|userData8:0x40|userData9:0x00|userData10:0xDA|userData11:0xC0|userData12:0x30|userData13:0xE4|userData14:0x04|
09:35:34.958 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatTemperatureCelsius->NumberMsgHandler DIRECT
09:35:34.973 [DEBUG] [o.o.b.i.i.device.DeviceFeature:263  ] - 20.46.59:ThermostatTemperatureCelsius publishing: 21.800000000000000710542735760100185871124267578125
09:35:34.973 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatTemperatureFahrenheit->NumberMsgHandler DIRECT
09:35:34.989 [DEBUG] [o.o.b.i.i.device.DeviceFeature:263  ] - 20.46.59:ThermostatTemperatureFahrenheit publishing: 71.240000000000009094947017729282379150390625
09:35:35.005 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatSystemMode->ThermostatSystemModeMsgHandler DIRECT
09:35:35.005 [DEBUG] [o.o.b.i.i.device.DeviceFeature:263  ] - 20.46.59:ThermostatSystemMode publishing: 3
09:35:35.020 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatIsHeating->NumberMsgHandler DIRECT
09:35:35.036 [DEBUG] [o.o.b.i.i.device.DeviceFeature:263  ] - 20.46.59:ThermostatIsHeating publishing: 0
09:35:35.036 [DEBUG] [.p.m.i.MysqlPersistenceService:409  ] - mySQL: Stored item 'Temperature' as '70.96999999999999886313162278383970260620117188'[70.96999999999999886313162278383970260620117188] in SQL database at Wed Oct 21 09:35:35 CDT 2015.
09:35:35.051 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatFanMode->NumberMsgHandler DIRECT
09:35:35.051 [DEBUG] [.p.m.i.MysqlPersistenceService:411  ] - mySQL: query: INSERT INTO Item19 (TIME, VALUE) VALUES(NOW(),?) ON DUPLICATE KEY UPDATE VALUE=?;
09:35:35.067 [DEBUG] [o.o.b.i.i.device.DeviceFeature:263  ] - 20.46.59:ThermostatFanMode publishing: 1
09:35:35.083 [DEBUG] [.p.m.i.MysqlPersistenceService:409  ] - mySQL: Stored item 'FF_T' as '71.240000000000009094947017729282379150390625'[71.240000000000009094947017729282379150390625] in SQL database at Wed Oct 21 09:35:35 CDT 2015.
09:35:35.083 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatIsCooling->NumberMsgHandler DIRECT
09:35:35.098 [DEBUG] [o.o.b.i.i.device.DeviceFeature:263  ] - 20.46.59:ThermostatIsCooling publishing: 0
09:35:35.098 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatHeatSetPoint->NumberMsgHandler DIRECT
09:35:35.114 [DEBUG] [o.o.b.i.i.device.DeviceFeature:263  ] - 20.46.59:ThermostatHeatSetPoint publishing: 48
09:35:35.114 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatCoolSetPoint->NumberMsgHandler DIRECT
09:35:35.129 [DEBUG] [.p.m.i.MysqlPersistenceService:411  ] - mySQL: query: INSERT INTO Item55 (TIME, VALUE) VALUES(NOW(),?) ON DUPLICATE KEY UPDATE VALUE=?;
09:35:35.145 [DEBUG] [.p.m.i.MysqlPersistenceService:409  ] - mySQL: Stored item 'FF_Temperature' as '71.240000000000009094947017729282379150390625'[71.240000000000009094947017729282379150390625] in SQL database at Wed Oct 21 09:35:35 CDT 2015.

Could this be a problem with the persistence rather than with the binding? I can’t see the line where the binding would be publishing the wrong value.
Never mind: see it now. Let me look at it.

71C = 159.8F

What is your thermostat displaying in, C or Fahrenheit?

F I also notice that the are two different commands the bad one was command 0x50 and the one that worked was 0x51

The status reports (0x6e) come in as Fahrenheit numbers. The binding is processing them as Celsius. BUG!
I don’t see it in my system because I never get the 0x6e status messages. Must be some setup error on my production modem that covered up the bug.
Working on it.

1 Like

Awesome. Thanks!

The fix was really simple, but for the life of it I cannot get my thermostat to send out the temperature messages (I worked it with a hair dryer to change the temperature, it just won’t send it).

So I have blind fix for you. Please try this jar file and see if it does any good. Check your logs for an incoming 0x6e message and see if it gets handled correctly. Thanks!

https://drive.google.com/open?id=0B8OtzwATWQSWTUU3aWphZVMteUU

Sorry, the first jar file did not contain the fix! I uploaded a new file and updated the link.

Now humidity stopped recieving updates

I’m running the very same jar file and humidity is working, both via polling and unsolicited status updates. Do you see any messages come in?

it actually looks like it started then shutdown.

13:00:06.951 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:169  ] - deactivating binding!
13:00:06.951 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:390  ] - shutting down binding
13:00:06.967 [DEBUG] [o.o.b.i.internal.driver.Port  :164  ] - waiting for read thread to exit for port COM9
13:00:06.967 [ERROR] [o.o.b.i.internal.driver.Port  :402  ] - got interrupted exception in write thread
13:00:06.967 [DEBUG] [o.o.b.i.internal.driver.Port  :408  ] - exiting writer thread!
13:00:07.754 [DEBUG] [o.o.b.i.internal.driver.Port  :251  ] - reader thread got interrupted!
13:00:07.759 [ERROR] [o.o.b.i.internal.driver.Port  :253  ] - reader thread exiting!
13:00:07.780 [DEBUG] [o.o.b.i.internal.driver.Port  :171  ] - waiting for write thread to exit for port COM9
13:00:07.792 [DEBUG] [o.o.b.i.internal.driver.Port  :178  ] - all threads for port COM9 stopped.
13:00:08.004 [DEBUG] [i.i.device.RequestQueueManager:76   ] - stopping thread
13:00:08.016 [DEBUG] [i.i.device.RequestQueueManager:143  ] - exiting request queue thread!
13:00:08.016 [DEBUG] [i.i.device.RequestQueueManager:83   ] - waiting for thread to join
13:00:08.040 [DEBUG] [i.i.device.RequestQueueManager:85   ] - request queue thread exited!
13:00:08.052 [DEBUG] [o.o.b.i.internal.driver.Poller:101  ] - stopping poller!
13:00:08.060 [DEBUG] [o.o.b.i.internal.driver.Poller:187  ] - poll thread exiting
13:00:08.084 [WARN ] [insteonplm.InsteonPLMActivator:43   ] - Insteon PLM binding has been stopped.
13:00:08.558 [INFO ] [insteonplm.InsteonPLMActivator:34   ] - Insteon PLM binding has been started.
13:00:08.605 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Light_FF_Front_Porch (Type=DimmerItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.667 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Light_FF_Fan_Can (Type=DimmerItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.667 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Light_FF_Living_Can (Type=DimmerItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.699 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Light_FF_Dining_Chandelier (Type=DimmerItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.699 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Light_FF_Kitchen_Ceiling (Type=SwitchItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.714 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Light_FF_Bed_Ceiling (Type=DimmerItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.730 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Light_FF_MBath_Ceiling (Type=DimmerItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.761 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Light_FF_David_Closet (Type=DimmerItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.761 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Light_FF_Lisa_Closet (Type=DimmerItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.777 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Light_Garage_Ceiling (Type=SwitchItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.792 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Light_SF_Corridor_Ceiling (Type=DimmerItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.808 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Light_SF_Family_Ceiling (Type=DimmerItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.823 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Light_SF_Lisbeth_Ceiling (Type=DimmerItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.823 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Light_SF_Josie_Ceiling (Type=DimmerItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.839 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Fan_FF_Living (Type=NumberItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.855 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Motion_FF_David_Closet (Type=ContactItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.855 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Motion_FF_Lisa_Closet (Type=ContactItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.870 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Window_SF_Josie (Type=ContactItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.886 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Garage_Door_L (Type=ContactItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.886 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'Garage_Entry_Door (Type=ContactItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.901 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'FF_Temperature (Type=NumberItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.917 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'FF_Humidity (Type=NumberItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.917 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'FF_Cool_SetPoint (Type=NumberItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.933 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'FF_Heat_SetPoint (Type=NumberItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.948 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'FF_Thermostat_FanMode (Type=NumberItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.948 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'FF_Thermostat_OpMode (Type=NumberItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.964 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'FF_Thermostat_MasterMode (Type=NumberItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.979 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'SF_Temperature (Type=NumberItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.979 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'SF_Humidity (Type=NumberItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.995 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'SF_Cool_SetPoint (Type=NumberItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:08.995 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'SF_Heat_SetPoint (Type=NumberItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:09.011 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'SF_Thermostat_FanMode (Type=NumberItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:09.026 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'SF_Thermostat_OpMode (Type=NumberItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:09.042 [DEBUG] [i.internal.GenericItemProvider:341  ] - Start processing binding configuration of Item 'SF_Thermostat_MasterMode (Type=NumberItem, State=Uninitialized)' with 'InsteonPLMGenericBindingProvider' reader.
13:00:09.073 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:155  ] - activating binding
13:00:09.151 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:262  ] - global binding config has arrived.
13:00:09.182 [INFO ] [.o.b.i.InsteonPLMActiveBinding:278  ] - refresh interval set to 600s
13:00:09.198 [INFO ] [.o.b.i.InsteonPLMActiveBinding:287  ] - poll interval set to 300000 per config file
13:00:09.213 [INFO ] [.o.b.i.InsteonPLMActiveBinding:310  ] - dead device timeout set to 3000s
13:00:09.213 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:266  ] - configuration update complete!
13:00:09.229 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:349  ] - initializing...
13:00:09.245 [INFO ] [.o.b.i.InsteonPLMActiveBinding:361  ] - config: poll_interval -> 300000
13:00:09.245 [INFO ] [.service.AbstractActiveService:169  ] - InsteonPLM has been started
13:00:09.245 [INFO ] [.o.b.i.InsteonPLMActiveBinding:361  ] - config: port_0 -> COM9
13:00:09.276 [DEBUG] [o.o.b.i.internal.driver.Driver:75   ] - added new port: port_0 COM9
13:00:09.276 [INFO ] [.o.b.i.InsteonPLMActiveBinding:603  ] - devices:   0 configured,   0 polling, msgs received:     0
13:00:09.276 [INFO ] [.o.b.i.InsteonPLMActiveBinding:361  ] - config: refresh -> 600000
13:00:09.276 [DEBUG] [o.o.b.i.internal.driver.Poller:176  ] - starting poll thread.
13:00:09.291 [INFO ] [.o.b.i.InsteonPLMActiveBinding:361  ] - config: service.pid -> org.openhab.insteonplm
13:00:09.307 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:367  ] - setting driver listener
13:00:09.323 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:369  ] - starting 0 ports
13:00:09.338 [DEBUG] [o.o.b.i.internal.driver.Port  :132  ] - starting port COM9
13:00:09.354 [ERROR] [.o.b.i.i.driver.SerialIOStream:76   ] - got no such port for COM9
13:00:09.369 [DEBUG] [o.o.b.i.internal.driver.Port  :137  ] - failed to open port COM9
13:00:09.385 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:371  ] - ports started
13:00:09.401 [ERROR] [.o.b.i.InsteonPLMActiveBinding:374  ] - initialization complete, but found no ports!
13:00:09.401 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item SF_Cool_SetPoint               binding changed: addr=2F.81.31|prodKey:F00.00.18|feature:coolsetpoint
13:00:09.447 [DEBUG] [.b.i.i.device.DeviceTypeLoader:195  ] - loaded 40 devices: 
13:00:09.471 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - 0x000041  ->pk:0x000041|model:2484DWH8|desc:KeypadLinc Countdown Timer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
13:00:09.483 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.0A ->pk:F00.00.0A|model:2852-222|desc:Leak Sensor|features:contact=LeakSensorContact:lastheardfrom=GenericLastTime|groups
13:00:09.488 [DEBUG] [.b.i.i.device.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
13:00:09.504 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - 0x000049  ->pk:0x000049|model:2843-222|desc:Wireless Open/Close Sensor|features:contact=GenericContact:lastheardfrom=GenericLastTime|groups
13:00:09.504 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.0C ->pk:F00.00.0C|model:2476D|desc:SwitchLinc Dimmer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
13:00:09.522 [DEBUG] [.b.i.i.device.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
13:00:09.522 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - 0x000068  ->pk:0x000068|model:2472D|desc:OutletLincDimmer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
13:00:09.537 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - 0x000045  ->pk:0x000045|model:2413U|desc:PowerLinc 2413U USB modem|features:broadcastonoff=GroupBroadcastOnOff|groups
13:00:09.537 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - 0x00004A  ->pk:0x00004A|model:2842-222|desc:Motion Sensor|features:data=MotionSensorData:contact=WirelessMotionSensorContact:lastheardfrom=GenericLastTime|groups
13:00:09.553 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.01 ->pk:F00.00.01|model:2477D|desc:SwitchLinc Dimmer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
13:00:09.569 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.05 ->pk:F00.00.05|model:2456D3|desc:LampLinc V2|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
13:00:09.569 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.04 ->pk:F00.00.04|model:2876S|desc:ICON Switch|features:lastheardfrom=GenericLastTime:switch=GenericSwitch|groups
13:00:09.584 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.03 ->pk:F00.00.03|model:2845-222|desc:Hidden Door Sensor|features:data=HiddenDoorSensorData:contact=WirelessMotionSensorContact:lastheardfrom=GenericLastTime|groups
13:00:09.600 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.02 ->pk:F00.00.02|model:2477S|desc:SwitchLinc Switch|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:switch=GenericSwitch|groups
13:00:09.600 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.09 ->pk:F00.00.09|model:2458-A1|desc:MorningLinc RF Lock Controller|features:switch=GenericSwitch|groups
13:00:09.615 [DEBUG] [.b.i.i.device.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
13:00:09.615 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.07 ->pk:F00.00.07|model:2453-222|desc:DIN Rail On/Off|features:lastheardfrom=GenericLastTime:switch=GenericSwitch|groups
13:00:09.631 [DEBUG] [.b.i.i.device.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
13:00:09.647 [DEBUG] [.b.i.i.device.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|groups:button_group=keypadbuttonB,keypadbuttonC,keypadbuttonD,keypadbuttonE,keypadbuttonF,keypadbuttonG,keypadbuttonH
13:00:09.662 [DEBUG] [.b.i.i.device.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|groups:button_group=keypadbuttonA,keypadbuttonB,keypadbuttonC,keypadbuttonD
13:00:09.678 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.1B ->pk:F00.00.1B|model:2635-222|desc:On/Off Module|features:lastheardfrom=GenericLastTime:switch=GenericSwitch|groups
13:00:09.693 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.1A ->pk:F00.00.1A|model:2475SDB|desc:In-LineLinc Relay|features:lastheardfrom=GenericLastTime:switch=GenericSwitch|groups
13:00:09.693 [DEBUG] [.b.i.i.device.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|groups
13:00:09.709 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.1D ->pk:F00.00.1D|model:2456S3|desc:ApplianceLinc|features:lastheardfrom=GenericLastTime:switch=GenericSwitch|groups
13:00:09.725 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - 0x000037  ->pk:0x000037|model:2486D|desc:KeypadLinc Dimmer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
13:00:09.725 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.1C ->pk:F00.00.1C|model:2475F|desc:FanLinc Module|features:fan=FanLincFan:lightdimmer=GenericDimmer:lastheardfrom=GenericLastTime|groups
13:00:09.740 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.12 ->pk:F00.00.12|model:2466S|desc:ToggleLinc Switch|features:lastheardfrom=GenericLastTime:switch=GenericSwitch|groups
13:00:09.740 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.11 ->pk:F00.00.11|model:2466D|desc:ToggleLinc Dimmer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
13:00:09.756 [DEBUG] [.b.i.i.device.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
13:00:09.771 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - X00.00.03 ->pk:X00.00.03|model:X10 motion sensor|desc:Generic X10 motion sensor|features:contact=X10Contact|groups
13:00:09.771 [DEBUG] [.b.i.i.device.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|groups:button_group=keypadbuttonB,keypadbuttonC,keypadbuttonD,keypadbuttonE,keypadbuttonF,keypadbuttonG,keypadbuttonH
13:00:09.803 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - X00.00.02 ->pk:X00.00.02|model:X10 dimmer|desc:Generic X10 Dimmer without preset|features:dimmer=X10Dimmer:switch=X10Switch|groups
13:00:09.803 [DEBUG] [.b.i.i.device.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|groups:button_group=keypadbuttonA,keypadbuttonB,keypadbuttonC,keypadbuttonD
13:00:09.818 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - X00.00.01 ->pk:X00.00.01|model:X10 switch|desc:any simple X10 switch|features:switch=X10Switch|groups
13:00:09.834 [DEBUG] [.b.i.i.device.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
13:00:09.865 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.13 ->pk:F00.00.13|model:2672-222|desc:LED Bulb|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
13:00:09.881 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.19 ->pk:F00.00.19|model:2457D2|desc:LampLinc Dimmer|features:fastonoff=FastOnOff:lastheardfrom=GenericLastTime:manualchange=ManualChange:dimmer=GenericDimmer|groups
13:00:09.896 [DEBUG] [.b.i.i.device.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
13:00:09.927 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - 0x00001A  ->pk:0x00001A|model:2450|desc:IO Link|features:contact=IOLincContact:lastheardfrom=GenericLastTime:switch=IOLincSwitch|groups
13:00:09.943 [DEBUG] [.b.i.i.device.DeviceTypeLoader:175  ] - F00.00.17 ->pk:F00.00.17|model:2423A1|desc:iMeter Solo Power Meter|features:meter=PowerMeter:lastheardfrom=GenericLastTime|groups
13:00:09.977 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data1b_group connected feature: ThermostatHumidityHigh(0:1:2)
13:00:09.992 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data1b_group connected feature: ThermostatHumidityLow(0:1:2)
13:00:10.008 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data1b_group connected feature: ThermostatStage1Duration(0:1:2)
13:00:10.023 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatCoolSetPoint(0:1:3)
13:00:10.039 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatHeatSetPoint(0:1:3)
13:00:10.039 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatSystemMode(0:1:3)
13:00:10.055 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatFanMode(0:1:3)
13:00:10.070 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatIsHeating(0:0:3)
13:00:10.093 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatIsCooling(0:0:3)
13:00:10.106 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatTemperatureCelsius(0:0:2)
13:00:10.118 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatTemperatureFahrenheit(0:0:2)
13:00:10.131 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatHumidity(0:0:2)
13:00:10.141 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data1_group connected feature: ThermostatBackLightDuration(0:1:2)
13:00:10.158 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data1_group connected feature: ThermostatACDelay(0:1:2)
13:00:10.163 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Light_SF_Josie_Ceiling         binding changed: addr=30.42.C0|prodKey:F00.00.01|feature:dimmer
13:00:10.179 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Light_FF_MBath_Ceiling         binding changed: addr=29.47.05|prodKey:F00.00.16|feature:loaddimmer
13:00:10.197 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton2(0:1:6)
13:00:10.197 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton3(0:1:6)
13:00:10.213 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton4(0:1:6)
13:00:10.228 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton5(0:1:6)
13:00:10.228 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton6(0:1:6)
13:00:10.244 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton7(0:1:6)
13:00:10.244 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton8(0:1:6)
13:00:10.259 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Light_FF_Kitchen_Ceiling       binding changed: addr=20.81.71|prodKey:F00.00.02|feature:switch
13:00:10.275 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Light_FF_Front_Porch           binding changed: addr=1D.F5.EB|prodKey:F00.00.16|feature:loaddimmer
13:00:10.291 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton2(0:1:6)
13:00:10.306 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton3(0:1:6)
13:00:10.322 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton4(0:1:6)
13:00:10.322 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton5(0:1:6)
13:00:10.337 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton6(0:1:6)
13:00:10.353 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton7(0:1:6)
13:00:10.353 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton8(0:1:6)
13:00:10.369 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Light_Garage_Ceiling           binding changed: addr=20.83.26|prodKey:F00.00.02|feature:switch
13:00:10.400 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Fan_FF_Living                  binding changed: addr=23.3E.B9|prodKey:F00.00.1C|feature:fan
13:00:10.415 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Light_SF_Family_Ceiling        binding changed: addr=29.49.2D|prodKey:F00.00.16|feature:loaddimmer
13:00:10.415 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton2(0:1:6)
13:00:10.431 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton3(0:1:6)
13:00:10.447 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton4(0:1:6)
13:00:10.462 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton5(0:1:6)
13:00:10.462 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton6(0:1:6)
13:00:10.478 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton7(0:1:6)
13:00:10.493 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton8(0:1:6)
13:00:10.493 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Light_FF_Lisa_Closet           binding changed: addr=28.F8.93|prodKey:F00.00.01|feature:dimmer
13:00:10.509 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item SF_Heat_SetPoint               binding changed: addr=2F.81.31|prodKey:F00.00.18|feature:heatsetpoint
13:00:10.525 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Light_SF_Lisbeth_Ceiling       binding changed: addr=30.3F.3F|prodKey:F00.00.01|feature:dimmer
13:00:10.540 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Motion_FF_David_Closet         binding changed: addr=21.59.A3|prodKey: 0x00004A|feature:contact
13:00:10.556 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item SF_Temperature                 binding changed: addr=2F.81.31|prodKey:F00.00.18|feature:tempfahrenheit
13:00:10.556 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item SF_Thermostat_MasterMode       binding changed: addr=2F.81.31|prodKey:F00.00.18|feature:mastercontrol
13:00:10.571 [ERROR] [.o.b.i.InsteonPLMActiveBinding:502  ] - item SF_Thermostat_MasterMode references unknown feature: mastercontrol, item disabled!
13:00:10.587 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item SF_Humidity                    binding changed: addr=2F.81.31|prodKey:F00.00.18|feature:humidity
13:00:10.587 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Light_FF_Dining_Chandelier     binding changed: addr=20.AC.EA|prodKey:F00.00.01|feature:dimmer
13:00:10.603 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Light_FF_David_Closet          binding changed: addr=28.FD.33|prodKey:F00.00.01|feature:dimmer
13:00:10.618 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item FF_Heat_SetPoint               binding changed: addr=20.46.59|prodKey:F00.00.18|feature:heatsetpoint
13:00:10.618 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data1b_group connected feature: ThermostatHumidityHigh(0:1:2)
13:00:10.634 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data1b_group connected feature: ThermostatHumidityLow(0:1:2)
13:00:10.649 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data1b_group connected feature: ThermostatStage1Duration(0:1:2)
13:00:10.649 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatCoolSetPoint(0:1:3)
13:00:10.665 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatHeatSetPoint(0:1:3)
13:00:10.665 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatSystemMode(0:1:3)
13:00:10.681 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatFanMode(0:1:3)
13:00:10.696 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatIsHeating(0:0:3)
13:00:10.696 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatIsCooling(0:0:3)
13:00:10.712 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatTemperatureCelsius(0:0:2)
13:00:10.727 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatTemperatureFahrenheit(0:0:2)
13:00:10.727 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data2_group connected feature: ThermostatHumidity(0:0:2)
13:00:10.743 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data1_group connected feature: ThermostatBackLightDuration(0:1:2)
13:00:10.759 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - data1_group connected feature: ThermostatACDelay(0:1:2)
13:00:10.759 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Motion_FF_Lisa_Closet          binding changed: addr=14.19.95|prodKey: 0x00004A|feature:contact
13:00:10.774 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Window_SF_Josie                binding changed: addr=25.A8.C3|prodKey: 0x000049|feature:contact
13:00:10.790 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Garage_Door_L                  binding changed: addr=28.C2.7D|prodKey: 0x00001A|feature:contact
13:00:10.805 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Light_SF_Corridor_Ceiling      binding changed: addr=1D.2A.8B|prodKey:F00.00.01|feature:dimmer
13:00:10.805 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item FF_Cool_SetPoint               binding changed: addr=20.46.59|prodKey:F00.00.18|feature:coolsetpoint
13:00:10.821 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item FF_Thermostat_OpMode           binding changed: addr=20.46.59|prodKey:F00.00.18|feature:systemmode
13:00:10.837 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item FF_Thermostat_MasterMode       binding changed: addr=20.46.59|prodKey:F00.00.18|feature:mastercontrol
13:00:10.852 [ERROR] [.o.b.i.InsteonPLMActiveBinding:502  ] - item FF_Thermostat_MasterMode references unknown feature: mastercontrol, item disabled!
13:00:10.852 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item FF_Temperature                 binding changed: addr=20.46.59|prodKey:F00.00.18|feature:tempfahrenheit
13:00:10.868 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item SF_Thermostat_FanMode          binding changed: addr=2F.81.31|prodKey:F00.00.18|feature:fanmode
13:00:10.883 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Light_FF_Bed_Ceiling           binding changed: addr=1D.97.2B|prodKey:F00.00.16|feature:loaddimmer
13:00:10.899 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton2(0:1:6)
13:00:10.899 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton3(0:1:6)
13:00:10.915 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton4(0:1:6)
13:00:10.915 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton5(0:1:6)
13:00:10.930 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton6(0:1:6)
13:00:10.946 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton7(0:1:6)
13:00:10.946 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton8(0:1:6)
13:00:10.961 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item FF_Humidity                    binding changed: addr=20.46.59|prodKey:F00.00.18|feature:humidity
13:00:10.977 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Garage_Entry_Door              binding changed: addr=23.3A.C5|prodKey: 0x000049|feature:contact
13:00:10.993 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Light_FF_Living_Can            binding changed: addr=2A.8E.C7|prodKey:F00.00.16|feature:loaddimmer
13:00:10.993 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton2(0:1:6)
13:00:11.008 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton3(0:1:6)
13:00:11.024 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton4(0:1:6)
13:00:11.024 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton5(0:1:6)
13:00:11.039 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton6(0:1:6)
13:00:11.055 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton7(0:1:6)
13:00:11.071 [DEBUG] [o.o.b.i.i.device.InsteonDevice:463  ] - button_group connected feature: KeyPadButton8(0:1:6)
13:00:11.071 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item FF_Thermostat_FanMode          binding changed: addr=20.46.59|prodKey:F00.00.18|feature:fanmode
13:00:11.086 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item Light_FF_Fan_Can               binding changed: addr=23.3E.B9|prodKey:F00.00.1C|feature:lightdimmer
13:00:11.102 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:217  ] - item SF_Thermostat_OpMode           binding changed: addr=2F.81.31|prodKey:F00.00.18|feature:systemmode
13:06:41.267 [INFO ] [.service.AbstractActiveService:181  ] - InsteonPLM has been shut down

I’m restarting OH server and seeing what it’s gonna do. Been a hectic day so I haven’t had much time to troubleshoot.

I spy something about mastercontrol in the log. That feature has been
removed. You may want to update your .items file.
I never had the binding shut down by itself. That’s probably done by the
framework.

That seems to have done the trick. the first restart was that I just dropped the new file in the folder and the addon reload but it didn’t close the serial port graciously so when it restarted the port was still bound up. After I shut OH down completely and then restarted OH it seems to be working now.

I thought I had commented out the master control lines. i’ll look again.

22:00:35.666 [DEBUG] [.o.b.i.InsteonPLMActiveBinding:522  ] - got msg: IN:Cmd:0x50|fromAddress:20.46.59|toAddress:1E.4C.C5|messageFlags:0x01=DIRECT:1:0|command1:0x6E|command2:0x8A|
22:00:35.682 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatTemperatureCelsius->NumberMsgHandler DIRECT
22:00:35.682 [DEBUG] [o.o.b.i.i.device.DeviceFeature:263  ] - 20.46.59:ThermostatTemperatureCelsius publishing: 20.555558600000001234775481862016022205352783203125
22:00:35.698 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatHumidityHigh->NoOpMsgHandler DIRECT
22:00:35.698 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatTemperatureFahrenheit->NumberMsgHandler DIRECT
22:00:35.713 [DEBUG] [o.o.b.i.i.device.DeviceFeature:263  ] - 20.46.59:ThermostatTemperatureFahrenheit publishing: 69
22:00:35.729 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatStage1Duration->NoOpMsgHandler DIRECT
22:00:35.744 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatHumidityLow->NoOpMsgHandler DIRECT
22:00:35.744 [DEBUG] [.p.m.i.MysqlPersistenceService:409  ] - mySQL: Stored item 'Temperature' as '69.84999999999999431565811391919851303100585938'[69.84999999999999431565811391919851303100585938] in SQL database at Thu Oct 22 22:00:35 CDT 2015.
22:00:35.760 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatSystemMode->NoOpMsgHandler DIRECT
22:00:35.776 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatIsHeating->NoOpMsgHandler DIRECT
22:00:35.776 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatFanMode->NoOpMsgHandler DIRECT
22:00:35.791 [DEBUG] [.p.m.i.MysqlPersistenceService:411  ] - mySQL: query: INSERT INTO Item19 (TIME, VALUE) VALUES(NOW(),?) ON DUPLICATE KEY UPDATE VALUE=?;
22:00:35.807 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatIsCooling->NoOpMsgHandler DIRECT
22:00:35.822 [DEBUG] [.p.m.i.MysqlPersistenceService:409  ] - mySQL: Stored item 'FF_T' as '69'[69] in SQL database at Thu Oct 22 22:00:35 CDT 2015.
22:00:35.822 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatHeatSetPoint->NoOpMsgHandler DIRECT
22:00:35.838 [DEBUG] [.p.m.i.MysqlPersistenceService:411  ] - mySQL: query: INSERT INTO Item55 (TIME, VALUE) VALUES(NOW(),?) ON DUPLICATE KEY UPDATE VALUE=?;
22:00:35.854 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatCoolSetPoint->NoOpMsgHandler DIRECT
22:00:35.869 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatHumidity->NoOpMsgHandler DIRECT
22:00:35.885 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatACDelay->NoOpMsgHandler DIRECT
22:00:35.885 [DEBUG] [.p.m.i.MysqlPersistenceService:409  ] - mySQL: Stored item 'FF_Temperature' as '69'[69] in SQL database at Thu Oct 22 22:00:35 CDT 2015.
22:00:35.885 [DEBUG] [b.i.i.device.MessageDispatcher:151  ] - 20.46.59:ThermostatBackLightDuration->NoOpMsgHandler DIRECT
22:00:35.900 [DEBUG] [o.o.b.i.i.device.DeviceFeature:263  ] - 20.46.59:GenericLastTime publishing: 2015-10-22T22:00:35
22:00:35.916 [DEBUG] [.p.m.i.MysqlPersistenceService:411  ] - mySQL: query: INSERT INTO Item46 (TIME, VALUE) VALUES(NOW(),?) ON DUPLICATE KEY UPDATE VALUE=?;