2020-04-18 09:14:15.656 [TRACE] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:localhostTCP:holding:ScreenLivGrH ‘Modbus Data’ received command ‘69’ to channel ‘modbus:data:localhostTCP:holding:ScreenLivGrH:dimmer’
2020-04-18 09:14:15.678 [TRACE] [ernal.handler.ModbusDataThingHandler] - Submitting write task: BasicWriteTask@190657b[request=BasicModbusWriteRegisterRequestBlueprint@15852d8[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 45),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7] (based from transformation [{“functionCode”: 6, “address”:32798, “value”: [69] },{“functionCode”: 6, “address”:32810, “value”: [1] }])
2020-04-18 09:14:15.683 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Scheduling one-off write task BasicWriteTask@190657b[request=BasicModbusWriteRegisterRequestBlueprint@15852d8[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 45),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7]
2020-04-18 09:14:15.687 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Will now execute one-off write task BasicWriteTask@190657b[request=BasicModbusWriteRegisterRequestBlueprint@15852d8[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 45),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7], waited in thread pool for 3
2020-04-18 09:14:15.688 [TRACE] [ernal.handler.ModbusDataThingHandler] - Submitting write task: BasicWriteTask@1f3c1a0[request=BasicModbusWriteRegisterRequestBlueprint@17cd158[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7] (based from transformation [{“functionCode”: 6, “address”:32798, “value”: [69] },{“functionCode”: 6, “address”:32810, “value”: [1] }])
2020-04-18 09:14:15.691 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Starting new operation with task BasicWriteTask@190657b[request=BasicModbusWriteRegisterRequestBlueprint@15852d8[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 45),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7]. Trying to get connection [operation ID b1c47de7-827a-4315-8d08-3a398da8a54c]
2020-04-18 09:14:15.691 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Scheduling one-off write task BasicWriteTask@1f3c1a0[request=BasicModbusWriteRegisterRequestBlueprint@17cd158[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7]
2020-04-18 09:14:15.694 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Executing task BasicWriteTask@190657b[request=BasicModbusWriteRegisterRequestBlueprint@15852d8[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 45),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7] (oneOff=true)! Waiting for connection. Idle connections for this endpoint: 1, and active 0 [operation ID b1c47de7-827a-4315-8d08-3a398da8a54c]
2020-04-18 09:14:15.695 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Will now execute one-off write task BasicWriteTask@1f3c1a0[request=BasicModbusWriteRegisterRequestBlueprint@17cd158[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7], waited in thread pool for 5
2020-04-18 09:14:15.697 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-04-18 09:14:15.699 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Starting new operation with task BasicWriteTask@1f3c1a0[request=BasicModbusWriteRegisterRequestBlueprint@17cd158[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7]. Trying to get connection [operation ID b1ed4c46-1281-41d6-976c-2ccfa23a96c3]
2020-04-18 09:14:15.703 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Executing task BasicWriteTask@1f3c1a0[request=BasicModbusWriteRegisterRequestBlueprint@17cd158[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7] (oneOff=true)! Waiting for connection. Idle connections for this endpoint: 0, and active 1 [operation ID b1ed4c46-1281-41d6-976c-2ccfa23a96c3]
2020-04-18 09:14:15.704 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Waited 0ms (interTransactionDelayMillis 60ms) before giving returning connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57940]] for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502], to ensure delay between transactions.
2020-04-18 09:14:15.708 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - borrowing connection (got Optional[TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57940]]]) for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502] took 11 ms
2020-04-18 09:14:15.712 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Executing task BasicWriteTask@190657b[request=BasicModbusWriteRegisterRequestBlueprint@15852d8[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 45),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7] (oneOff=true)! Connection received in 15 ms [operation ID b1c47de7-827a-4315-8d08-3a398da8a54c]
2020-04-18 09:14:15.715 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Operation with task BasicWriteTask@190657b[request=BasicModbusWriteRegisterRequestBlueprint@15852d8[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 45),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7]. Got a connection successfully [operation ID b1c47de7-827a-4315-8d08-3a398da8a54c]
2020-04-18 09:14:15.718 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 [operation ID b1c47de7-827a-4315-8d08-3a398da8a54c]
2020-04-18 09:14:15.721 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping if necessary [operation ID b1c47de7-827a-4315-8d08-3a398da8a54c]
2020-04-18 09:14:15.724 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Sleep ended, slept 0 [operation ID b1c47de7-827a-4315-8d08-3a398da8a54c]
2020-04-18 09:14:15.727 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Going execute transaction with read request (FC=WRITE_SINGLE_REGISTER): 00 00 00 00 00 06 02 06 80 1e 00 45 [operation ID b1c47de7-827a-4315-8d08-3a398da8a54c]
2020-04-18 09:14:15.730 [TRACE] [wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 24964: net.wimpi.modbus.msg.WriteSingleRegisterRequest@b48112
2020-04-18 09:14:15.743 [TRACE] [wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 24964
2020-04-18 09:14:15.746 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Response for write request (FC=6, transaction ID=24964): 61 84 00 00 00 06 02 06 80 1e 00 45 [operation ID b1c47de7-827a-4315-8d08-3a398da8a54c]
2020-04-18 09:14:15.747 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Calling write response callback org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7 for request BasicModbusWriteRegisterRequestBlueprint@15852d8[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 45),maxTries=3]. Response was ModbusResponseImpl(responseFC=6)
2020-04-18 09:14:15.750 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Successful write, matching request BasicModbusWriteRegisterRequestBlueprint@15852d8[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 45),maxTries=3]
2020-04-18 09:14:15.753 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Called write response callback org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7 for request BasicModbusWriteRegisterRequestBlueprint@15852d8[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 45),maxTries=3]. Response was ModbusResponseImpl(responseFC=6)
2020-04-18 09:14:15.755 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502] connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57940]] -> true
2020-04-18 09:14:15.757 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Passivating connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57940]] for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502]…
2020-04-18 09:14:15.759 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - (passivate) Connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57940]] (endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502]) age 56ms is over the reconnectAfterMillis=0ms limit or has been connection time (1587194055703) is after the “disconnectBeforeConnectedMillis”=1587150537379 -> disconnecting.
2020-04-18 09:14:15.762 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - …Passivated connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57940]] for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502]
2020-04-18 09:14:15.764 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - returned connection to pool for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502]
2020-04-18 09:14:15.766 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - returning connection for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502] took 11 ms
2020-04-18 09:14:15.767 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-04-18 09:14:15.768 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Connection was returned to the pool, ending operation [operation ID b1c47de7-827a-4315-8d08-3a398da8a54c]
2020-04-18 09:14:15.770 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 79 ms, connection: 28, transaction=15, callback=8} [operation ID b1c47de7-827a-4315-8d08-3a398da8a54c]
2020-04-18 09:14:15.820 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Waited 49ms (interTransactionDelayMillis 60ms) before giving returning connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57942]] for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502], to ensure delay between transactions.
2020-04-18 09:14:15.822 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - borrowing connection (got Optional[TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57942]]]) for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502] took 115 ms
2020-04-18 09:14:15.823 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Executing task BasicWriteTask@1f3c1a0[request=BasicModbusWriteRegisterRequestBlueprint@17cd158[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7] (oneOff=true)! Connection received in 117 ms [operation ID b1ed4c46-1281-41d6-976c-2ccfa23a96c3]
2020-04-18 09:14:15.825 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Operation with task BasicWriteTask@1f3c1a0[request=BasicModbusWriteRegisterRequestBlueprint@17cd158[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7]. Got a connection successfully [operation ID b1ed4c46-1281-41d6-976c-2ccfa23a96c3]
2020-04-18 09:14:15.827 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 [operation ID b1ed4c46-1281-41d6-976c-2ccfa23a96c3]
2020-04-18 09:14:15.828 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping if necessary [operation ID b1ed4c46-1281-41d6-976c-2ccfa23a96c3]
2020-04-18 09:14:15.829 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Sleep ended, slept 0 [operation ID b1ed4c46-1281-41d6-976c-2ccfa23a96c3]
2020-04-18 09:14:15.831 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Going execute transaction with read request (FC=WRITE_SINGLE_REGISTER): 00 00 00 00 00 06 02 06 80 2a 00 01 [operation ID b1ed4c46-1281-41d6-976c-2ccfa23a96c3]
2020-04-18 09:14:15.833 [TRACE] [wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 24965: net.wimpi.modbus.msg.WriteSingleRegisterRequest@1fd9228
2020-04-18 09:14:15.845 [TRACE] [wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 24965
2020-04-18 09:14:15.847 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Response for write request (FC=6, transaction ID=24965): 61 85 00 00 00 06 02 06 80 2a 00 01 [operation ID b1ed4c46-1281-41d6-976c-2ccfa23a96c3]
2020-04-18 09:14:15.849 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Calling write response callback org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7 for request BasicModbusWriteRegisterRequestBlueprint@17cd158[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3]. Response was ModbusResponseImpl(responseFC=6)
2020-04-18 09:14:15.850 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Successful write, matching request BasicModbusWriteRegisterRequestBlueprint@17cd158[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3]
2020-04-18 09:14:15.853 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Called write response callback org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7 for request BasicModbusWriteRegisterRequestBlueprint@17cd158[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3]. Response was ModbusResponseImpl(responseFC=6)
2020-04-18 09:14:15.854 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502] connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57942]] -> true
2020-04-18 09:14:15.856 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Passivating connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57942]] for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502]…
2020-04-18 09:14:15.858 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - (passivate) Connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57942]] (endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502]) age 87ms is over the reconnectAfterMillis=0ms limit or has been connection time (1587194055770) is after the “disconnectBeforeConnectedMillis”=1587150537379 -> disconnecting.
2020-04-18 09:14:15.860 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - …Passivated connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57942]] for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502]
2020-04-18 09:14:15.862 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - returned connection to pool for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502]
2020-04-18 09:14:15.864 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - returning connection for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502] took 9 ms
2020-04-18 09:14:15.865 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Connection was returned to the pool, ending operation [operation ID b1ed4c46-1281-41d6-976c-2ccfa23a96c3]
2020-04-18 09:14:15.867 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 168 ms, connection: 128, transaction=15, callback=6} [operation ID b1ed4c46-1281-41d6-976c-2ccfa23a96c3]
2020-04-18 09:14:17.536 [TRACE] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:localhostTCP:holding:ScreenLivGrH ‘Modbus Data’ received command ‘0’ to channel ‘modbus:data:localhostTCP:holding:ScreenLivGrH:dimmer’
2020-04-18 09:14:17.561 [TRACE] [ernal.handler.ModbusDataThingHandler] - Submitting write task: BasicWriteTask@138b765[request=BasicModbusWriteRegisterRequestBlueprint@15e1b0a[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 00),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7] (based from transformation [{“functionCode”: 6, “address”:32798, “value”: [0] },{“functionCode”: 6, “address”:32810, “value”: [1] }])
2020-04-18 09:14:17.565 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Scheduling one-off write task BasicWriteTask@138b765[request=BasicModbusWriteRegisterRequestBlueprint@15e1b0a[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 00),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7]
2020-04-18 09:14:17.570 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Will now execute one-off write task BasicWriteTask@138b765[request=BasicModbusWriteRegisterRequestBlueprint@15e1b0a[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 00),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7], waited in thread pool for 5
2020-04-18 09:14:17.570 [TRACE] [ernal.handler.ModbusDataThingHandler] - Submitting write task: BasicWriteTask@1833352[request=BasicModbusWriteRegisterRequestBlueprint@1d82f58[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7] (based from transformation [{“functionCode”: 6, “address”:32798, “value”: [0] },{“functionCode”: 6, “address”:32810, “value”: [1] }])
2020-04-18 09:14:17.573 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Starting new operation with task BasicWriteTask@138b765[request=BasicModbusWriteRegisterRequestBlueprint@15e1b0a[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 00),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7]. Trying to get connection [operation ID a7865652-2d9e-4dfa-8d36-288e9b4c86ef]
2020-04-18 09:14:17.575 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Scheduling one-off write task BasicWriteTask@1833352[request=BasicModbusWriteRegisterRequestBlueprint@1d82f58[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7]
2020-04-18 09:14:17.611 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Will now execute one-off write task BasicWriteTask@1833352[request=BasicModbusWriteRegisterRequestBlueprint@1d82f58[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7], waited in thread pool for 4
2020-04-18 09:14:17.615 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Starting new operation with task BasicWriteTask@1833352[request=BasicModbusWriteRegisterRequestBlueprint@1d82f58[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7]. Trying to get connection [operation ID a33c0b3e-2832-4e42-906e-504832f65fca]
2020-04-18 09:14:17.617 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Executing task BasicWriteTask@1833352[request=BasicModbusWriteRegisterRequestBlueprint@1d82f58[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7] (oneOff=true)! Waiting for connection. Idle connections for this endpoint: 1, and active 0 [operation ID a33c0b3e-2832-4e42-906e-504832f65fca]
2020-04-18 09:14:17.576 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Executing task BasicWriteTask@138b765[request=BasicModbusWriteRegisterRequestBlueprint@15e1b0a[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 00),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7] (oneOff=true)! Waiting for connection. Idle connections for this endpoint: 1, and active 0 [operation ID a7865652-2d9e-4dfa-8d36-288e9b4c86ef]
2020-04-18 09:14:17.620 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-04-18 09:14:17.624 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Waited 0ms (interTransactionDelayMillis 60ms) before giving returning connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57944]] for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502], to ensure delay between transactions.
2020-04-18 09:14:17.626 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - borrowing connection (got Optional[TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57944]]]) for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502] took 6 ms
2020-04-18 09:14:17.628 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Executing task BasicWriteTask@1833352[request=BasicModbusWriteRegisterRequestBlueprint@1d82f58[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7] (oneOff=true)! Connection received in 9 ms [operation ID a33c0b3e-2832-4e42-906e-504832f65fca]
2020-04-18 09:14:17.630 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Operation with task BasicWriteTask@1833352[request=BasicModbusWriteRegisterRequestBlueprint@1d82f58[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7]. Got a connection successfully [operation ID a33c0b3e-2832-4e42-906e-504832f65fca]
2020-04-18 09:14:17.632 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 [operation ID a33c0b3e-2832-4e42-906e-504832f65fca]
2020-04-18 09:14:17.633 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping if necessary [operation ID a33c0b3e-2832-4e42-906e-504832f65fca]
2020-04-18 09:14:17.635 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Sleep ended, slept 0 [operation ID a33c0b3e-2832-4e42-906e-504832f65fca]
2020-04-18 09:14:17.637 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Going execute transaction with read request (FC=WRITE_SINGLE_REGISTER): 00 00 00 00 00 06 02 06 80 2a 00 01 [operation ID a33c0b3e-2832-4e42-906e-504832f65fca]
2020-04-18 09:14:17.639 [TRACE] [wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 24966: net.wimpi.modbus.msg.WriteSingleRegisterRequest@1c146e7
2020-04-18 09:14:17.650 [TRACE] [wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 24966
2020-04-18 09:14:17.652 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Response for write request (FC=6, transaction ID=24966): 61 86 00 00 00 06 02 06 80 2a 00 01 [operation ID a33c0b3e-2832-4e42-906e-504832f65fca]
2020-04-18 09:14:17.654 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Calling write response callback org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7 for request BasicModbusWriteRegisterRequestBlueprint@1d82f58[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3]. Response was ModbusResponseImpl(responseFC=6)
2020-04-18 09:14:17.658 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Successful write, matching request BasicModbusWriteRegisterRequestBlueprint@1d82f58[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3]
2020-04-18 09:14:17.660 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Called write response callback org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7 for request BasicModbusWriteRegisterRequestBlueprint@1d82f58[slaveId=2,reference=32810,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 01),maxTries=3]. Response was ModbusResponseImpl(responseFC=6)
2020-04-18 09:14:17.662 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502] connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57944]] -> true
2020-04-18 09:14:17.664 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Passivating connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57944]] for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502]…
2020-04-18 09:14:17.666 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - (passivate) Connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57944]] (endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502]) age 43ms is over the reconnectAfterMillis=0ms limit or has been connection time (1587194057623) is after the “disconnectBeforeConnectedMillis”=1587150537379 -> disconnecting.
2020-04-18 09:14:17.669 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - …Passivated connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57944]] for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502]
2020-04-18 09:14:17.671 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - returned connection to pool for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502]
2020-04-18 09:14:17.673 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - returning connection for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502] took 10 ms
2020-04-18 09:14:17.674 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Connection was returned to the pool, ending operation [operation ID a33c0b3e-2832-4e42-906e-504832f65fca]
2020-04-18 09:14:17.676 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 60 ms, connection: 21, transaction=13, callback=9} [operation ID a33c0b3e-2832-4e42-906e-504832f65fca]
2020-04-18 09:14:17.683 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Waited 12ms (interConnectDelayMillis 0ms, interTransactionDelayMillis 60ms) before connecting disconnected connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57944]] for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502], to allow delay between connections re-connects
2020-04-18 09:14:17.685 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-04-18 09:14:17.726 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Waited 38ms (interTransactionDelayMillis 60ms) before giving returning connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57946]] for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502], to ensure delay between transactions.
2020-04-18 09:14:17.728 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - borrowing connection (got Optional[TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57946]]]) for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502] took 108 ms
2020-04-18 09:14:17.730 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Executing task BasicWriteTask@138b765[request=BasicModbusWriteRegisterRequestBlueprint@15e1b0a[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 00),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7] (oneOff=true)! Connection received in 110 ms [operation ID a7865652-2d9e-4dfa-8d36-288e9b4c86ef]
2020-04-18 09:14:17.732 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Operation with task BasicWriteTask@138b765[request=BasicModbusWriteRegisterRequestBlueprint@15e1b0a[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 00),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7]. Got a connection successfully [operation ID a7865652-2d9e-4dfa-8d36-288e9b4c86ef]
2020-04-18 09:14:17.733 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 [operation ID a7865652-2d9e-4dfa-8d36-288e9b4c86ef]
2020-04-18 09:14:17.735 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping if necessary [operation ID a7865652-2d9e-4dfa-8d36-288e9b4c86ef]
2020-04-18 09:14:17.736 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Sleep ended, slept 0 [operation ID a7865652-2d9e-4dfa-8d36-288e9b4c86ef]
2020-04-18 09:14:17.738 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Going execute transaction with read request (FC=WRITE_SINGLE_REGISTER): 00 00 00 00 00 06 02 06 80 1e 00 00 [operation ID a7865652-2d9e-4dfa-8d36-288e9b4c86ef]
2020-04-18 09:14:17.739 [TRACE] [wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 24967: net.wimpi.modbus.msg.WriteSingleRegisterRequest@137fb2d
2020-04-18 09:14:17.751 [TRACE] [wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 24967
2020-04-18 09:14:17.753 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Response for write request (FC=6, transaction ID=24967): 61 87 00 00 00 06 02 06 80 1e 00 00 [operation ID a7865652-2d9e-4dfa-8d36-288e9b4c86ef]
2020-04-18 09:14:17.755 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Calling write response callback org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7 for request BasicModbusWriteRegisterRequestBlueprint@15e1b0a[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 00),maxTries=3]. Response was ModbusResponseImpl(responseFC=6)
2020-04-18 09:14:17.756 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Successful write, matching request BasicModbusWriteRegisterRequestBlueprint@15e1b0a[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 00),maxTries=3]
2020-04-18 09:14:17.758 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Called write response callback org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler@179a9f7 for request BasicModbusWriteRegisterRequestBlueprint@15e1b0a[slaveId=2,reference=32798,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(00 00),maxTries=3]. Response was ModbusResponseImpl(responseFC=6)
2020-04-18 09:14:17.766 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502] connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57946]] -> true
2020-04-18 09:14:17.768 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Passivating connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57946]] for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502]…
2020-04-18 09:14:17.770 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - (passivate) Connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57946]] (endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502]) age 81ms is over the reconnectAfterMillis=0ms limit or has been connection time (1587194057688) is after the “disconnectBeforeConnectedMillis”=1587150537379 -> disconnecting.
2020-04-18 09:14:17.772 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - …Passivated connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57946]] for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502]
2020-04-18 09:14:17.774 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - returned connection to pool for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502]
2020-04-18 09:14:17.776 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - returning connection for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502] took 11 ms
2020-04-18 09:14:17.777 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Connection was returned to the pool, ending operation [operation ID a7865652-2d9e-4dfa-8d36-288e9b4c86ef]
2020-04-18 09:14:17.780 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Modbus operation ended, timing info: {total: 207 ms, connection: 122, transaction=14, callback=11} [operation ID a7865652-2d9e-4dfa-8d36-288e9b4c86ef]
2020-04-18 09:14:25.216 [TRACE] [ternal.ModbusManagerImpl.PollMonitor] -
2020-04-18 09:14:25.219 [TRACE] [ternal.ModbusManagerImpl.PollMonitor] - POLL MONITOR: scheduled poll task. FC: READ_INPUT_DISCRETES, start 32768, length 45, done: false, canceled: false, delay: 11079. Full task BasicPollTaskImpl@d03559[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@15ee052[slaveId=2,functionCode=READ_INPUT_DISCRETES,start=32768,length=45,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@3e949a84]
2020-04-18 09:14:25.230 [TRACE] [ternal.ModbusManagerImpl.PollMonitor] - POLL MONITOR: scheduled poll task. FC: READ_INPUT_REGISTERS, start 32768, length 45, done: false, canceled: false, delay: 11375. Full task BasicPollTaskImpl@1957c7b[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@16c10ae[slaveId=2,functionCode=READ_INPUT_REGISTERS,start=32768,length=45,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@7a006d83]
2020-04-18 09:14:25.233 [TRACE] [ternal.ModbusManagerImpl.PollMonitor] - POLL MONITOR: scheduledThreadPoolExecutor queue size: 2, remaining space 2147483647. Active threads 1
2020-04-18 09:14:25.235 [TRACE] [ternal.ModbusManagerImpl.PollMonitor] - </POLL MONITOR>
2020-04-18 09:14:35.237 [TRACE] [ternal.ModbusManagerImpl.PollMonitor] -
2020-04-18 09:14:35.241 [TRACE] [ternal.ModbusManagerImpl.PollMonitor] - POLL MONITOR: scheduled poll task. FC: READ_INPUT_DISCRETES, start 32768, length 45, done: false, canceled: false, delay: 1057. Full task BasicPollTaskImpl@d03559[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@15ee052[slaveId=2,functionCode=READ_INPUT_DISCRETES,start=32768,length=45,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@3e949a84]
2020-04-18 09:14:35.244 [TRACE] [ternal.ModbusManagerImpl.PollMonitor] - POLL MONITOR: scheduled poll task. FC: READ_INPUT_REGISTERS, start 32768, length 45, done: false, canceled: false, delay: 1361. Full task BasicPollTaskImpl@1957c7b[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@16c10ae[slaveId=2,functionCode=READ_INPUT_REGISTERS,start=32768,length=45,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@7a006d83]
2020-04-18 09:14:35.247 [TRACE] [ternal.ModbusManagerImpl.PollMonitor] - POLL MONITOR: scheduledThreadPoolExecutor queue size: 2, remaining space 2147483647. Active threads 1
2020-04-18 09:14:35.249 [TRACE] [ternal.ModbusManagerImpl.PollMonitor] - </POLL MONITOR>
2020-04-18 09:14:36.299 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Executing scheduled (50000ms) poll task BasicPollTaskImpl@d03559[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@15ee052[slaveId=2,functionCode=READ_INPUT_DISCRETES,start=32768,length=45,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@3e949a84]. Current millis: 1587194076298
2020-04-18 09:14:36.302 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Starting new operation with task BasicPollTaskImpl@d03559[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@15ee052[slaveId=2,functionCode=READ_INPUT_DISCRETES,start=32768,length=45,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@3e949a84]. Trying to get connection [operation ID e19e0a10-f87c-4c77-bf20-c6449d0a64fd]
2020-04-18 09:14:36.305 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Executing task BasicPollTaskImpl@d03559[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@15ee052[slaveId=2,functionCode=READ_INPUT_DISCRETES,start=32768,length=45,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@3e949a84] (oneOff=false)! Waiting for connection. Idle connections for this endpoint: 1, and active 0 [operation ID e19e0a10-f87c-4c77-bf20-c6449d0a64fd]
2020-04-18 09:14:36.308 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2020-04-18 09:14:36.315 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Waited 0ms (interTransactionDelayMillis 60ms) before giving returning connection TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57952]] for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502], to ensure delay between transactions.
2020-04-18 09:14:36.319 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - borrowing connection (got Optional[TCPMasterConnection@f1542[socket=Socket[addr=/192.168.0.37,port=502,localport=57952]]]) for endpoint ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502] took 10 ms
2020-04-18 09:14:36.323 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Executing task BasicPollTaskImpl@d03559[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@15ee052[slaveId=2,functionCode=READ_INPUT_DISCRETES,start=32768,length=45,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@3e949a84] (oneOff=false)! Connection received in 14 ms [operation ID e19e0a10-f87c-4c77-bf20-c6449d0a64fd]
2020-04-18 09:14:36.326 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Operation with task BasicPollTaskImpl@d03559[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@15ee052[slaveId=2,functionCode=READ_INPUT_DISCRETES,start=32768,length=45,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@56c345[address=192.168.0.37,port=502],callback=org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@3e949a84]. Got a connection successfully [operation ID e19e0a10-f87c-4c77-bf20-c6449d0a64fd]
2020-04-18 09:14:36.330 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 [operation ID e19e0a10-f87c-4c77-bf20-c6449d0a64fd]
2020-04-18 09:14:36.333 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping if necessary [operation ID e19e0a10-f87c-4c77-bf20-c6449d0a64fd]
2020-04-18 09:14:36.336 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Sleep ended, slept 0 [operation ID e19e0a10-f87c-4c77-bf20-c6449d0a64fd]
2020-04-18 09:14:36.339 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_INPUT_DISCRETES): 00 00 00 00 00 06 02 02 80 00 00 2d [operation ID e19e0a10-f87c-4c77-bf20-c6449d0a64fd]
2020-04-18 09:14:36.343 [TRACE] [wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 24968: net.wimpi.modbus.msg.ReadInputDiscretesRequest@7c2a08
2020-04-18 09:14:36.350 [TRACE] [wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 24968
2020-04-18 09:14:36.354 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Response for read request (FC=2, transaction ID=24968): 61 88 00 00 00 09 02 02 06 01 08 00 00 00 00 [operation ID e19e0a10-f87c-4c77-bf20-c6449d0a64fd]
2020-04-18 09:14:36.357 [TRACE] [modbus.internal.ModbusLibraryWrapper] - Calling read response callback org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@3e949a84 for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@15ee052[slaveId=2,functionCode=READ_INPUT_DISCRETES,start=32768,length=45,maxTries=3]. Response was net.wimpi.modbus.msg.ReadInputDiscretesResponse@6f03bc