Binding Modbus 2.5.7. Stops working after unsuccessful read attempt

Add-ons Bindings
, ,
63

The following is the rest of the result from “http://localhost:8080/rest/things” from the previous post.

{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di3:lastReadError","id":"lastReadError","channelTypeUID":"modbus:last-erroring-read-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Read","description":"Date of last read error","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di3:lastWriteSuccess","id":"lastWriteSuccess","channelTypeUID":"modbus:last-successful-write-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Write","description":"Date of last write","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di3:lastWriteError","id":"lastWriteError","channelTypeUID":"modbus:last-erroring-write-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Write","description":"Date of last write error","defaultTags":[],"properties":{},"configuration":{}}]},{"statusInfo":{"status":"ONLINE","statusDetail":"NONE"},"editable":false,"label":"Modbus Data","bridgeUID":"modbus:poller:HVAC:hvacpoll","configuration":{"readValueType":"bit","readTransform":"default","writeTransform":"default","readStart":"32768.6","updateUnchangedValuesEveryMillis":1000,"writeMultipleEvenWithSingleRegisterOrCoil":false,"writeMaxTries":3},"properties":{},"UID":"modbus:data:HVAC:hvacpoll:di6","thingTypeUID":"modbus:data","channels":[{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di6:number","id":"number","channelTypeUID":"modbus:number-type","itemType":"Number","kind":"STATE","label":"Value as Number","description":"Number item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":["Turck_i6"],"uid":"modbus:data:HVAC:hvacpoll:di6:switch","id":"switch","channelTypeUID":"modbus:switch-type","itemType":"Switch","kind":"STATE","label":"Value as Switch","description":"Switch item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di6:contact","id":"contact","channelTypeUID":"modbus:contact-type","itemType":"Contact","kind":"STATE","label":"Value as Contact","description":"Contact item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di6:dimmer","id":"dimmer","channelTypeUID":"modbus:dimmer-type","itemType":"Dimmer","kind":"STATE","label":"Value as Dimmer","description":"Dimmer item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di6:datetime","id":"datetime","channelTypeUID":"modbus:datetime-type","itemType":"DateTime","kind":"STATE","label":"Value as DateTime","description":"DateTime item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di6:string","id":"string","channelTypeUID":"modbus:string-type","itemType":"String","kind":"STATE","label":"Value as String","description":"String item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di6:rollershutter","id":"rollershutter","channelTypeUID":"modbus:rollershutter-type","itemType":"Rollershutter","kind":"STATE","label":"Value as Rollershutter","description":"Rollershutter item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di6:lastReadSuccess","id":"lastReadSuccess","channelTypeUID":"modbus:last-successful-read-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Read","description":"Date of last read","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di6:lastReadError","id":"lastReadError","channelTypeUID":"modbus:last-erroring-read-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Read","description":"Date of last read error","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di6:lastWriteSuccess","id":"lastWriteSuccess","channelTypeUID":"modbus:last-successful-write-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Write","description":"Date of last write","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di6:lastWriteError","id":"lastWriteError","channelTypeUID":"modbus:last-erroring-write-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Write","description":"Date of last write error","defaultTags":[],"properties":{},"configuration":{}}]},{"statusInfo":{"status":"ONLINE","statusDetail":"NONE"},"editable":false,"label":"Modbus Data","bridgeUID":"modbus:poller:HVAC:hvacpoll","configuration":{"readValueType":"bit","readTransform":"default","writeTransform":"default","readStart":"32768.5","updateUnchangedValuesEveryMillis":1000,"writeMultipleEvenWithSingleRegisterOrCoil":false,"writeMaxTries":3},"properties":{},"UID":"modbus:data:HVAC:hvacpoll:di5","thingTypeUID":"modbus:data","channels":[{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di5:number","id":"number","channelTypeUID":"modbus:number-type","itemType":"Number","kind":"STATE","label":"Value as Number","description":"Number item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":["Turck_i5"],"uid":"modbus:data:HVAC:hvacpoll:di5:switch","id":"switch","channelTypeUID":"modbus:switch-type","itemType":"Switch","kind":"STATE","label":"Value as Switch","description":"Switch item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di5:contact","id":"contact","channelTypeUID":"modbus:contact-type","itemType":"Contact","kind":"STATE","label":"Value as Contact","description":"Contact item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di5:dimmer","id":"dimmer","channelTypeUID":"modbus:dimmer-type","itemType":"Dimmer","kind":"STATE","label":"Value as Dimmer","description":"Dimmer item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di5:datetime","id":"datetime","channelTypeUID":"modbus:datetime-type","itemType":"DateTime","kind":"STATE","label":"Value as DateTime","description":"DateTime item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di5:string","id":"string","channelTypeUID":"modbus:string-type","itemType":"String","kind":"STATE","label":"Value as String","description":"String item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di5:rollershutter","id":"rollershutter","channelTypeUID":"modbus:rollershutter-type","itemType":"Rollershutter","kind":"STATE","label":"Value as Rollershutter","description":"Rollershutter item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di5:lastReadSuccess","id":"lastReadSuccess","channelTypeUID":"modbus:last-successful-read-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Read","description":"Date of last read","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di5:lastReadError","id":"lastReadError","channelTypeUID":"modbus:last-erroring-read-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Read","description":"Date of last read error","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di5:lastWriteSuccess","id":"lastWriteSuccess","channelTypeUID":"modbus:last-successful-write-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Write","description":"Date of last write","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di5:lastWriteError","id":"lastWriteError","channelTypeUID":"modbus:last-erroring-write-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Write","description":"Date of last write error","defaultTags":[],"properties":{},"configuration":{}}]},{"statusInfo":{"status":"ONLINE","statusDetail":"NONE"},"editable":false,"label":"Modbus Data","bridgeUID":"modbus:poller:HVAC:hvacpoll","configuration":{"readValueType":"bit","readTransform":"default","writeTransform":"default","readStart":"32768.8","updateUnchangedValuesEveryMillis":1000,"writeMultipleEvenWithSingleRegisterOrCoil":false,"writeMaxTries":3},"properties":{},"UID":"modbus:data:HVAC:hvacpoll:di8","thingTypeUID":"modbus:data","channels":[{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di8:number","id":"number","channelTypeUID":"modbus:number-type","itemType":"Number","kind":"STATE","label":"Value as Number","description":"Number item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":["Turck_i8"],"uid":"modbus:data:HVAC:hvacpoll:di8:switch","id":"switch","channelTypeUID":"modbus:switch-type","itemType":"Switch","kind":"STATE","label":"Value as Switch","description":"Switch item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di8:contact","id":"contact","channelTypeUID":"modbus:contact-type","itemType":"Contact","kind":"STATE","label":"Value as Contact","description":"Contact item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di8:dimmer","id":"dimmer","channelTypeUID":"modbus:dimmer-type","itemType":"Dimmer","kind":"STATE","label":"Value as Dimmer","description":"Dimmer item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di8:datetime","id":"datetime","channelTypeUID":"modbus:datetime-type","itemType":"DateTime","kind":"STATE","label":"Value as DateTime","description":"DateTime item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di8:string","id":"string","channelTypeUID":"modbus:string-type","itemType":"String","kind":"STATE","label":"Value as String","description":"String item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di8:rollershutter","id":"rollershutter","channelTypeUID":"modbus:rollershutter-type","itemType":"Rollershutter","kind":"STATE","label":"Value as Rollershutter","description":"Rollershutter item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di8:lastReadSuccess","id":"lastReadSuccess","channelTypeUID":"modbus:last-successful-read-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Read","description":"Date of last read","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di8:lastReadError","id":"lastReadError","channelTypeUID":"modbus:last-erroring-read-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Read","description":"Date of last read error","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di8:lastWriteSuccess","id":"lastWriteSuccess","channelTypeUID":"modbus:last-successful-write-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Write","description":"Date of last write","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di8:lastWriteError","id":"lastWriteError","channelTypeUID":"modbus:last-erroring-write-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Write","description":"Date of last write error","defaultTags":[],"properties":{},"configuration":{}}]},{"statusInfo":{"status":"ONLINE","statusDetail":"NONE"},"editable":false,"label":"Modbus Data","bridgeUID":"modbus:poller:HVAC:hvacpoll","configuration":{"readValueType":"bit","readTransform":"default","writeTransform":"default","readStart":"32768.14","updateUnchangedValuesEveryMillis":1000,"writeMultipleEvenWithSingleRegisterOrCoil":false,"writeMaxTries":3},"properties":{},"UID":"modbus:data:HVAC:hvacpoll:di14","thingTypeUID":"modbus:data","channels":[{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di14:number","id":"number","channelTypeUID":"modbus:number-type","itemType":"Number","kind":"STATE","label":"Value as Number","description":"Number item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":["Turck_i14"],"uid":"modbus:data:HVAC:hvacpoll:di14:switch","id":"switch","channelTypeUID":"modbus:switch-type","itemType":"Switch","kind":"STATE","label":"Value as Switch","description":"Switch item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di14:contact","id":"contact","channelTypeUID":"modbus:contact-type","itemType":"Contact","kind":"STATE","label":"Value as Contact","description":"Contact item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di14:dimmer","id":"dimmer","channelTypeUID":"modbus:dimmer-type","itemType":"Dimmer","kind":"STATE","label":"Value as Dimmer","description":"Dimmer item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di14:datetime","id":"datetime","channelTypeUID":"modbus:datetime-type","itemType":"DateTime","kind":"STATE","label":"Value as DateTime","description":"DateTime item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di14:string","id":"string","channelTypeUID":"modbus:string-type","itemType":"String","kind":"STATE","label":"Value as String","description":"String item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di14:rollershutter","id":"rollershutter","channelTypeUID":"modbus:rollershutter-type","itemType":"Rollershutter","kind":"STATE","label":"Value as Rollershutter","description":"Rollershutter item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di14:lastReadSuccess","id":"lastReadSuccess","channelTypeUID":"modbus:last-successful-read-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Read","description":"Date of last read","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di14:lastReadError","id":"lastReadError","channelTypeUID":"modbus:last-erroring-read-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Read","description":"Date of last read error","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di14:lastWriteSuccess","id":"lastWriteSuccess","channelTypeUID":"modbus:last-successful-write-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Write","description":"Date of last write","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di14:lastWriteError","id":"lastWriteError","channelTypeUID":"modbus:last-erroring-write-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Write","description":"Date of last write error","defaultTags":[],"properties":{},"configuration":{}}]},{"statusInfo":{"status":"ONLINE","statusDetail":"NONE"},"editable":false,"label":"Modbus Data","bridgeUID":"modbus:poller:HVAC:hvacpoll","configuration":{"readValueType":"bit","readTransform":"default","writeTransform":"default","readStart":"32768.7","updateUnchangedValuesEveryMillis":1000,"writeMultipleEvenWithSingleRegisterOrCoil":false,"writeMaxTries":3},"properties":{},"UID":"modbus:data:HVAC:hvacpoll:di7","thingTypeUID":"modbus:data","channels":[{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di7:number","id":"number","channelTypeUID":"modbus:number-type","itemType":"Number","kind":"STATE","label":"Value as Number","description":"Number item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":["Turck_i7"],"uid":"modbus:data:HVAC:hvacpoll:di7:switch","id":"switch","channelTypeUID":"modbus:switch-type","itemType":"Switch","kind":"STATE","label":"Value as Switch","description":"Switch item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di7:contact","id":"contact","channelTypeUID":"modbus:contact-type","itemType":"Contact","kind":"STATE","label":"Value as Contact","description":"Contact item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di7:dimmer","id":"dimmer","channelTypeUID":"modbus:dimmer-type","itemType":"Dimmer","kind":"STATE","label":"Value as Dimmer","description":"Dimmer item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di7:datetime","id":"datetime","channelTypeUID":"modbus:datetime-type","itemType":"DateTime","kind":"STATE","label":"Value as DateTime","description":"DateTime item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di7:string","id":"string","channelTypeUID":"modbus:string-type","itemType":"String","kind":"STATE","label":"Value as String","description":"String item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di7:rollershutter","id":"rollershutter","channelTypeUID":"modbus:rollershutter-type","itemType":"Rollershutter","kind":"STATE","label":"Value as Rollershutter","description":"Rollershutter item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di7:lastReadSuccess","id":"lastReadSuccess","channelTypeUID":"modbus:last-successful-read-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Read","description":"Date of last read","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di7:lastReadError","id":"lastReadError","channelTypeUID":"modbus:last-erroring-read-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Read","description":"Date of last read error","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di7:lastWriteSuccess","id":"lastWriteSuccess","channelTypeUID":"modbus:last-successful-write-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Write","description":"Date of last write","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di7:lastWriteError","id":"lastWriteError","channelTypeUID":"modbus:last-erroring-write-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Write","description":"Date of last write error","defaultTags":[],"properties":{},"configuration":{}}]},{"statusInfo":{"status":"ONLINE","statusDetail":"NONE"},"editable":false,"label":"Modbus Data","bridgeUID":"modbus:poller:HVAC:hvacpoll","configuration":{"readValueType":"bit","readTransform":"default","writeTransform":"default","readStart":"32768.15","updateUnchangedValuesEveryMillis":1000,"writeMultipleEvenWithSingleRegisterOrCoil":false,"writeMaxTries":3},"properties":{},"UID":"modbus:data:HVAC:hvacpoll:di15","thingTypeUID":"modbus:data","channels":[{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di15:number","id":"number","channelTypeUID":"modbus:number-type","itemType":"Number","kind":"STATE","label":"Value as Number","description":"Number item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":["Turck_i15"],"uid":"modbus:data:HVAC:hvacpoll:di15:switch","id":"switch","channelTypeUID":"modbus:switch-type","itemType":"Switch","kind":"STATE","label":"Value as Switch","description":"Switch item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di15:contact","id":"contact","channelTypeUID":"modbus:contact-type","itemType":"Contact","kind":"STATE","label":"Value as Contact","description":"Contact item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di15:dimmer","id":"dimmer","channelTypeUID":"modbus:dimmer-type","itemType":"Dimmer","kind":"STATE","label":"Value as Dimmer","description":"Dimmer item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di15:datetime","id":"datetime","channelTypeUID":"modbus:datetime-type","itemType":"DateTime","kind":"STATE","label":"Value as DateTime","description":"DateTime item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di15:string","id":"string","channelTypeUID":"modbus:string-type","itemType":"String","kind":"STATE","label":"Value as String","description":"String item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di15:rollershutter","id":"rollershutter","channelTypeUID":"modbus:rollershutter-type","itemType":"Rollershutter","kind":"STATE","label":"Value as Rollershutter","description":"Rollershutter item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di15:lastReadSuccess","id":"lastReadSuccess","channelTypeUID":"modbus:last-successful-read-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Read","description":"Date of last read","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di15:lastReadError","id":"lastReadError","channelTypeUID":"modbus:last-erroring-read-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Read","description":"Date of last read error","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di15:lastWriteSuccess","id":"lastWriteSuccess","channelTypeUID":"modbus:last-successful-write-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Write","description":"Date of last write","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di15:lastWriteError","id":"lastWriteError","channelTypeUID":"modbus:last-erroring-write-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Write","description":"Date of last write error","defaultTags":[],"properties":{},"configuration":{}}]},{"statusInfo":{"status":"ONLINE","statusDetail":"NONE"},"editable":false,"label":"Modbus Data","bridgeUID":"modbus:poller:HVAC:hvacpoll","configuration":{"readValueType":"bit","readTransform":"default","writeTransform":"default","readStart":"32768.12","updateUnchangedValuesEveryMillis":1000,"writeMultipleEvenWithSingleRegisterOrCoil":false,"writeMaxTries":3},"properties":{},"UID":"modbus:data:HVAC:hvacpoll:di12","thingTypeUID":"modbus:data","channels":[{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di12:number","id":"number","channelTypeUID":"modbus:number-type","itemType":"Number","kind":"STATE","label":"Value as Number","description":"Number item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":["Turck_i12"],"uid":"modbus:data:HVAC:hvacpoll:di12:switch","id":"switch","channelTypeUID":"modbus:switch-type","itemType":"Switch","kind":"STATE","label":"Value as Switch","description":"Switch item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di12:contact","id":"contact","channelTypeUID":"modbus:contact-type","itemType":"Contact","kind":"STATE","label":"Value as Contact","description":"Contact item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di12:dimmer","id":"dimmer","channelTypeUID":"modbus:dimmer-type","itemType":"Dimmer","kind":"STATE","label":"Value as Dimmer","description":"Dimmer item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di12:datetime","id":"datetime","channelTypeUID":"modbus:datetime-type","itemType":"DateTime","kind":"STATE","label":"Value as DateTime","description":"DateTime item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di12:string","id":"string","channelTypeUID":"modbus:string-type","itemType":"String","kind":"STATE","label":"Value as String","description":"String item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di12:rollershutter","id":"rollershutter","channelTypeUID":"modbus:rollershutter-type","itemType":"Rollershutter","kind":"STATE","label":"Value as Rollershutter","description":"Rollershutter item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di12:lastReadSuccess","id":"lastReadSuccess","channelTypeUID":"modbus:last-successful-read-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Read","description":"Date of last read","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di12:lastReadError","id":"lastReadError","channelTypeUID":"modbus:last-erroring-read-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Read","description":"Date of last read error","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di12:lastWriteSuccess","id":"lastWriteSuccess","channelTypeUID":"modbus:last-successful-write-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Write","description":"Date of last write","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di12:lastWriteError","id":"lastWriteError","channelTypeUID":"modbus:last-erroring-write-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Write","description":"Date of last write error","defaultTags":[],"properties":{},"configuration":{}}]},{"statusInfo":{"status":"ONLINE","statusDetail":"NONE"},"editable":false,"label":"Modbus Data","bridgeUID":"modbus:poller:HVAC:hvacpoll","configuration":{"readValueType":"bit","readTransform":"default","writeTransform":"default","readStart":"32768.9","updateUnchangedValuesEveryMillis":1000,"writeMultipleEvenWithSingleRegisterOrCoil":false,"writeMaxTries":3},"properties":{},"UID":"modbus:data:HVAC:hvacpoll:di9","thingTypeUID":"modbus:data","channels":[{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di9:number","id":"number","channelTypeUID":"modbus:number-type","itemType":"Number","kind":"STATE","label":"Value as Number","description":"Number item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":["Turck_i9"],"uid":"modbus:data:HVAC:hvacpoll:di9:switch","id":"switch","channelTypeUID":"modbus:switch-type","itemType":"Switch","kind":"STATE","label":"Value as Switch","description":"Switch item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di9:contact","id":"contact","channelTypeUID":"modbus:contact-type","itemType":"Contact","kind":"STATE","label":"Value as Contact","description":"Contact item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di9:dimmer","id":"dimmer","channelTypeUID":"modbus:dimmer-type","itemType":"Dimmer","kind":"STATE","label":"Value as Dimmer","description":"Dimmer item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di9:datetime","id":"datetime","channelTypeUID":"modbus:datetime-type","itemType":"DateTime","kind":"STATE","label":"Value as DateTime","description":"DateTime item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di9:string","id":"string","channelTypeUID":"modbus:string-type","itemType":"String","kind":"STATE","label":"Value as String","description":"String item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di9:rollershutter","id":"rollershutter","channelTypeUID":"modbus:rollershutter-type","itemType":"Rollershutter","kind":"STATE","label":"Value as Rollershutter","description":"Rollershutter item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di9:lastReadSuccess","id":"lastReadSuccess","channelTypeUID":"modbus:last-successful-read-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Read","description":"Date of last read","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di9:lastReadError","id":"lastReadError","channelTypeUID":"modbus:last-erroring-read-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Read","description":"Date of last read error","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di9:lastWriteSuccess","id":"lastWriteSuccess","channelTypeUID":"modbus:last-successful-write-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Write","description":"Date of last write","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di9:lastWriteError","id":"lastWriteError","channelTypeUID":"modbus:last-erroring-write-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Write","description":"Date of last write error","defaultTags":[],"properties":{},"configuration":{}}]},{"statusInfo":{"status":"ONLINE","statusDetail":"NONE"},"editable":false,"label":"Modbus Data","bridgeUID":"modbus:poller:HVAC:hvacpoll","configuration":{"readValueType":"bit","readTransform":"default","writeTransform":"default","readStart":"32768.13","updateUnchangedValuesEveryMillis":1000,"writeMultipleEvenWithSingleRegisterOrCoil":false,"writeMaxTries":3},"properties":{},"UID":"modbus:data:HVAC:hvacpoll:di13","thingTypeUID":"modbus:data","channels":[{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di13:number","id":"number","channelTypeUID":"modbus:number-type","itemType":"Number","kind":"STATE","label":"Value as Number","description":"Number item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":["Turck_i13"],"uid":"modbus:data:HVAC:hvacpoll:di13:switch","id":"switch","channelTypeUID":"modbus:switch-type","itemType":"Switch","kind":"STATE","label":"Value as Switch","description":"Switch item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di13:contact","id":"contact","channelTypeUID":"modbus:contact-type","itemType":"Contact","kind":"STATE","label":"Value as Contact","description":"Contact item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di13:dimmer","id":"dimmer","channelTypeUID":"modbus:dimmer-type","itemType":"Dimmer","kind":"STATE","label":"Value as Dimmer","description":"Dimmer item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di13:datetime","id":"datetime","channelTypeUID":"modbus:datetime-type","itemType":"DateTime","kind":"STATE","label":"Value as DateTime","description":"DateTime item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di13:string","id":"string","channelTypeUID":"modbus:string-type","itemType":"String","kind":"STATE","label":"Value as String","description":"String item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di13:rollershutter","id":"rollershutter","channelTypeUID":"modbus:rollershutter-type","itemType":"Rollershutter","kind":"STATE","label":"Value as Rollershutter","description":"Rollershutter item channel","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di13:lastReadSuccess","id":"lastReadSuccess","channelTypeUID":"modbus:last-successful-read-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Read","description":"Date of last read","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di13:lastReadError","id":"lastReadError","channelTypeUID":"modbus:last-erroring-read-type","itemType":"DateTime","kind":"STATE","label":"Last Erroring Read","description":"Date of last read error","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di13:lastWriteSuccess","id":"lastWriteSuccess","channelTypeUID":"modbus:last-successful-write-type","itemType":"DateTime","kind":"STATE","label":"Last Successful Write","description":"Date of last write","defaultTags":[],"properties":{},"configuration":{}},{"linkedItems":[],"uid":"modbus:data:HVAC:hvacpoll:di13:lastWriteError","id":"lastWriteError","channelTypeUID":"modbus:last-erroring-write-type","itemType":"DateTime","kind":"STATE","label":"Last
64

You are walloping your TCP slave quite hard. Why not try something a bit less ambitious while sorting out your problems, like 1000?

It seems really unlikely that this could seize up without a report from the binding in your openhab.log

65

Thanks @BHall! Your installation looks good at least.

I still do not understand the issue. Please note that if the data is not changing in modbus slave, there will be no openhab events.

First of all I noticed you have typo in the item definition of the register… This is why only the switches update and not the number. The thing id is typoed, I guess you have changed register numbers at some point? Please correct that first. After you have corrected this, please paste items and things here again to be sure.

Please link lastReadSuccess and lastReadError channels of the reg32768 data thing. This way you can see whether there is communication between the device and openhab…Or whether there is some issue in the binding.

Please also enable verbose logging.

Next time the issue occurs we should have better means to analyze what is really happening using logs, extra channels and the thing status exposed by the http rest api. It would be best to have all the relevant logs, e.g zipped and uploaded to some online service (wetransfer.com, Dropbox, onedrive etc)

66

I do get openhab events when I change a bit in the register, at least for awhile. I do that by pushing a switch on the wall which is wired to a discrete input on my ModbusTCP device. When I spoke of it no longer working, I was referring to when I push on a switch and the change of state no longer shows up in the events log. Once the event logging stops I can restart openhab and then when I change a bit in a register, the change of state will again show up in the events log until it quits again. I hope this makes sense, I am probably doing a poor job of explaining.

Fixed the typo in the item definition of the register and the register now shows up in the events log when a change occurs. Some of the names are not what I will end up with but hopefully ok for now.

I think I have the verbose logging set up.

I am still working on how to properly set up the linking for lastReadSuccess and lastReadError channels of the reg32768 data thing. I thought I would see if I can do this in the file instead of the PaperUI.

I like the idea of zipping up the files instead of all the cutting and pasting to get it in a post especially since size becomes a problem pretty quickly. I will have to work through the posting of the files, I haven’t had much experience with that.

You mentioned pasting items and things again to a post but I assume I should do that after the linking is added. So far the only changes that have been made are:

  1. changing the name of the register in the “hvac.items” file, from “reg32767” to “reg32768”.
  2. changing the “refresh” from 200 to 500 in the “modbus.things” file.

I will try to work on this some more tomorrow evening, need to get a little sleep before going to work in the morning.

I feel real bad about wasting peoples time with my issues here, especially if it is due to my stupidity.

Thanks!

67

Thanks for pointing this out. I started off with 200ms because I think that is about where I am at with my current system, but would have to check to be sure. I had changed the Modbus binding to 500ms but I guess that change got lost with some file copying, etc. I changed it back to 500ms for now. I can go to 1000ms or even higher if necessary for testing.

But in the end I will have to have pretty fast response time, otherwise will be pretty useless since I need to catch the pressing of wall switches in a timely fashion.

Thanks again for your input and ideas.

68

I can assure you that if you want to detect the pulse of a push button you will never always catch it, I have also tried this. 8 out of 10 times it works but this was not good enough for me.
I tried on 1ms and it didn’t always work so it was unreliable.
I finally resolved it like this.
https://community.openhab.org/t/how-to-make-ordinary-push-button-lighting-smart-with-openhab/98513

69

Thank you very much for the information. I will definitely read this to learn about how you resolved your issues.

I have found my existing setup to be satisfactory as far as response time goes.

My reason for looking at openhab is because of all the things people seem to be able to do with it and the strong community. There is so much creativity here. With my existing system I am pretty much on an island so to speak.

My Modbus setup is a single slave device with expandable I/O. It is pretty nice, and compact, but the downside is if the I/O processor were to fail you would loose everything at once.

I do have an Elk system with some remote I/O that I have some stuff on, but that is another story.

Thanks again for the input and information.

70

Sounds good. I think you should then have the following

Number HVAC_Temp "Temp [%d]" { channel="modbus:data:HVAC:hvacpoll:reg32768:number" }

Last read success and error are linked as follows

DateTime HVAC_Temp_Last_Success  "Temp last ok
[%1$tA, %1$td.%1$tm.%1$tY %1$tH:%1$tM:%1$tS
" { channel="modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess" }

DateTime HVAC_Temp_Last_Error "Temp last err
[%1$tA, %1$td.%1$tm.%1$tY %1$tH:%1$tM:%1$tS
" { channel="modbus:data:HVAC:hvacpoll:reg32768:lastReadError" }

There is a certain syntax to channel naming, you will figure it out over time even though it might feel overwhelming at first. When in doubt, I use paper ui myself to get full channel id, and then write it in items file.

Please paste the http things output after you have done these changes, we can verify the links are registered correctly and there is no typos

EDIT: instructions on how enable verbose logging is explained here. Use the log:set command with TRACE

71

Per your request I have modified the hvac.items file to add lastReadSuccess and lastReadError linking. The lastReadSuccess is showing up in the log but oddly enough after over an hour everything is still working. I will shut down openhab for the night due to the tremendious number of log records being created. I believe this is the longest it has ever gone without stopping. I have included my items and things files as they are now. I have also included a small sample of the content in the “events.log” and “openhab.log” files.

hvac.items

Number HVAC_Temp "Temp [%d]" { channel="modbus:data:HVAC:hvacpoll:reg32768:number" }
Switch Turck_i0 "i0 [%s]" { channel="modbus:data:HVAC:hvacpoll:di0:switch" }
Switch Turck_i1 "i1 [%s]" { channel="modbus:data:HVAC:hvacpoll:di1:switch" }
Switch Turck_i2 "i2 [%s]" { channel="modbus:data:HVAC:hvacpoll:di2:switch" }
Switch Turck_i3 "i3 [%s]" { channel="modbus:data:HVAC:hvacpoll:di3:switch" }
Switch Turck_i4 "i4 [%s]" { channel="modbus:data:HVAC:hvacpoll:di4:switch" }
Switch Turck_i5 "i5 [%s]" { channel="modbus:data:HVAC:hvacpoll:di5:switch" }
Switch Turck_i6 "i6 [%s]" { channel="modbus:data:HVAC:hvacpoll:di6:switch" }
Switch Turck_i7 "i7 [%s]" { channel="modbus:data:HVAC:hvacpoll:di7:switch" }
Switch Turck_i8 "i8 [%s]" { channel="modbus:data:HVAC:hvacpoll:di8:switch" }
Switch Turck_i9 "i9 [%s]" { channel="modbus:data:HVAC:hvacpoll:di9:switch" }
Switch Turck_i10 "i10 [%s]" { channel="modbus:data:HVAC:hvacpoll:di10:switch" }
Switch Turck_i11 "i11 [%s]" { channel="modbus:data:HVAC:hvacpoll:di11:switch" }
Switch Turck_i12 "i12 [%s]" { channel="modbus:data:HVAC:hvacpoll:di12:switch" }
Switch Turck_i13 "i13 [%s]" { channel="modbus:data:HVAC:hvacpoll:di13:switch" }
Switch Turck_i14 "i14 [%s]" { channel="modbus:data:HVAC:hvacpoll:di14:switch" }
Switch Turck_i15 "i15 [%s]" { channel="modbus:data:HVAC:hvacpoll:di15:switch" }
DateTime HVAC_Temp_Last_Success  "Temp last ok [%1$tA, %1$td.%1$tm.%1$tY %1$tH:%1$tM:%1$tS" { channel="modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess" }
DateTime HVAC_Temp_Last_Error "Temp last err [%1$tA, %1$td.%1$tm.%1$tY %1$tH:%1$tM:%1$tS" { channel="modbus:data:HVAC:hvacpoll:reg32768:lastReadError" }


modbus.things

Bridge modbus:tcp:HVAC [host="192.168.1.111", port=502, id=1]
{
        Bridge poller hvacpoll [ start=32768, length=1, refresh=500, type="holding" ]
        {
            Thing data reg32768 [readStart="32768", readValueType="int16" ]
            Thing data di0 [readStart="32768.0", readValueType="bit" ]
            Thing data di1 [readStart="32768.1", readValueType="bit" ]
            Thing data di2 [readStart="32768.2", readValueType="bit" ]
            Thing data di3 [readStart="32768.3", readValueType="bit" ]
            Thing data di4 [readStart="32768.4", readValueType="bit" ]
            Thing data di5 [readStart="32768.5", readValueType="bit" ]
            Thing data di6 [readStart="32768.6", readValueType="bit" ]
            Thing data di7 [readStart="32768.7", readValueType="bit" ]
            Thing data di8 [readStart="32768.8", readValueType="bit" ]    
            Thing data di9 [readStart="32768.9", readValueType="bit" ]
            Thing data di10 [readStart="32768.10", readValueType="bit" ]
            Thing data di11 [readStart="32768.11", readValueType="bit" ]
            Thing data di12 [readStart="32768.12", readValueType="bit" ]
            Thing data di13 [readStart="32768.13", readValueType="bit" ]
            Thing data di14 [readStart="32768.14", readValueType="bit" ]
            Thing data di15 [readStart="32768.15", readValueType="bit" ]
        }
}


events.log - small sample from file

2020-08-17 23:46:03.514 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:02.994-0500 to 2020-08-17T23:46:03.513-0500
2020-08-17 23:46:04.045 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:03.513-0500 to 2020-08-17T23:46:04.045-0500
2020-08-17 23:46:04.571 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:04.045-0500 to 2020-08-17T23:46:04.571-0500
2020-08-17 23:46:05.102 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:04.571-0500 to 2020-08-17T23:46:05.102-0500
2020-08-17 23:46:05.655 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:05.102-0500 to 2020-08-17T23:46:05.654-0500
2020-08-17 23:46:06.202 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:05.654-0500 to 2020-08-17T23:46:06.201-0500
2020-08-17 23:46:06.735 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:06.201-0500 to 2020-08-17T23:46:06.735-0500
2020-08-17 23:46:07.253 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:06.735-0500 to 2020-08-17T23:46:07.253-0500
2020-08-17 23:46:07.772 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:07.253-0500 to 2020-08-17T23:46:07.772-0500
2020-08-17 23:46:08.308 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:07.772-0500 to 2020-08-17T23:46:08.307-0500
2020-08-17 23:46:08.856 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:08.307-0500 to 2020-08-17T23:46:08.855-0500
2020-08-17 23:46:09.410 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:08.855-0500 to 2020-08-17T23:46:09.409-0500
2020-08-17 23:46:09.939 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:09.409-0500 to 2020-08-17T23:46:09.938-0500
2020-08-17 23:46:10.477 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:09.938-0500 to 2020-08-17T23:46:10.477-0500
2020-08-17 23:46:11.016 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:10.477-0500 to 2020-08-17T23:46:11.015-0500
2020-08-17 23:46:11.564 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:11.015-0500 to 2020-08-17T23:46:11.564-0500
2020-08-17 23:46:12.096 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:11.564-0500 to 2020-08-17T23:46:12.096-0500
2020-08-17 23:46:12.627 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:12.096-0500 to 2020-08-17T23:46:12.626-0500
2020-08-17 23:46:13.164 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:12.626-0500 to 2020-08-17T23:46:13.162-0500
2020-08-17 23:46:13.695 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:13.162-0500 to 2020-08-17T23:46:13.695-0500
2020-08-17 23:46:14.227 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:13.695-0500 to 2020-08-17T23:46:14.226-0500
2020-08-17 23:46:14.761 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:14.226-0500 to 2020-08-17T23:46:14.760-0500
2020-08-17 23:46:15.291 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:14.760-0500 to 2020-08-17T23:46:15.290-0500
2020-08-17 23:46:15.832 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:15.290-0500 to 2020-08-17T23:46:15.830-0500
2020-08-17 23:46:16.370 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:15.830-0500 to 2020-08-17T23:46:16.369-0500
2020-08-17 23:46:16.899 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:16.369-0500 to 2020-08-17T23:46:16.898-0500
2020-08-17 23:46:17.433 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:16.898-0500 to 2020-08-17T23:46:17.432-0500
2020-08-17 23:46:17.971 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:17.432-0500 to 2020-08-17T23:46:17.969-0500
2020-08-17 23:46:18.510 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32768 to -32512
2020-08-17 23:46:18.511 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:17.969-0500 to 2020-08-17T23:46:18.509-0500
2020-08-17 23:46:18.513 [vent.ItemStateChangedEvent] - Turck_i8 changed from OFF to ON
2020-08-17 23:46:19.039 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32512 to -32768
2020-08-17 23:46:19.039 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:18.509-0500 to 2020-08-17T23:46:19.039-0500
2020-08-17 23:46:19.042 [vent.ItemStateChangedEvent] - Turck_i8 changed from ON to OFF
2020-08-17 23:46:19.565 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:19.039-0500 to 2020-08-17T23:46:19.565-0500
2020-08-17 23:46:20.102 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32768 to -32256
2020-08-17 23:46:20.102 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:19.565-0500 to 2020-08-17T23:46:20.101-0500
2020-08-17 23:46:20.103 [vent.ItemStateChangedEvent] - Turck_i9 changed from OFF to ON
2020-08-17 23:46:20.633 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:20.101-0500 to 2020-08-17T23:46:20.633-0500
2020-08-17 23:46:21.173 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32256 to -32768
2020-08-17 23:46:21.173 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:20.633-0500 to 2020-08-17T23:46:21.170-0500
2020-08-17 23:46:21.175 [vent.ItemStateChangedEvent] - Turck_i9 changed from ON to OFF
2020-08-17 23:46:21.710 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:21.170-0500 to 2020-08-17T23:46:21.709-0500
2020-08-17 23:46:22.246 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:21.709-0500 to 2020-08-17T23:46:22.245-0500
2020-08-17 23:46:22.775 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:22.245-0500 to 2020-08-17T23:46:22.773-0500
2020-08-17 23:46:23.315 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:22.773-0500 to 2020-08-17T23:46:23.314-0500
2020-08-17 23:46:23.844 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:23.314-0500 to 2020-08-17T23:46:23.843-0500
2020-08-17 23:46:24.379 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:23.843-0500 to 2020-08-17T23:46:24.377-0500
2020-08-17 23:46:24.913 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:24.377-0500 to 2020-08-17T23:46:24.913-0500
2020-08-17 23:46:25.442 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:24.913-0500 to 2020-08-17T23:46:25.441-0500
2020-08-17 23:46:25.978 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:25.441-0500 to 2020-08-17T23:46:25.977-0500
2020-08-17 23:46:26.511 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:25.977-0500 to 2020-08-17T23:46:26.510-0500
2020-08-17 23:46:27.051 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:26.510-0500 to 2020-08-17T23:46:27.050-0500
2020-08-17 23:46:27.646 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:27.050-0500 to 2020-08-17T23:46:27.645-0500
2020-08-17 23:46:28.186 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:27.645-0500 to 2020-08-17T23:46:28.186-0500
2020-08-17 23:46:28.716 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:28.186-0500 to 2020-08-17T23:46:28.714-0500
2020-08-17 23:46:29.255 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:28.714-0500 to 2020-08-17T23:46:29.255-0500
2020-08-17 23:46:29.774 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:29.255-0500 to 2020-08-17T23:46:29.774-0500
2020-08-17 23:46:30.308 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:29.774-0500 to 2020-08-17T23:46:30.308-0500
2020-08-17 23:46:30.838 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:30.308-0500 to 2020-08-17T23:46:30.837-0500
2020-08-17 23:46:31.358 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:30.837-0500 to 2020-08-17T23:46:31.358-0500
2020-08-17 23:46:31.881 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:31.358-0500 to 2020-08-17T23:46:31.880-0500
2020-08-17 23:46:32.410 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:31.880-0500 to 2020-08-17T23:46:32.410-0500
2020-08-17 23:46:32.947 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:32.410-0500 to 2020-08-17T23:46:32.946-0500
2020-08-17 23:46:33.482 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:32.946-0500 to 2020-08-17T23:46:33.481-0500
2020-08-17 23:46:34.012 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:33.481-0500 to 2020-08-17T23:46:34.011-0500
2020-08-17 23:46:34.545 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:34.011-0500 to 2020-08-17T23:46:34.543-0500
2020-08-17 23:46:35.086 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:34.543-0500 to 2020-08-17T23:46:35.085-0500
2020-08-17 23:46:35.625 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:35.085-0500 to 2020-08-17T23:46:35.624-0500
2020-08-17 23:46:36.161 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:35.624-0500 to 2020-08-17T23:46:36.160-0500
2020-08-17 23:46:36.682 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:36.160-0500 to 2020-08-17T23:46:36.681-0500
2020-08-17 23:46:37.197 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:36.681-0500 to 2020-08-17T23:46:37.197-0500
2020-08-17 23:46:37.746 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:37.197-0500 to 2020-08-17T23:46:37.745-0500
2020-08-17 23:46:38.282 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:37.745-0500 to 2020-08-17T23:46:38.282-0500
2020-08-17 23:46:38.812 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-17T23:46:38.282-0500 to 2020-08-17T23:46:38.811-0500


openhab.log - small sample from file

ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]. Response was net.wimpi.modbus.msg.ReadMultipleRegistersResponse@1c568862
2020-08-17 23:50:51.036 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502] connection TCPMasterConnection@33f6d054[socket=Socket[addr=/192.168.1.111,port=502,localport=57069]] -> true
2020-08-17 23:50:51.036 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Passivating connection TCPMasterConnection@33f6d054[socket=Socket[addr=/192.168.1.111,port=502,localport=57069]] for endpoint ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502]...
2020-08-17 23:50:51.036 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - (passivate) Connection TCPMasterConnection@33f6d054[socket=Socket[addr=/192.168.1.111,port=502,localport=57069]] (endpoint ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502]) age 36ms is over the reconnectAfterMillis=0ms limit or has been connection time (1597726251000) is after the "disconnectBeforeConnectedMillis"=-1 -> disconnecting.
2020-08-17 23:50:51.036 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - ...Passivated connection TCPMasterConnection@33f6d054[socket=Socket[addr=/192.168.1.111,port=502,localport=57069]] for endpoint ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502]
2020-08-17 23:50:51.037 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - returned connection to pool for endpoint ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502]
2020-08-17 23:50:51.037 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - returning connection for endpoint ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502] took 1 ms
2020-08-17 23:50:51.037 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Connection was returned to the pool, ending operation [operation ID c30de6b6-716e-4b45-b5ba-bc2a0f13cf04]
2020-08-17 23:50:51.037 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 49 ms, connection: 13, transaction=10, callback=20} [operation ID c30de6b6-716e-4b45-b5ba-bc2a0f13cf04]
2020-08-17 23:50:51.037 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Execution of scheduled (500ms) poll task BasicPollTask@3c86225d[request=ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@6c6fa612,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@6c6fa612] finished at 1597726251037. Was started at millis: 1597726250988 (=duration of 49 millis)
2020-08-17 23:50:51.540 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Executing scheduled (500ms) poll task BasicPollTask@3c86225d[request=ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@6c6fa612,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@6c6fa612]. Current millis: 1597726251540
2020-08-17 23:50:51.540 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Starting new operation with task BasicPollTask@3c86225d[request=ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@6c6fa612,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@6c6fa612]. Trying to get connection [operation ID 4162e2d5-d476-41ef-9ccd-f92381856c6b]
2020-08-17 23:50:51.541 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Executing task BasicPollTask@3c86225d[request=ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@6c6fa612,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@6c6fa612] (oneOff=false)! Waiting for connection. Idle connections for this endpoint: 1, and active 0 [operation ID 4162e2d5-d476-41ef-9ccd-f92381856c6b]
2020-08-17 23:50:51.541 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-08-17 23:50:51.547 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Waited 0ms (interTransactionDelayMillis 60ms) before giving returning connection TCPMasterConnection@33f6d054[socket=Socket[addr=/192.168.1.111,port=502,localport=57070]] for endpoint ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502], to ensure delay between transactions.
2020-08-17 23:50:51.547 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - borrowing connection (got Optional[TCPMasterConnection@33f6d054[socket=Socket[addr=/192.168.1.111,port=502,localport=57070]]]) for endpoint ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502] took 6 ms
2020-08-17 23:50:51.548 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Executing task BasicPollTask@3c86225d[request=ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@6c6fa612,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@6c6fa612] (oneOff=false)! Connection received in 7 ms [operation ID 4162e2d5-d476-41ef-9ccd-f92381856c6b]
2020-08-17 23:50:51.549 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Operation with task BasicPollTask@3c86225d[request=ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@6c6fa612,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@6c6fa612]. Got a connection successfully [operation ID 4162e2d5-d476-41ef-9ccd-f92381856c6b]
2020-08-17 23:50:51.549 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 [operation ID 4162e2d5-d476-41ef-9ccd-f92381856c6b]
2020-08-17 23:50:51.550 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping if necessary [operation ID 4162e2d5-d476-41ef-9ccd-f92381856c6b]
2020-08-17 23:50:51.550 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Sleep ended, slept 0 [operation ID 4162e2d5-d476-41ef-9ccd-f92381856c6b]
2020-08-17 23:50:51.551 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 01 03 80 00 00 01  [operation ID 4162e2d5-d476-41ef-9ccd-f92381856c6b]
2020-08-17 23:50:51.551 [TRACE] [wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 9265: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@57516320
2020-08-17 23:50:51.555 [TRACE] [wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 9265
2020-08-17 23:50:51.555 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=9265): 24 31 00 00 00 05 01 03 02 80 00  [operation ID 4162e2d5-d476-41ef-9ccd-f92381856c6b]
2020-08-17 23:50:51.556 [TRACE] [modbus.internal.ModbusLibraryWrapper] - Calling read response callback org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@6c6fa612 for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]. Response was net.wimpi.modbus.msg.ReadMultipleRegistersResponse@34c878d8
2020-08-17 23:50:51.557 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:HVAC:hvacpoll received response PollResult(failure=null)
2020-08-17 23:50:51.558 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'OFF' (type OnOffType). Input data: number value 0 (value type 'bit' taken into account) and bool value false. Transformation: <identity>
2020-08-17 23:50:51.559 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:di0 channels updated: {modbus:data:HVAC:hvacpoll:di0:switch=OFF}. readValueType=bit, readIndex=Optional[32768], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 0 and boolValue=false. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-17 23:50:51.560 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'OFF' (type OnOffType). Input data: number value 0 (value type 'bit' taken into account) and bool value false. Transformation: <identity>
2020-08-17 23:50:51.562 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:di1 channels updated: {modbus:data:HVAC:hvacpoll:di1:switch=OFF}. readValueType=bit, readIndex=Optional[32768], readSubIndex(or 0)=1, extractIndex=1 -> numeric value 0 and boolValue=false. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-17 23:50:51.563 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'OFF' (type OnOffType). Input data: number value 0 (value type 'bit' taken into account) and bool value false. Transformation: <identity>
2020-08-17 23:50:51.564 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:di2 channels updated: {modbus:data:HVAC:hvacpoll:di2:switch=OFF}. readValueType=bit, readIndex=Optional[32768], readSubIndex(or 0)=2, extractIndex=2 -> numeric value 0 and boolValue=false. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-17 23:50:51.565 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'OFF' (type OnOffType). Input data: number value 0 (value type 'bit' taken into account) and bool value false. Transformation: <identity>
2020-08-17 23:50:51.565 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:di3 channels updated: {modbus:data:HVAC:hvacpoll:di3:switch=OFF}. readValueType=bit, readIndex=Optional[32768], readSubIndex(or 0)=3, extractIndex=3 -> numeric value 0 and boolValue=false. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-17 23:50:51.566 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel number will be updated to '-32768' (type DecimalType). Input data: number value -32768 (value type 'int16' taken into account) and bool value true. Transformation: <identity>
2020-08-17 23:50:51.567 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:reg32768 channels updated: {modbus:data:HVAC:hvacpoll:reg32768:number=-32768, modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess=2020-08-17T23:50:51.566-0500}. readValueType=int16, readIndex=Optional[32768], readSubIndex(or 0)=0, extractIndex=0 -> numeric value -32768 and boolValue=true. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-17 23:50:51.568 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'OFF' (type OnOffType). Input data: number value 0 (value type 'bit' taken into account) and bool value false. Transformation: <identity>
2020-08-17 23:50:51.568 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:di6 channels updated: {modbus:data:HVAC:hvacpoll:di6:switch=OFF}. readValueType=bit, readIndex=Optional[32768], readSubIndex(or 0)=6, extractIndex=6 -> numeric value 0 and boolValue=false. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-17 23:50:51.569 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'OFF' (type OnOffType). Input data: number value 0 (value type 'bit' taken into account) and bool value false. Transformation: <identity>
2020-08-17 23:50:51.569 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:di5 channels updated: {modbus:data:HVAC:hvacpoll:di5:switch=OFF}. readValueType=bit, readIndex=Optional[32768], readSubIndex(or 0)=5, extractIndex=5 -> numeric value 0 and boolValue=false. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-17 23:50:51.570 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'OFF' (type OnOffType). Input data: number value 0 (value type 'bit' taken into account) and bool value false. Transformation: <identity>
2020-08-17 23:50:51.570 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:di7 channels updated: {modbus:data:HVAC:hvacpoll:di7:switch=OFF}. readValueType=bit, readIndex=Optional[32768], readSubIndex(or 0)=7, extractIndex=7 -> numeric value 0 and boolValue=false. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-17 23:50:51.570 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'OFF' (type OnOffType). Input data: number value 0 (value type 'bit' taken into account) and bool value false. Transformation: <identity>
2020-08-17 23:50:51.571 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:di9 channels updated: {modbus:data:HVAC:hvacpoll:di9:switch=OFF}. readValueType=bit, readIndex=Optional[32768], readSubIndex(or 0)=9, extractIndex=9 -> numeric value 0 and boolValue=false. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-17 23:50:51.571 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'OFF' (type OnOffType). Input data: number value 0 (value type 'bit' taken into account) and bool value false. Transformation: <identity>
2020-08-17 23:50:51.572 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:di12 channels updated: {modbus:data:HVAC:hvacpoll:di12:switch=OFF}. readValueType=bit, readIndex=Optional[32768], readSubIndex(or 0)=12, extractIndex=12 -> numeric value 0 and boolValue=false. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-17 23:50:51.572 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'OFF' (type OnOffType). Input data: number value 0 (value type 'bit' taken into account) and bool value false. Transformation: <identity>
2020-08-17 23:50:51.572 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:di10 channels updated: {modbus:data:HVAC:hvacpoll:di10:switch=OFF}. readValueType=bit, readIndex=Optional[32768], readSubIndex(or 0)=10, extractIndex=10 -> numeric value 0 and boolValue=false. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-17 23:50:51.573 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'OFF' (type OnOffType). Input data: number value 0 (value type 'bit' taken into account) and bool value false. Transformation: <identity>
2020-08-17 23:50:51.573 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:di8 channels updated: {modbus:data:HVAC:hvacpoll:di8:switch=OFF}. readValueType=bit, readIndex=Optional[32768], readSubIndex(or 0)=8, extractIndex=8 -> numeric value 0 and boolValue=false. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-17 23:50:51.573 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'OFF' (type OnOffType). Input data: number value 0 (value type 'bit' taken into account) and bool value false. Transformation: <identity>
2020-08-17 23:50:51.574 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:di4 channels updated: {modbus:data:HVAC:hvacpoll:di4:switch=OFF}. readValueType=bit, readIndex=Optional[32768], readSubIndex(or 0)=4, extractIndex=4 -> numeric value 0 and boolValue=false. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-17 23:50:51.574 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'OFF' (type OnOffType). Input data: number value 0 (value type 'bit' taken into account) and bool value false. Transformation: <identity>
2020-08-17 23:50:51.574 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:di11 channels updated: {modbus:data:HVAC:hvacpoll:di11:switch=OFF}. readValueType=bit, readIndex=Optional[32768], readSubIndex(or 0)=11, extractIndex=11 -> numeric value 0 and boolValue=false. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-17 23:50:51.575 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'ON' (type OnOffType). Input data: number value 1 (value type 'bit' taken into account) and bool value true. Transformation: <identity>
2020-08-17 23:50:51.575 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:di15 channels updated: {modbus:data:HVAC:hvacpoll:di15:switch=ON}. readValueType=bit, readIndex=Optional[32768], readSubIndex(or 0)=15, extractIndex=15 -> numeric value 1 and boolValue=true. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-17 23:50:51.575 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'OFF' (type OnOffType). Input data: number value 0 (value type 'bit' taken into account) and bool value false. Transformation: <identity>
2020-08-17 23:50:51.575 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:di14 channels updated: {modbus:data:HVAC:hvacpoll:di14:switch=OFF}. readValueType=bit, readIndex=Optional[32768], readSubIndex(or 0)=14, extractIndex=14 -> numeric value 0 and boolValue=false. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-17 23:50:51.576 [TRACE] [ernal.handler.ModbusDataThingHandler] - Channel switch will be updated to 'OFF' (type OnOffType). Input data: number value 0 (value type 'bit' taken into account) and bool value false. Transformation: <identity>
2020-08-17 23:50:51.576 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:di13 channels updated: {modbus:data:HVAC:hvacpoll:di13:switch=OFF}. readValueType=bit, readIndex=Optional[32768], readSubIndex(or 0)=13, extractIndex=13 -> numeric value 0 and boolValue=false. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-17 23:50:51.576 [TRACE] [modbus.internal.ModbusLibraryWrapper] - Called read response callback org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@6c6fa612 for request ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]. Response was net.wimpi.modbus.msg.ReadMultipleRegistersResponse@34c878d8
2020-08-17 23:50:51.576 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502] connection TCPMasterConnection@33f6d054[socket=Socket[addr=/192.168.1.111,port=502,localport=57070]] -> true
2020-08-17 23:50:51.576 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Passivating connection TCPMasterConnection@33f6d054[socket=Socket[addr=/192.168.1.111,port=502,localport=57070]] for endpoint ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502]...
2020-08-17 23:50:51.577 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - (passivate) Connection TCPMasterConnection@33f6d054[socket=Socket[addr=/192.168.1.111,port=502,localport=57070]] (endpoint ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502]) age 30ms is over the reconnectAfterMillis=0ms limit or has been connection time (1597726251547) is after the "disconnectBeforeConnectedMillis"=-1 -> disconnecting.
2020-08-17 23:50:51.577 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - ...Passivated connection TCPMasterConnection@33f6d054[socket=Socket[addr=/192.168.1.111,port=502,localport=57070]] for endpoint ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502]
2020-08-17 23:50:51.577 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - returned connection to pool for endpoint ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502]
2020-08-17 23:50:51.577 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - returning connection for endpoint ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502] took 1 ms
2020-08-17 23:50:51.577 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Connection was returned to the pool, ending operation [operation ID 4162e2d5-d476-41ef-9ccd-f92381856c6b]
2020-08-17 23:50:51.578 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 38 ms, connection: 8, transaction=4, callback=20} [operation ID 4162e2d5-d476-41ef-9ccd-f92381856c6b]
2020-08-17 23:50:51.578 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Execution of scheduled (500ms) poll task BasicPollTask@3c86225d[request=ModbusPollerThingHandler.ModbusPollerReadRequest@75156a78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@13b21299[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@6c6fa612,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@6c6fa612] finished at 1597726251578. Was started at millis: 1597726251540 (=duration of 38 millis)
72

People can be remarkably quick on a button. Polling at 200mS only improves your chances a bit. There may also be mechanical switch bounce to deal with here.
You really need a ‘hardware’ solution here - a pulse stretcher technique most likely, though you can implement the effect in logic with PLC type boxes.

That’s just about making sure you capture pushes; you would still need a fast poll for a quick response, but it takes the pressure off a bit.
In your logs you can see your “500” poll is actual around 530mS intervals with the overheads.

1 Like
73

It must been something about modbus then. My house is build with IHC push buttons all around the house. I have no trouble gettting the puls to openhab.
Also my Velbus panels using push buttons are beeing recongnized by openhab all the time.

The issue with push buttons is, when you work with long pressure timings. Then things intend to screw up badly.

74

Openhab 2.5.8 is now released, including the fixes discussed here.

1 Like
75

Sorry about being slow with this but I have had a lot of obligations the last few days.

I set up all the logging as requested and everything seemed to be working. I ran it a good while with no issues. I decided to leave most of the extra logging off for awhile and it was working, was getting events to show a change of state on a couple of inputs. I also have a simple HABPanel set up and I can see when an input changes state. I commented out the “Last_Success” but left the “Last_Error” in my “hvac.items” file and I was still logging events from my inputs when operated so I left it on and went to bed. When I got up after 6-1/2 hours or so I activated my inputs and no events were logged. Without stopping openHAB I opened the the hvac.items file and uncommented the “Last Success” and saved the file. It showed that change in the log and immediately started logging the “Last Success” events and when I operated an input it would show up in the event log and in HABPanel. I thought that was interesting, I never saw any “Last Errors” during this test. I know I should have had all the logging on but wasn’t sure if it would be a problem for my Surface SSD hitting it with so many writes for an extended time. I am inclosing a shot of my log files.

events.log

2020-08-23 21:13:40.403 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-23T21:13:39.886-0500 to 2020-08-23T21:13:40.401-0500
2020-08-23 21:13:40.912 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-23T21:13:40.401-0500 to 2020-08-23T21:13:40.912-0500
2020-08-23 21:13:41.436 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-23T21:13:40.912-0500 to 2020-08-23T21:13:41.434-0500
2020-08-23 21:13:41.965 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-23T21:13:41.434-0500 to 2020-08-23T21:13:41.963-0500
2020-08-23 21:13:42.479 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-23T21:13:41.963-0500 to 2020-08-23T21:13:42.478-0500
2020-08-23 21:13:42.998 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-23T21:13:42.478-0500 to 2020-08-23T21:13:42.997-0500
2020-08-23 21:13:43.521 [temChannelLinkRemovedEvent] - Link 'HVAC_Temp_Last_Success => modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess' has been removed.
2020-08-23 21:14:23.426 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32768 to -32512
2020-08-23 21:14:23.426 [vent.ItemStateChangedEvent] - Turck_i8 changed from OFF to ON
2020-08-23 21:14:24.461 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32512 to -32768
2020-08-23 21:14:24.462 [vent.ItemStateChangedEvent] - Turck_i8 changed from ON to OFF
2020-08-23 21:14:25.494 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32768 to -32256
2020-08-23 21:14:25.495 [vent.ItemStateChangedEvent] - Turck_i9 changed from OFF to ON
2020-08-23 21:14:26.532 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32256 to -32768
2020-08-23 21:14:26.533 [vent.ItemStateChangedEvent] - Turck_i9 changed from ON to OFF
2020-08-23 21:26:29.610 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32768 to -32512
2020-08-23 21:26:29.611 [vent.ItemStateChangedEvent] - Turck_i8 changed from OFF to ON
2020-08-23 21:26:30.129 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32512 to -32768
2020-08-23 21:26:30.130 [vent.ItemStateChangedEvent] - Turck_i8 changed from ON to OFF
2020-08-23 21:26:31.164 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32768 to -32256
2020-08-23 21:26:31.164 [vent.ItemStateChangedEvent] - Turck_i9 changed from OFF to ON
2020-08-23 21:26:31.683 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32256 to -32768
2020-08-23 21:26:31.684 [vent.ItemStateChangedEvent] - Turck_i9 changed from ON to OFF
2020-08-23 22:25:09.313 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32768 to -32512
2020-08-23 22:25:09.313 [vent.ItemStateChangedEvent] - Turck_i8 changed from OFF to ON
2020-08-23 22:25:09.831 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32512 to -32768
2020-08-23 22:25:09.831 [vent.ItemStateChangedEvent] - Turck_i8 changed from ON to OFF
2020-08-23 22:25:10.875 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32768 to -32256
2020-08-23 22:25:10.875 [vent.ItemStateChangedEvent] - Turck_i9 changed from OFF to ON
2020-08-23 22:25:11.395 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32256 to -32768
2020-08-23 22:25:11.397 [vent.ItemStateChangedEvent] - Turck_i9 changed from ON to OFF
2020-08-23 22:38:54.667 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32768 to -32512
2020-08-23 22:38:54.667 [vent.ItemStateChangedEvent] - Turck_i8 changed from OFF to ON
2020-08-23 22:38:55.192 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32512 to -32768
2020-08-23 22:38:55.193 [vent.ItemStateChangedEvent] - Turck_i8 changed from ON to OFF
2020-08-23 22:38:56.222 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32768 to -32256
2020-08-23 22:38:56.223 [vent.ItemStateChangedEvent] - Turck_i9 changed from OFF to ON
2020-08-23 22:38:57.265 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32256 to -32768
2020-08-23 22:38:57.266 [vent.ItemStateChangedEvent] - Turck_i9 changed from ON to OFF
2020-08-24 05:41:56.010 [.ItemChannelLinkAddedEvent] - Link 'HVAC_Temp_Last_Success-modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess' has been added.
2020-08-24 05:41:56.023 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from NULL to 2020-08-24T05:41:56.020-0500
2020-08-24 05:41:56.091 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:41:56.020-0500 to 2020-08-24T05:41:56.089-0500
2020-08-24 05:41:56.614 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:41:56.089-0500 to 2020-08-24T05:41:56.612-0500
2020-08-24 05:41:57.132 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:41:56.612-0500 to 2020-08-24T05:41:57.129-0500
2020-08-24 05:41:57.652 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:41:57.129-0500 to 2020-08-24T05:41:57.650-0500
2020-08-24 05:41:58.170 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:41:57.650-0500 to 2020-08-24T05:41:58.167-0500
2020-08-24 05:41:58.699 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:41:58.167-0500 to 2020-08-24T05:41:58.697-0500
2020-08-24 05:41:59.232 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:41:58.697-0500 to 2020-08-24T05:41:59.229-0500
2020-08-24 05:41:59.759 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:41:59.229-0500 to 2020-08-24T05:41:59.757-0500
2020-08-24 05:42:00.283 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:41:59.757-0500 to 2020-08-24T05:42:00.280-0500
2020-08-24 05:42:00.799 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:00.280-0500 to 2020-08-24T05:42:00.797-0500
2020-08-24 05:42:01.317 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:00.797-0500 to 2020-08-24T05:42:01.317-0500
2020-08-24 05:42:01.844 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:01.317-0500 to 2020-08-24T05:42:01.842-0500
2020-08-24 05:42:02.361 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:01.842-0500 to 2020-08-24T05:42:02.361-0500
2020-08-24 05:42:02.886 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:02.361-0500 to 2020-08-24T05:42:02.884-0500
2020-08-24 05:42:03.412 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:02.884-0500 to 2020-08-24T05:42:03.406-0500
2020-08-24 05:42:03.936 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:03.406-0500 to 2020-08-24T05:42:03.935-0500
2020-08-24 05:42:04.459 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:03.935-0500 to 2020-08-24T05:42:04.457-0500
2020-08-24 05:42:04.989 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:04.457-0500 to 2020-08-24T05:42:04.986-0500
2020-08-24 05:42:05.512 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:04.986-0500 to 2020-08-24T05:42:05.509-0500
2020-08-24 05:42:06.030 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:05.509-0500 to 2020-08-24T05:42:06.029-0500
2020-08-24 05:42:06.555 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:06.029-0500 to 2020-08-24T05:42:06.553-0500
2020-08-24 05:42:07.074 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:06.553-0500 to 2020-08-24T05:42:07.073-0500
2020-08-24 05:42:07.596 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:07.073-0500 to 2020-08-24T05:42:07.595-0500
2020-08-24 05:42:08.114 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:07.595-0500 to 2020-08-24T05:42:08.112-0500
2020-08-24 05:42:08.640 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:08.112-0500 to 2020-08-24T05:42:08.637-0500
2020-08-24 05:42:09.159 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:08.637-0500 to 2020-08-24T05:42:09.157-0500
2020-08-24 05:42:09.675 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:09.157-0500 to 2020-08-24T05:42:09.675-0500
2020-08-24 05:42:10.194 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:09.675-0500 to 2020-08-24T05:42:10.192-0500
2020-08-24 05:42:10.715 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:10.192-0500 to 2020-08-24T05:42:10.714-0500
2020-08-24 05:42:11.228 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:10.714-0500 to 2020-08-24T05:42:11.227-0500
2020-08-24 05:42:11.755 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:11.227-0500 to 2020-08-24T05:42:11.750-0500
2020-08-24 05:42:12.281 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:11.750-0500 to 2020-08-24T05:42:12.279-0500
2020-08-24 05:42:12.798 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:12.279-0500 to 2020-08-24T05:42:12.796-0500
2020-08-24 05:42:13.318 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:12.796-0500 to 2020-08-24T05:42:13.315-0500
2020-08-24 05:42:13.839 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:13.315-0500 to 2020-08-24T05:42:13.836-0500
2020-08-24 05:42:14.361 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:13.836-0500 to 2020-08-24T05:42:14.359-0500
2020-08-24 05:42:14.879 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:14.359-0500 to 2020-08-24T05:42:14.878-0500
2020-08-24 05:42:15.403 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:14.878-0500 to 2020-08-24T05:42:15.402-0500
2020-08-24 05:42:15.925 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:15.402-0500 to 2020-08-24T05:42:15.924-0500
2020-08-24 05:42:16.443 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:15.924-0500 to 2020-08-24T05:42:16.442-0500
2020-08-24 05:42:16.964 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:16.442-0500 to 2020-08-24T05:42:16.962-0500
2020-08-24 05:42:17.476 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:16.962-0500 to 2020-08-24T05:42:17.475-0500
2020-08-24 05:42:17.995 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:17.475-0500 to 2020-08-24T05:42:17.995-0500
2020-08-24 05:42:18.515 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:17.995-0500 to 2020-08-24T05:42:18.514-0500
2020-08-24 05:42:19.025 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:18.514-0500 to 2020-08-24T05:42:19.024-0500
2020-08-24 05:42:19.533 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:19.024-0500 to 2020-08-24T05:42:19.533-0500
2020-08-24 05:42:20.041 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:19.533-0500 to 2020-08-24T05:42:20.040-0500
2020-08-24 05:42:20.565 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:20.040-0500 to 2020-08-24T05:42:20.563-0500
2020-08-24 05:42:21.091 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:20.563-0500 to 2020-08-24T05:42:21.088-0500
2020-08-24 05:42:21.603 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:21.088-0500 to 2020-08-24T05:42:21.601-0500
2020-08-24 05:42:22.126 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:21.601-0500 to 2020-08-24T05:42:22.124-0500
2020-08-24 05:42:22.644 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:22.124-0500 to 2020-08-24T05:42:22.644-0500
2020-08-24 05:42:23.168 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:22.644-0500 to 2020-08-24T05:42:23.167-0500
2020-08-24 05:42:23.692 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:23.167-0500 to 2020-08-24T05:42:23.690-0500
2020-08-24 05:42:24.216 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:23.690-0500 to 2020-08-24T05:42:24.214-0500
2020-08-24 05:42:24.735 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:24.214-0500 to 2020-08-24T05:42:24.733-0500
2020-08-24 05:42:25.254 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:24.733-0500 to 2020-08-24T05:42:25.253-0500
2020-08-24 05:42:25.777 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:25.253-0500 to 2020-08-24T05:42:25.775-0500
2020-08-24 05:42:26.305 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:25.775-0500 to 2020-08-24T05:42:26.304-0500
2020-08-24 05:42:26.816 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:26.304-0500 to 2020-08-24T05:42:26.814-0500
2020-08-24 05:42:27.336 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:26.814-0500 to 2020-08-24T05:42:27.334-0500
2020-08-24 05:42:27.855 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:27.334-0500 to 2020-08-24T05:42:27.853-0500
2020-08-24 05:42:28.376 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-24T05:42:27.853-0500 to 2020-08-24T05:42:28.374-0500
2020-08-24 05:42:28.899 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success 


openhab.log

2020-08-21 06:27:09.738 [INFO ] [ll.impl.action.osgi.CommandExtension] - Unregistering commands for bundle org.apache.karaf.deployer.kar/4.2.7
2020-08-23 20:51:36.183 [INFO ] [port.EventAdminConfigurationNotifier] - Sending Event Admin nofification (configuration successful) to org/ops4j/pax/logging/Configuration
2020-08-23 20:51:36.473 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.shell.commands/4.2.7
2020-08-23 20:51:36.476 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.deployer.kar/4.2.7
2020-08-23 20:51:36.892 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.wrapper.core/4.2.7
2020-08-23 20:51:37.832 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.bundle.core/4.2.7
2020-08-23 20:51:37.874 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.config.core/4.2.7
2020-08-23 20:51:38.165 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.diagnostic.core/4.2.7
2020-08-23 20:51:38.210 [INFO ] [ll.impl.action.osgi.CommandExtension] - Command registration delayed for bundle org.apache.karaf.features.command/4.2.7. Missing dependencies: [org.apache.karaf.features.FeaturesService]
2020-08-23 20:51:38.250 [INFO ] [ll.impl.action.osgi.CommandExtension] - Command registration delayed for bundle org.apache.karaf.http.core/4.2.7. Missing dependencies: [org.apache.karaf.http.core.ProxyService, org.apache.karaf.http.core.ServletService]
2020-08-23 20:51:38.253 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.features.command/4.2.7
2020-08-23 20:51:38.256 [INFO ] [raf.deployer.features.osgi.Activator] - Deployment finished. Registering FeatureDeploymentListener
2020-08-23 20:51:38.305 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.instance.core/4.2.7
2020-08-23 20:51:38.340 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.jaas.command/4.2.7
2020-08-23 20:51:38.343 [INFO ] [ll.impl.action.osgi.CommandExtension] - Updating commands for bundle org.apache.karaf.jaas.command/4.2.7
2020-08-23 20:51:38.345 [INFO ] [ll.impl.action.osgi.CommandExtension] - Updating commands for bundle org.apache.karaf.jaas.command/4.2.7
2020-08-23 20:51:38.383 [INFO ] [ll.impl.action.osgi.CommandExtension] - Updating commands for bundle org.apache.karaf.jaas.command/4.2.7
2020-08-23 20:51:38.389 [INFO ] [ll.impl.action.osgi.CommandExtension] - Updating commands for bundle org.apache.karaf.jaas.command/4.2.7
2020-08-23 20:51:38.392 [INFO ] [ll.impl.action.osgi.CommandExtension] - Updating commands for bundle org.apache.karaf.jaas.command/4.2.7
2020-08-23 20:51:38.443 [INFO ] [ll.impl.action.osgi.CommandExtension] - Command registration delayed for bundle org.apache.karaf.kar.core/4.2.7. Missing dependencies: [org.apache.karaf.kar.KarService]
2020-08-23 20:51:38.465 [INFO ] [ll.impl.action.osgi.CommandExtension] - Command registration delayed for bundle org.apache.karaf.log.core/4.2.7. Missing dependencies: [org.apache.karaf.log.core.LogEventFormatter, org.apache.karaf.log.core.LogService]
2020-08-23 20:51:38.481 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.package.core/4.2.7
2020-08-23 20:51:38.493 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.scr.state/4.2.7
2020-08-23 20:51:38.517 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.service.core/4.2.7
2020-08-23 20:51:38.524 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.log.core/4.2.7
2020-08-23 20:51:38.537 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.kar.core/4.2.7
2020-08-23 20:51:38.666 [INFO ] [ll.impl.action.osgi.CommandExtension] - Command registration delayed for bundle org.apache.karaf.shell.ssh/4.2.7. Missing dependencies: [org.apache.sshd.server.SshServer]
2020-08-23 20:51:38.686 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.system.core/4.2.7
2020-08-23 20:51:38.837 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Examining bundle for SPI provider: org.eclipse.jetty.http
2020-08-23 20:51:38.842 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Found SPI resource: bundleentry://80.fwk418958713/META-INF/services/org.eclipse.jetty.http.HttpFieldPreEncoder
2020-08-23 20:51:38.953 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Loaded SPI provider: class org.eclipse.jetty.http.Http1FieldPreEncoder
2020-08-23 20:51:38.954 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered service: {org.eclipse.jetty.http.HttpFieldPreEncoder}={serviceloader.mediator=39, service.id=108, service.bundleid=80, service.scope=bundle, .org.apache.aries.spifly.provider.implclass=org.eclipse.jetty.http.Http1FieldPreEncoder}
2020-08-23 20:51:38.965 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider: org.eclipse.jetty.http.HttpFieldPreEncoder in bundle org.eclipse.jetty.http
2020-08-23 20:51:38.981 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Examining bundle for SPI provider: org.eclipse.jetty.websocket.common
2020-08-23 20:51:38.982 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Found SPI resource: bundleentry://98.fwk418958713/META-INF/services/org.eclipse.jetty.websocket.api.extensions.Extension
2020-08-23 20:51:39.038 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Loaded SPI provider: class org.eclipse.jetty.websocket.common.extensions.identity.IdentityExtension
2020-08-23 20:51:39.040 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered service: {org.eclipse.jetty.websocket.api.extensions.Extension}={serviceloader.mediator=39, service.id=109, service.bundleid=98, service.scope=bundle, .org.apache.aries.spifly.provider.implclass=org.eclipse.jetty.websocket.common.extensions.identity.IdentityExtension}
2020-08-23 20:51:39.041 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider: org.eclipse.jetty.websocket.api.extensions.Extension in bundle org.eclipse.jetty.websocket.common
2020-08-23 20:51:39.043 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Loaded SPI provider: class org.eclipse.jetty.websocket.common.extensions.fragment.FragmentExtension
2020-08-23 20:51:39.044 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered service: {org.eclipse.jetty.websocket.api.extensions.Extension}={serviceloader.mediator=39, service.id=110, service.bundleid=98, service.scope=bundle, .org.apache.aries.spifly.provider.implclass=org.eclipse.jetty.websocket.common.extensions.fragment.FragmentExtension}
2020-08-23 20:51:39.045 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider: org.eclipse.jetty.websocket.api.extensions.Extension in bundle org.eclipse.jetty.websocket.common
2020-08-23 20:51:39.055 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Loaded SPI provider: class org.eclipse.jetty.websocket.common.extensions.compress.PerMessageDeflateExtension
2020-08-23 20:51:39.060 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered service: {org.eclipse.jetty.websocket.api.extensions.Extension}={serviceloader.mediator=39, service.id=111, service.bundleid=98, service.scope=bundle, .org.apache.aries.spifly.provider.implclass=org.eclipse.jetty.websocket.common.extensions.compress.PerMessageDeflateExtension}
2020-08-23 20:51:39.061 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider: org.eclipse.jetty.websocket.api.extensions.Extension in bundle org.eclipse.jetty.websocket.common
2020-08-23 20:51:39.062 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Loaded SPI provider: class org.eclipse.jetty.websocket.common.extensions.compress.DeflateFrameExtension
2020-08-23 20:51:39.064 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered service: {org.eclipse.jetty.websocket.api.extensions.Extension}={serviceloader.mediator=39, service.id=112, service.bundleid=98, service.scope=bundle, .org.apache.aries.spifly.provider.implclass=org.eclipse.jetty.websocket.common.extensions.compress.DeflateFrameExtension}
2020-08-23 20:51:39.066 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider: org.eclipse.jetty.websocket.api.extensions.Extension in bundle org.eclipse.jetty.websocket.common
2020-08-23 20:51:39.067 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Loaded SPI provider: class org.eclipse.jetty.websocket.common.extensions.compress.XWebkitDeflateFrameExtension
2020-08-23 20:51:39.072 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered service: {org.eclipse.jetty.websocket.api.extensions.Extension}={serviceloader.mediator=39, service.id=113, service.bundleid=98, service.scope=bundle, .org.apache.aries.spifly.provider.implclass=org.eclipse.jetty.websocket.common.extensions.compress.XWebkitDeflateFrameExtension}
2020-08-23 20:51:39.074 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider: org.eclipse.jetty.websocket.api.extensions.Extension in bundle org.eclipse.jetty.websocket.common
2020-08-23 20:51:39.079 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Examining bundle for SPI provider: org.eclipse.jetty.websocket.javax.websocket
2020-08-23 20:51:39.082 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Found SPI resource: bundleentry://99.fwk418958713/META-INF/services/javax.websocket.ContainerProvider
2020-08-23 20:51:39.085 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Loaded SPI provider: class org.eclipse.jetty.websocket.jsr356.JettyClientContainerProvider
2020-08-23 20:51:39.086 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered service: {javax.websocket.ContainerProvider}={serviceloader.mediator=39, service.id=114, service.bundleid=99, service.scope=bundle, .org.apache.aries.spifly.provider.implclass=org.eclipse.jetty.websocket.jsr356.JettyClientContainerProvider}
2020-08-23 20:51:39.087 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider: javax.websocket.ContainerProvider in bundle org.eclipse.jetty.websocket.javax.websocket
2020-08-23 20:51:39.089 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Examining bundle for SPI provider: org.eclipse.jetty.websocket.javax.websocket.server
2020-08-23 20:51:39.090 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Found SPI resource: bundleentry://100.fwk418958713/META-INF/services/javax.servlet.ServletContainerInitializer
2020-08-23 20:51:39.092 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Loaded SPI provider: class org.eclipse.jetty.websocket.jsr356.server.deploy.WebSocketServerContainerInitializer
2020-08-23 20:51:39.093 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered service: {javax.servlet.ServletContainerInitializer}={serviceloader.mediator=39, service.id=115, service.bundleid=100, service.scope=bundle, .org.apache.aries.spifly.provider.implclass=org.eclipse.jetty.websocket.jsr356.server.deploy.WebSocketServerContainerInitializer}
2020-08-23 20:51:39.094 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider: javax.servlet.ServletContainerInitializer in bundle org.eclipse.jetty.websocket.javax.websocket.server
2020-08-23 20:51:39.094 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Found SPI resource: bundleentry://100.fwk418958713/META-INF/services/javax.websocket.server.ServerEndpointConfig$Configurator
2020-08-23 20:51:39.096 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Loaded SPI provider: class org.eclipse.jetty.websocket.jsr356.server.ContainerDefaultConfigurator
2020-08-23 20:51:39.097 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered service: {javax.websocket.server.ServerEndpointConfig$Configurator}={serviceloader.mediator=39, service.id=116, service.bundleid=100, service.scope=bundle, .org.apache.aries.spifly.provider.implclass=org.eclipse.jetty.websocket.jsr356.server.ContainerDefaultConfigurator}
2020-08-23 20:51:39.097 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider: javax.websocket.server.ServerEndpointConfig$Configurator in bundle org.eclipse.jetty.websocket.javax.websocket.server
2020-08-23 20:51:39.099 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Examining bundle for SPI provider: org.eclipse.jetty.websocket.server
2020-08-23 20:51:39.099 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Found SPI resource: bundleentry://101.fwk418958713/META-INF/services/javax.servlet.ServletContainerInitializer
2020-08-23 20:51:39.101 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Loaded SPI provider: class org.eclipse.jetty.websocket.server.NativeWebSocketServletContainerInitializer
2020-08-23 20:51:39.102 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered service: {javax.servlet.ServletContainerInitializer}={serviceloader.mediator=39, service.id=117, service.bundleid=101, service.scope=bundle, .org.apache.aries.spifly.provider.implclass=org.eclipse.jetty.websocket.server.NativeWebSocketServletContainerInitializer}
2020-08-23 20:51:39.102 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider: javax.servlet.ServletContainerInitializer in bundle org.eclipse.jetty.websocket.server
2020-08-23 20:51:39.179 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.shell.ssh/4.2.7
2020-08-23 20:51:39.247 [INFO ] [org.eclipse.jetty.util.log          ] - Logging initialized @5891ms to org.eclipse.jetty.util.log.Slf4jLog
2020-08-23 20:51:39.281 [INFO ] [j.pax.web.service.internal.Activator] - EventAdmin support enabled, servlet events will be postet to topics.
2020-08-23 20:51:39.283 [INFO ] [j.pax.web.service.internal.Activator] - LogService support enabled, log events will be created.
2020-08-23 20:51:39.291 [INFO ] [j.pax.web.service.internal.Activator] - Pax Web started
2020-08-23 20:51:39.650 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.event/4.2.7
2020-08-23 20:51:40.098 [INFO ] [org.eclipse.jetty.util.TypeUtil     ] - JVM Runtime does not support Modules
2020-08-23 20:51:40.162 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Location set to '31.581896,-94.465492'.
2020-08-23 20:51:40.207 [INFO ] [rvice.jetty.internal.JettyServerImpl] - Pax Web available at [0.0.0.0]:[8443]
2020-08-23 20:51:40.223 [INFO ] [vice.jetty.internal.JettyFactoryImpl] - No ALPN class available
2020-08-23 20:51:40.223 [INFO ] [vice.jetty.internal.JettyFactoryImpl] - HTTP/2 not available, creating standard ServerConnector for Http
2020-08-23 20:51:40.225 [INFO ] [rvice.jetty.internal.JettyServerImpl] - Pax Web available at [0.0.0.0]:[8080]
2020-08-23 20:51:40.230 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.apache.karaf.http.core_4.2.7 [53]] to http service
2020-08-23 20:51:40.265 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.ops4j.pax.web.pax-web-extender-whiteboard_7.2.11 [193]] to http service
2020-08-23 20:51:40.273 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [19]] to http service
2020-08-23 20:51:40.276 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.http.core/4.2.7
2020-08-23 20:51:41.041 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.core.audio_2.5.0 [134]] to http service
2020-08-23 20:51:41.055 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2020-08-23 20:51:41.094 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.core.audio_2.5.0 [134], contextID=default], with context-name: 
2020-08-23 20:51:41.108 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2020-08-23 20:51:41.174 [INFO ] [org.eclipse.jetty.server.session    ] - DefaultSessionIdManager workerName=node0
2020-08-23 20:51:41.175 [INFO ] [org.eclipse.jetty.server.session    ] - No SessionScavenger set, using defaults
2020-08-23 20:51:41.178 [INFO ] [org.eclipse.jetty.server.session    ] - node0 Scavenging every 600000ms
2020-08-23 20:51:41.191 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core.audio_2.5.0 [134], contextID=default]}
2020-08-23 20:51:41.202 [INFO ] [org.eclipse.jetty.server.Server     ] - jetty-9.4.20.v20190813; built: 2019-08-13T21:28:18.144Z; git: 84700530e645e812b336747464d6fbbf370c9a20; jvm 1.8.0_252-b14
2020-08-23 20:51:41.226 [INFO ] [.jetty.server.handler.ContextHandler] - Started o.e.j.s.h.ContextHandler@743f1b5f{/static,null,AVAILABLE}
2020-08-23 20:51:41.251 [INFO ] [pse.jetty.util.ssl.SslContextFactory] - x509=X509@39995ada(mykey,h=[openhab.org],w=[]) for Server@f7750e9[provider=null,keyStore=file:///C:/openhab2/userdata/etc/keystore,trustStore=file:///C:/openhab2/userdata/etc/keystore]
2020-08-23 20:51:41.310 [INFO ] [lipse.jetty.server.AbstractConnector] - Started 0.0.0.0:8443@55979a4{SSL,[ssl, http/1.1]}{0.0.0.0:8443}
2020-08-23 20:51:41.316 [INFO ] [lipse.jetty.server.AbstractConnector] - Started default@216627c7{HTTP/1.1,[http/1.1]}{0.0.0.0:8080}
2020-08-23 20:51:41.317 [INFO ] [org.eclipse.jetty.server.Server     ] - Started @7961ms
2020-08-23 20:51:41.764 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2020-08-23 20:51:41.765 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [19], contextID=default], with context-name: 
2020-08-23 20:51:41.766 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2020-08-23 20:51:41.774 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=com.eclipsesource.jaxrs.publisher_5.3.1.201602281253 [19], contextID=default]}
2020-08-23 20:51:41.811 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.core.io.http_2.5.0 [147]] to http service
2020-08-23 20:51:44.013 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.openhab.core.karaf/2.5.0
2020-08-23 20:51:45.204 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'hvac.items'
2020-08-23 20:51:45.659 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'modbus.things'
2020-08-23 20:51:45.735 [INFO ] [org.quartz.impl.StdSchedulerFactory ] - Using default implementation for ThreadExecutor
2020-08-23 20:51:45.752 [INFO ] [rg.quartz.core.SchedulerSignalerImpl] - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
2020-08-23 20:51:45.752 [INFO ] [org.quartz.core.QuartzScheduler     ] - Quartz Scheduler v.2.2.1 created.
2020-08-23 20:51:45.753 [INFO ] [org.quartz.simpl.RAMJobStore        ] - RAMJobStore initialized.
2020-08-23 20:51:45.754 [INFO ] [org.quartz.core.QuartzScheduler     ] - Scheduler meta-data: Quartz Scheduler (v2.2.1) '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 10 threads.
  Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered.

2020-08-23 20:51:45.755 [INFO ] [org.quartz.impl.StdSchedulerFactory ] - Quartz scheduler 'openHAB-job-scheduler' initialized from specified file: 'C:\openhab2\runtime/etc/quartz.properties'
2020-08-23 20:51:45.755 [INFO ] [org.quartz.impl.StdSchedulerFactory ] - Quartz scheduler version: 2.2.1
2020-08-23 20:51:45.756 [INFO ] [org.quartz.core.QuartzScheduler     ] - Scheduler openHAB-job-scheduler_$_NON_CLUSTERED started.
2020-08-23 20:51:46.777 [INFO ] [org.quartz.core.QuartzScheduler     ] - JobFactory set to: org.eclipse.smarthome.model.rule.runtime.internal.engine.GuiceAwareJobFactory@267cf7e2
2020-08-23 20:51:46.778 [INFO ] [org.quartz.core.QuartzScheduler     ] - Scheduler openHAB-job-scheduler_$_NON_CLUSTERED paused.
2020-08-23 20:51:46.898 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2020-08-23 20:51:47.336 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.core.ui_2.5.0 [188]] to http service
2020-08-23 20:51:47.341 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2020-08-23 20:51:47.342 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.core.ui_2.5.0 [188], contextID=custom], with context-name: 
2020-08-23 20:51:47.344 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2020-08-23 20:51:47.387 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core.ui_2.5.0 [188], contextID=custom]}
2020-08-23 20:51:47.448 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2020-08-23 20:51:47.449 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.core.ui_2.5.0 [188], contextID=default], with context-name: 
2020-08-23 20:51:47.450 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2020-08-23 20:51:47.515 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core.ui_2.5.0 [188], contextID=default]}
2020-08-23 20:51:47.528 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.core.ui.icon_2.5.0 [189]] to http service
2020-08-23 20:51:47.531 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2020-08-23 20:51:47.532 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.core.ui.icon_2.5.0 [189], contextID=default], with context-name: 
2020-08-23 20:51:47.533 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2020-08-23 20:51:47.545 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core.ui.icon_2.5.0 [189], contextID=default]}
2020-08-23 20:51:47.592 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.ui.dashboard_2.5.6 [191]] to http service
2020-08-23 20:51:47.603 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2020-08-23 20:51:47.605 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.5.6 [191], contextID=default], with context-name: 
2020-08-23 20:51:47.606 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2020-08-23 20:51:47.629 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.5.6 [191], contextID=default]}
2020-08-23 20:51:47.633 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2020-08-23 20:51:47.639 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.5.6 [191], contextID=custom], with context-name: 
2020-08-23 20:51:47.642 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2020-08-23 20:51:47.666 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.dashboard_2.5.6 [191], contextID=custom]}
2020-08-23 20:51:47.669 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://192.168.1.43:8080
2020-08-23 20:51:47.669 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://192.168.1.43:8443
2020-08-23 20:51:47.717 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Modbus manager activated
2020-08-23 20:51:48.253 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.ui.basic_2.5.7 [216]] to http service
2020-08-23 20:51:48.262 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2020-08-23 20:51:48.263 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.ui.basic_2.5.7 [216], contextID=custom], with context-name: 
2020-08-23 20:51:48.264 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2020-08-23 20:51:48.313 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.basic_2.5.7 [216], contextID=custom]}
2020-08-23 20:51:48.324 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2020-08-23 20:51:48.325 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.ui.basic_2.5.7 [216], contextID=custom], with context-name: 
2020-08-23 20:51:48.334 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2020-08-23 20:51:48.370 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.basic_2.5.7 [216], contextID=custom]}
2020-08-23 20:51:48.450 [INFO ] [d.internal.element.ServletWebElement] - Ignoring servlet [362] without valid alias or url patterns property.
2020-08-23 20:51:48.524 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.ui.habpanel_2.5.7 [217]] to http service
2020-08-23 20:51:48.539 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2020-08-23 20:51:48.540 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.5.7 [217], contextID=default], with context-name: 
2020-08-23 20:51:48.541 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2020-08-23 20:51:48.577 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.habpanel_2.5.7 [217], contextID=default]}
2020-08-23 20:51:48.579 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2020-08-23 20:51:48.594 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.ui.homebuilder_2.5.7 [218]] to http service
2020-08-23 20:51:48.610 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2020-08-23 20:51:48.613 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.ui.homebuilder_2.5.7 [218], contextID=default], with context-name: 
2020-08-23 20:51:48.614 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2020-08-23 20:51:48.650 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.homebuilder_2.5.7 [218], contextID=default]}
2020-08-23 20:51:48.652 [INFO ] [ebuilder.internal.HomeBuilderServlet] - Started Home Builder at /homebuilder
2020-08-23 20:51:48.727 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.ui.paper_2.5.7 [220]] to http service
2020-08-23 20:51:48.731 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2020-08-23 20:51:48.732 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.ui.paper_2.5.7 [220], contextID=custom], with context-name: 
2020-08-23 20:51:48.734 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2020-08-23 20:51:48.768 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.paper_2.5.7 [220], contextID=custom]}
2020-08-23 20:51:48.769 [INFO ] [openhab.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2020-08-23 20:51:50.784 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.core.boot_2.5.0 [137]] to http service
2020-08-23 20:51:50.788 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2020-08-23 20:51:50.788 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.core.boot_2.5.0 [137], contextID=default], with context-name: 
2020-08-23 20:51:50.789 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2020-08-23 20:51:50.809 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core.boot_2.5.0 [137], contextID=default]}
2020-08-23 20:51:51.790 [INFO ] [org.quartz.core.QuartzScheduler     ] - Scheduler openHAB-job-scheduler_$_NON_CLUSTERED started.
2020-08-23 21:13:43.498 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'hvac.items'
2020-08-24 05:41:56.000 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'hvac.items'
2020-08-24 05:42:01.012 [INFO ] [org.quartz.core.QuartzScheduler     ] - Scheduler openHAB-job-scheduler_$_NON_CLUSTERED started.


hvac.items

Number HVAC_Temp "Temp [%d]" { channel="modbus:data:HVAC:hvacpoll:reg32768:number" }
Switch Turck_i0 "i0 [%s]" { channel="modbus:data:HVAC:hvacpoll:di0:switch" }
Switch Turck_i1 "i1 [%s]" { channel="modbus:data:HVAC:hvacpoll:di1:switch" }
Switch Turck_i2 "i2 [%s]" { channel="modbus:data:HVAC:hvacpoll:di2:switch" }
Switch Turck_i3 "i3 [%s]" { channel="modbus:data:HVAC:hvacpoll:di3:switch" }
Switch Turck_i4 "i4 [%s]" { channel="modbus:data:HVAC:hvacpoll:di4:switch" }
Switch Turck_i5 "i5 [%s]" { channel="modbus:data:HVAC:hvacpoll:di5:switch" }
Switch Turck_i6 "i6 [%s]" { channel="modbus:data:HVAC:hvacpoll:di6:switch" }
Switch Turck_i7 "i7 [%s]" { channel="modbus:data:HVAC:hvacpoll:di7:switch" }
Switch Turck_i8 "i8 [%s]" { channel="modbus:data:HVAC:hvacpoll:di8:switch" }
Switch Turck_i9 "i9 [%s]" { channel="modbus:data:HVAC:hvacpoll:di9:switch" }
Switch Turck_i10 "i10 [%s]" { channel="modbus:data:HVAC:hvacpoll:di10:switch" }
Switch Turck_i11 "i11 [%s]" { channel="modbus:data:HVAC:hvacpoll:di11:switch" }
Switch Turck_i12 "i12 [%s]" { channel="modbus:data:HVAC:hvacpoll:di12:switch" }
Switch Turck_i13 "i13 [%s]" { channel="modbus:data:HVAC:hvacpoll:di13:switch" }
Switch Turck_i14 "i14 [%s]" { channel="modbus:data:HVAC:hvacpoll:di14:switch" }
Switch Turck_i15 "i15 [%s]" { channel="modbus:data:HVAC:hvacpoll:di15:switch" }
DateTime HVAC_Temp_Last_Success  "Temp last ok [%1$tA, %1$td.%1$tm.%1$tY %1$tH:%1$tM:%1$tS" { channel="modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess" }
DateTime HVAC_Temp_Last_Error "Temp last err [%1$tA, %1$td.%1$tm.%1$tY %1$tH:%1$tM:%1$tS" { channel="modbus:data:HVAC:hvacpoll:reg32768:lastReadError" }
76

You Surface shouldn´t suffer from any problems. If you use the standard log settings, it will create a maximum of 10x 10Mb file size and overwrite the oldest.

77

@bhall sorry to say this but it’s impossible to get to the root of the issue with this little information. To help you, I would need verbose logs from the time it works, and when it starts to not work.

I suggest considering to update your openHAB and binding to stable 2.5.8, now that it is out. This also introduces some small logging fixes that are needed to diagnose traffic using DEBUG level.

You can reduce the amount of logging by

  • lowering poll rate to 30 s
  • simplifying your item configuration, leave only Number HVAC_Temp, DateTime HVAC_Temp_Last_Success and DateTime HVAC_Temp_Last_Error
  • Simplify your things, remove diXX things and leave only the tcp, poller and data reg32768
  • Setting log level to DEBUG instead of TRACE: log:set DEBUG org.openhab.io.transport.modbus and log:set DEBUG org.openhab.binding.modbus.

Let it run as long as needed, so it eventually stops working.

You should see log lines like the below Thing modbus:poller:fc8f3903 received response ...

20:52:32.321 [DEBUG] [dbus.handler.ModbusPollerThingHandler] - Thing modbus:poller:fc8f3903 received response PollResult(result=AsyncModbusReadResult(request = ModbusPollerThingHandler.ModbusPollerReadRequest@412a0b1a[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=5,maxTries=3], registers = ModbusRegisterArrayImpl(00 00 00 00 00 00 00 00 00 00)))
78

Per your recommendation I will do the upgrade as soon as I can and can leave it going at the 30 sec interval.

Do you think 60 seconds would be too long of an interval?

79

Thanks @BHall. Make sure you remove the snapshot versions from the addons folder.

60 seconds works as well in the sense that logs would tell whether the binding itself is working as expected . I hope that whatever you are experiencing would still happen with the lower poll rate.

80

I did another clean install and went with the stable 2.5.8 as you suggested, then went into the PaperUI and installed the Modbus binding. I then exited the PaperUI and copied my item and thing files setting them up in a minimal way. I let it run overnight, I think around 7 hours. Got up this morning and activated an input before doing anything else or looking at logs. The change showed up in the event log and it appears to have run all night, apparently without issues. I am including a sample of log files.

This is the longest success so far.

events.log

2020-08-25 05:42:38.159 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:42:08.125-0500 to 2020-08-25T05:42:38.158-0500
2020-08-25 05:43:08.173 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:42:38.158-0500 to 2020-08-25T05:43:08.172-0500
2020-08-25 05:43:38.197 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:43:08.172-0500 to 2020-08-25T05:43:38.195-0500
2020-08-25 05:44:08.215 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:43:38.195-0500 to 2020-08-25T05:44:08.213-0500
2020-08-25 05:44:38.233 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:44:08.213-0500 to 2020-08-25T05:44:38.231-0500
2020-08-25 05:45:08.262 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:44:38.231-0500 to 2020-08-25T05:45:08.260-0500
2020-08-25 05:45:38.281 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32768 to -32512
2020-08-25 05:45:38.282 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:45:08.260-0500 to 2020-08-25T05:45:38.280-0500
2020-08-25 05:46:08.297 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32512 to -32768
2020-08-25 05:46:08.297 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:45:38.280-0500 to 2020-08-25T05:46:08.296-0500
2020-08-25 05:46:38.324 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:46:08.296-0500 to 2020-08-25T05:46:38.321-0500
2020-08-25 05:47:08.345 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:46:38.321-0500 to 2020-08-25T05:47:08.343-0500
2020-08-25 05:47:38.363 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:47:08.343-0500 to 2020-08-25T05:47:38.361-0500
2020-08-25 05:48:08.381 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:47:38.361-0500 to 2020-08-25T05:48:08.379-0500
2020-08-25 05:48:38.397 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:48:08.379-0500 to 2020-08-25T05:48:38.395-0500
2020-08-25 05:49:08.411 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:48:38.395-0500 to 2020-08-25T05:49:08.409-0500
2020-08-25 05:49:38.428 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:49:08.409-0500 to 2020-08-25T05:49:38.427-0500
2020-08-25 05:50:08.443 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:49:38.427-0500 to 2020-08-25T05:50:08.441-0500
2020-08-25 05:50:38.472 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:50:08.441-0500 to 2020-08-25T05:50:38.469-0500
2020-08-25 05:51:08.501 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:50:38.469-0500 to 2020-08-25T05:51:08.499-0500
2020-08-25 05:51:38.527 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:51:08.499-0500 to 2020-08-25T05:51:38.524-0500
2020-08-25 05:52:08.542 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32768 to -32512
2020-08-25 05:52:08.542 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:51:38.524-0500 to 2020-08-25T05:52:08.540-0500
2020-08-25 05:52:38.568 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:52:08.540-0500 to 2020-08-25T05:52:38.566-0500
2020-08-25 05:53:08.587 [vent.ItemStateChangedEvent] - HVAC_Temp changed from -32512 to -32768
2020-08-25 05:53:08.588 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:52:38.566-0500 to 2020-08-25T05:53:08.585-0500
2020-08-25 05:53:38.611 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:53:08.585-0500 to 2020-08-25T05:53:38.608-0500
2020-08-25 05:54:08.631 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:53:38.608-0500 to 2020-08-25T05:54:08.630-0500
2020-08-25 05:54:38.661 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:54:08.630-0500 to 2020-08-25T05:54:38.658-0500
2020-08-25 05:55:08.686 [vent.ItemStateChangedEvent] - HVAC_Temp_Last_Success changed from 2020-08-25T05:54:38.658-0500 to 2020-08-25T05:55:08.685-0500


openhab.log

2020-08-25 05:49:08.412 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 12 ms, connection: 5, transaction=4, callback=3} [operation ID 119856bd-d0f5-44dc-b004-61e181195040]
2020-08-25 05:49:08.412 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Execution of scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b] finished at 1598352548412. Was started at millis: 1598352548399 (=duration of 13 millis)
2020-08-25 05:49:15.933 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2020-08-25 05:49:38.419 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Executing scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b]. Current millis: 1598352578419
2020-08-25 05:49:38.420 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-08-25 05:49:38.426 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:HVAC:hvacpoll received response PollResult(result=AsyncModbusReadResult(request = ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3], registers = ModbusRegisterArrayImpl(80 00)))
2020-08-25 05:49:38.427 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:reg32768 channels updated: {modbus:data:HVAC:hvacpoll:reg32768:number=-32768, modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess=2020-08-25T05:49:38.427-0500}. readValueType=int16, readIndex=Optional[32768], readSubIndex(or 0)=0, extractIndex=0 -> numeric value -32768 and boolValue=true. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-25 05:49:38.428 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 8 ms, connection: 4, transaction=2, callback=2} [operation ID c95da290-c2e0-4e81-8ad4-ed35bb63546d]
2020-08-25 05:49:38.428 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Execution of scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b] finished at 1598352578428. Was started at millis: 1598352578419 (=duration of 9 millis)
2020-08-25 05:49:44.356 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2020-08-25 05:50:05.026 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.openhab.addons)
2020-08-25 05:50:05.026 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.openhab.addons bound to mvn:org.openhab.core.bundles/org.openhab.core.karaf/2.5.0
2020-08-25 05:50:05.027 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.ops4j.pax.url.mvn, location=null)
2020-08-25 05:50:05.027 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.ops4j.pax.url.mvn bound to ?
2020-08-25 05:50:05.028 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.ops4j.pax.url.mvn, location=null)
2020-08-25 05:50:05.028 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.ops4j.pax.url.mvn bound to ?
2020-08-25 05:50:08.432 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Executing scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b]. Current millis: 1598352608432
2020-08-25 05:50:08.433 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-08-25 05:50:08.441 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:HVAC:hvacpoll received response PollResult(result=AsyncModbusReadResult(request = ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3], registers = ModbusRegisterArrayImpl(80 00)))
2020-08-25 05:50:08.442 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:reg32768 channels updated: {modbus:data:HVAC:hvacpoll:reg32768:number=-32768, modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess=2020-08-25T05:50:08.441-0500}. readValueType=int16, readIndex=Optional[32768], readSubIndex(or 0)=0, extractIndex=0 -> numeric value -32768 and boolValue=true. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-25 05:50:08.444 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 11 ms, connection: 5, transaction=3, callback=3} [operation ID d5a3ddd3-ba9f-4d56-80d4-ad819f88d4a0]
2020-08-25 05:50:08.444 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Execution of scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b] finished at 1598352608444. Was started at millis: 1598352608432 (=duration of 12 millis)
2020-08-25 05:50:12.396 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2020-08-25 05:50:35.757 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2020-08-25 05:50:38.458 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Executing scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b]. Current millis: 1598352638458
2020-08-25 05:50:38.459 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-08-25 05:50:38.468 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:HVAC:hvacpoll received response PollResult(result=AsyncModbusReadResult(request = ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3], registers = ModbusRegisterArrayImpl(80 00)))
2020-08-25 05:50:38.470 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:reg32768 channels updated: {modbus:data:HVAC:hvacpoll:reg32768:number=-32768, modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess=2020-08-25T05:50:38.469-0500}. readValueType=int16, readIndex=Optional[32768], readSubIndex(or 0)=0, extractIndex=0 -> numeric value -32768 and boolValue=true. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-25 05:50:38.472 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 13 ms, connection: 6, transaction=4, callback=3} [operation ID bae506c0-35d3-489f-9c00-c1b5ef01be9d]
2020-08-25 05:50:38.474 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Execution of scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b] finished at 1598352638474. Was started at millis: 1598352638458 (=duration of 16 millis)
2020-08-25 05:50:59.768 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2020-08-25 05:51:05.038 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.openhab.addons)
2020-08-25 05:51:05.038 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.openhab.addons bound to mvn:org.openhab.core.bundles/org.openhab.core.karaf/2.5.0
2020-08-25 05:51:05.039 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.ops4j.pax.url.mvn, location=null)
2020-08-25 05:51:05.039 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.ops4j.pax.url.mvn bound to ?
2020-08-25 05:51:05.039 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.ops4j.pax.url.mvn, location=null)
2020-08-25 05:51:05.040 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.ops4j.pax.url.mvn bound to ?
2020-08-25 05:51:08.490 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Executing scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b]. Current millis: 1598352668490
2020-08-25 05:51:08.491 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-08-25 05:51:08.499 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:HVAC:hvacpoll received response PollResult(result=AsyncModbusReadResult(request = ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3], registers = ModbusRegisterArrayImpl(80 00)))
2020-08-25 05:51:08.500 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:reg32768 channels updated: {modbus:data:HVAC:hvacpoll:reg32768:number=-32768, modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess=2020-08-25T05:51:08.499-0500}. readValueType=int16, readIndex=Optional[32768], readSubIndex(or 0)=0, extractIndex=0 -> numeric value -32768 and boolValue=true. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-25 05:51:08.501 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 11 ms, connection: 5, transaction=3, callback=3} [operation ID ce204d43-13a3-47f3-95f6-fce5193cbe5f]
2020-08-25 05:51:08.501 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Execution of scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b] finished at 1598352668501. Was started at millis: 1598352668490 (=duration of 11 millis)
2020-08-25 05:51:24.265 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2020-08-25 05:51:38.512 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Executing scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b]. Current millis: 1598352698512
2020-08-25 05:51:38.513 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-08-25 05:51:38.523 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:HVAC:hvacpoll received response PollResult(result=AsyncModbusReadResult(request = ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3], registers = ModbusRegisterArrayImpl(80 00)))
2020-08-25 05:51:38.525 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:reg32768 channels updated: {modbus:data:HVAC:hvacpoll:reg32768:number=-32768, modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess=2020-08-25T05:51:38.524-0500}. readValueType=int16, readIndex=Optional[32768], readSubIndex(or 0)=0, extractIndex=0 -> numeric value -32768 and boolValue=true. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-25 05:51:38.527 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 14 ms, connection: 7, transaction=3, callback=3} [operation ID 71ae18c5-bcf8-4292-a1c0-1b350a6189d5]
2020-08-25 05:51:38.528 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Execution of scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b] finished at 1598352698528. Was started at millis: 1598352698512 (=duration of 16 millis)
2020-08-25 05:51:49.663 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2020-08-25 05:52:05.051 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.openhab.addons)
2020-08-25 05:52:05.051 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.openhab.addons bound to mvn:org.openhab.core.bundles/org.openhab.core.karaf/2.5.0
2020-08-25 05:52:05.052 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.ops4j.pax.url.mvn, location=null)
2020-08-25 05:52:05.052 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.ops4j.pax.url.mvn bound to ?
2020-08-25 05:52:05.052 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.ops4j.pax.url.mvn, location=null)
2020-08-25 05:52:05.053 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.ops4j.pax.url.mvn bound to ?
2020-08-25 05:52:08.531 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Executing scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b]. Current millis: 1598352728531
2020-08-25 05:52:08.532 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-08-25 05:52:08.540 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:HVAC:hvacpoll received response PollResult(result=AsyncModbusReadResult(request = ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3], registers = ModbusRegisterArrayImpl(81 00)))
2020-08-25 05:52:08.541 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:reg32768 channels updated: {modbus:data:HVAC:hvacpoll:reg32768:number=-32512, modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess=2020-08-25T05:52:08.540-0500}. readValueType=int16, readIndex=Optional[32768], readSubIndex(or 0)=0, extractIndex=0 -> numeric value -32512 and boolValue=true. Registers ModbusRegisterArrayImpl(81 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-25 05:52:08.543 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 11 ms, connection: 4, transaction=4, callback=3} [operation ID f31894cb-4201-4b36-bcbc-93eb51b9119d]
2020-08-25 05:52:08.543 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Execution of scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b] finished at 1598352728543. Was started at millis: 1598352728531 (=duration of 12 millis)
2020-08-25 05:52:14.340 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2020-08-25 05:52:38.557 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Executing scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b]. Current millis: 1598352758557
2020-08-25 05:52:38.558 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-08-25 05:52:38.565 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:HVAC:hvacpoll received response PollResult(result=AsyncModbusReadResult(request = ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3], registers = ModbusRegisterArrayImpl(81 00)))
2020-08-25 05:52:38.567 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:reg32768 channels updated: {modbus:data:HVAC:hvacpoll:reg32768:number=-32512, modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess=2020-08-25T05:52:38.566-0500}. readValueType=int16, readIndex=Optional[32768], readSubIndex(or 0)=0, extractIndex=0 -> numeric value -32512 and boolValue=true. Registers ModbusRegisterArrayImpl(81 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-25 05:52:38.569 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 11 ms, connection: 4, transaction=4, callback=3} [operation ID e94afb93-eae8-449d-9606-983d3ec2adbe]
2020-08-25 05:52:38.569 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Execution of scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b] finished at 1598352758569. Was started at millis: 1598352758557 (=duration of 12 millis)
2020-08-25 05:52:42.832 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2020-08-25 05:53:05.067 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.openhab.addons)
2020-08-25 05:53:05.067 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.openhab.addons bound to mvn:org.openhab.core.bundles/org.openhab.core.karaf/2.5.0
2020-08-25 05:53:05.067 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.ops4j.pax.url.mvn, location=null)
2020-08-25 05:53:05.067 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.ops4j.pax.url.mvn bound to ?
2020-08-25 05:53:05.067 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.ops4j.pax.url.mvn, location=null)
2020-08-25 05:53:05.067 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.ops4j.pax.url.mvn bound to ?
2020-08-25 05:53:08.574 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Executing scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b]. Current millis: 1598352788574
2020-08-25 05:53:08.575 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-08-25 05:53:08.584 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:HVAC:hvacpoll received response PollResult(result=AsyncModbusReadResult(request = ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3], registers = ModbusRegisterArrayImpl(80 00)))
2020-08-25 05:53:08.586 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:reg32768 channels updated: {modbus:data:HVAC:hvacpoll:reg32768:number=-32768, modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess=2020-08-25T05:53:08.585-0500}. readValueType=int16, readIndex=Optional[32768], readSubIndex(or 0)=0, extractIndex=0 -> numeric value -32768 and boolValue=true. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-25 05:53:08.588 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 13 ms, connection: 5, transaction=4, callback=4} [operation ID 14106b6a-b329-4e9e-a4b5-72af1c3c4533]
2020-08-25 05:53:08.588 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Execution of scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b] finished at 1598352788588. Was started at millis: 1598352788574 (=duration of 14 millis)
2020-08-25 05:53:09.833 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2020-08-25 05:53:35.230 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2020-08-25 05:53:38.596 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Executing scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b]. Current millis: 1598352818596
2020-08-25 05:53:38.597 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-08-25 05:53:38.607 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:HVAC:hvacpoll received response PollResult(result=AsyncModbusReadResult(request = ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3], registers = ModbusRegisterArrayImpl(80 00)))
2020-08-25 05:53:38.609 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:reg32768 channels updated: {modbus:data:HVAC:hvacpoll:reg32768:number=-32768, modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess=2020-08-25T05:53:38.608-0500}. readValueType=int16, readIndex=Optional[32768], readSubIndex(or 0)=0, extractIndex=0 -> numeric value -32768 and boolValue=true. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-25 05:53:38.611 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 14 ms, connection: 6, transaction=3, callback=5} [operation ID 30e58def-40a2-423d-a7e2-f8d21cff3cd6]
2020-08-25 05:53:38.612 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Execution of scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b] finished at 1598352818612. Was started at millis: 1598352818596 (=duration of 16 millis)
2020-08-25 05:53:58.424 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2020-08-25 05:54:05.070 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.openhab.addons)
2020-08-25 05:54:05.070 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.openhab.addons bound to mvn:org.openhab.core.bundles/org.openhab.core.karaf/2.5.0
2020-08-25 05:54:05.071 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.ops4j.pax.url.mvn, location=null)
2020-08-25 05:54:05.071 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.ops4j.pax.url.mvn bound to ?
2020-08-25 05:54:05.071 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.ops4j.pax.url.mvn, location=null)
2020-08-25 05:54:05.071 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.ops4j.pax.url.mvn bound to ?
2020-08-25 05:54:08.623 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Executing scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b]. Current millis: 1598352848623
2020-08-25 05:54:08.623 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-08-25 05:54:08.630 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:HVAC:hvacpoll received response PollResult(result=AsyncModbusReadResult(request = ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3], registers = ModbusRegisterArrayImpl(80 00)))
2020-08-25 05:54:08.631 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:reg32768 channels updated: {modbus:data:HVAC:hvacpoll:reg32768:number=-32768, modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess=2020-08-25T05:54:08.630-0500}. readValueType=int16, readIndex=Optional[32768], readSubIndex(or 0)=0, extractIndex=0 -> numeric value -32768 and boolValue=true. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-25 05:54:08.631 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 8 ms, connection: 4, transaction=3, callback=1} [operation ID 58ca41b4-8af3-421b-917f-3bbb2df9adec]
2020-08-25 05:54:08.632 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Execution of scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b] finished at 1598352848632. Was started at millis: 1598352848623 (=duration of 9 millis)
2020-08-25 05:54:28.401 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2020-08-25 05:54:38.646 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Executing scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b]. Current millis: 1598352878646
2020-08-25 05:54:38.647 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-08-25 05:54:38.657 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:HVAC:hvacpoll received response PollResult(result=AsyncModbusReadResult(request = ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3], registers = ModbusRegisterArrayImpl(80 00)))
2020-08-25 05:54:38.659 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:reg32768 channels updated: {modbus:data:HVAC:hvacpoll:reg32768:number=-32768, modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess=2020-08-25T05:54:38.658-0500}. readValueType=int16, readIndex=Optional[32768], readSubIndex(or 0)=0, extractIndex=0 -> numeric value -32768 and boolValue=true. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-25 05:54:38.661 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 14 ms, connection: 7, transaction=3, callback=4} [operation ID c9318198-d321-40b9-b759-b26b4a676a7d]
2020-08-25 05:54:38.662 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Execution of scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b] finished at 1598352878662. Was started at millis: 1598352878646 (=duration of 16 millis)
2020-08-25 05:54:52.761 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2020-08-25 05:55:05.080 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.openhab.addons)
2020-08-25 05:55:05.081 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.openhab.addons bound to mvn:org.openhab.core.bundles/org.openhab.core.karaf/2.5.0
2020-08-25 05:55:05.081 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.ops4j.pax.url.mvn, location=null)
2020-08-25 05:55:05.082 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.ops4j.pax.url.mvn bound to ?
2020-08-25 05:55:05.082 [DEBUG] [org.apache.felix.configadmin        ] - getConfiguration(pid=org.ops4j.pax.url.mvn, location=null)
2020-08-25 05:55:05.083 [DEBUG] [org.apache.felix.configadmin        ] - Found cached configuration org.ops4j.pax.url.mvn bound to ?
2020-08-25 05:55:08.678 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Executing scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b]. Current millis: 1598352908678
2020-08-25 05:55:08.678 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-08-25 05:55:08.685 [DEBUG] [bus.handler.ModbusPollerThingHandler] - Thing modbus:poller:HVAC:hvacpoll received response PollResult(result=AsyncModbusReadResult(request = ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3], registers = ModbusRegisterArrayImpl(80 00)))
2020-08-25 05:55:08.686 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:hvacpoll:reg32768 channels updated: {modbus:data:HVAC:hvacpoll:reg32768:number=-32768, modbus:data:HVAC:hvacpoll:reg32768:lastReadSuccess=2020-08-25T05:55:08.685-0500}. readValueType=int16, readIndex=Optional[32768], readSubIndex(or 0)=0, extractIndex=0 -> numeric value -32768 and boolValue=true. Registers ModbusRegisterArrayImpl(80 00) for request ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3]
2020-08-25 05:55:08.687 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 8 ms, connection: 4, transaction=2, callback=2} [operation ID 64e9bda7-7e35-464b-9955-c8e4d4d1b523]
2020-08-25 05:55:08.687 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Execution of scheduled (30000ms) poll task BasicPollTask@4e64568b[request=ModbusPollerThingHandler.ModbusPollerReadRequest@456ecc78[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=32768,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@50929ac[address=192.168.1.111,port=502],resultCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b,failureCallback=org.openhab.binding.modbus.handler.ModbusPollerThingHandler$ReadCallbackDelegator@5f4fb53b] finished at 1598352908687. Was started at millis: 1598352908678 (=duration of 9 millis)
2020-08-25 05:55:19.118 [DEBUG] [rg.quartz.core.QuartzSchedulerThread] - batch acquisition of 0 triggers
2020-08-25 05:55:28.346 [DEBUG] [e.osgi.LoggingCommandSessionListener] - Executing command: 'logout'
2020-08-25 05:55:28.353 [INFO ] [raf.shell.commands.impl.LogoutAction] - Disconnecting from current session...
1 Like
81

Update:

I ran the Modbus trial again overnight last night with the only change being going from reading once every 30 seconds to once per second.

Everything was still working this morning and I still have not noticed any errors.

I have not done any more today, trying to prepare and waiting to see what hurricane Laura does to us.

82

@ssalonen,

I ran the previous test overnight last night with the extra logging as before and it ran all night, it would still log changes in the register this morning and I did not notice any errors. The refresh was set for 1000 ms.

This morning, without shutting down openhab, I changed the refresh to 250 ms and it has ran since then and will still log changes in the register and I haven’t noticed any errors, repeatedly logging the HVAC_Temp_Last_Success message in the event log.

The purpose of all of this was to produce some errors in the logs that I could send but everything seems to run good when the logging is in place.

I guess I will try again later this evening with some of the extra logging removed and see what happens. The last time I tried running it without the extra logging it wasn’t long before it quit logging changes in the register.

It almost seems like when you keep it constantly busy everything works but when the extra logging is removed it goes back to not logging register changes for very long.

For what it’s worth, all openhab is currently doing is the reading and logging of the single Modbus register. I have held off on doing anything else with openhab until I could get this issue resolved.

Maybe I could turn the extra stuff off one item at a time and see if/when it quits again. I wouldn’t mind some logging being in place all the time if that would keep it working, but it seems like that should be unnecessary and I am using solid state drives and understand there is limit on total writes before the drive expires although that limit is probably a lot.

It seems to work very well except for this one issue.

I may be doing something very stupid here but I don’t know what it is. I feel very bad about wasting your time and the time of others that have tried to help. I have been reading a lot of posts in another thread where there was a lot of heated arguments back and forth over time wasted fooling with inexperienced users and I really don’t want to be one of those they are talking about.

I will proceed with what I mentioned unless you might have a better idea.

Thanks again!