Today I have been setting up second mb server on the PLC and trying to figure out how to pull those bits individualy from holding register. My .things file is a bit different now but I’ll revert back to the old one when I have more time. Hopefully tomorrow so you can start digging into this.
Just as a side note. Now when having two different connections with single pollers each those errors are gone.
Thanks!
Reading individual bits from registers should work using readValueType="bit" but let me know if you encounter any issues. See the basic example in readme:
//...
// Extract individual bits of the 16-bit register
// bit 0 is the least significant bit, and bit 15 is the most significant bit
Thing data input1502bit0 [ readStart="1502.0", readValueType="bit" ]
Thing data input1502bit1 [ readStart="1502.1", readValueType="bit" ]
Thing data input1502bit2 [ readStart="1502.2", readValueType="bit" ]
//...
Writing individual bits requires more effort by using e.g. proxy items and constructing the full 16 bit register from those using rules.
Best,
Sami
Yeah I have been reading docs and that’s where I got the idea to use holding register for status bits. Not on my computer now so cant’ show you the full example but something weird. I’f I create an array of booleans in s1200 and read them like your example says I can access only first two bits and they are with readStart=“0.8” and “0.9”. Could the encoding be somehow messed up?
Can you please share the holding register table from s1200 (screenshot from tia portal for example)?
You need to calculate yourself registers contain the boolean data…
Best,
Sami
I’ll take a screenshot for you. I don’t know if this is what you are meaning but I used modbus client to poll one register and started flipping bits on and off to see how they are arranged but i got so confused that I had to stop 
Hahaa! I got it!
In the picture below you can see the holding register table you requested and corresponding bit addresses in the comment section used by .things file to access the right bits.
Here’s also my current .things file section what is used to read these bits:
Bridge modbus:tcp:endpointTCP2 [ host="192.168.1.100", port=503, id=3, connectMaxTries=3 ] {
Bridge poller valves [ start=0, length=1, refresh=2000, type="holding" ] {
Thing data valveOh1 [ readStart="0.8", readValueType="bit" ]
Thing data valveOh2 [ readStart="0.9", readValueType="bit" ]
Thing data valveOh3 [ readStart="0.10", readValueType="bit" ]
Thing data valveOh4 [ readStart="0.11", readValueType="bit" ]
Thing data valveMh1 [ readStart="0.12", readValueType="bit" ]
Thing data valveMh2 [ readStart="0.13", readValueType="bit" ]
Thing data valveMh3 [ readStart="0.14", readValueType="bit" ]
Thing data valveMh4 [ readStart="0.15", readValueType="bit" ]
Thing data valvePh [ readStart="0.0", readValueType="bit" ]
}
}
I’ll do those dual poller testings later.
EDIT
Adding these data things as switch items and adding them to sitemap doesn’t seem to work. Whole sitemap stops working.
1) TRACE logs with one poller (holding register) and .things file:
16:44:59.239 [DEBUG] [ort.modbus.internal.ModbusManagerImpl] - Executing scheduled (5000ms) poll task PollTaskImpl@6e121efc[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@64412c0d[slaveId=2,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=14,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@604690f]
16:44:59.330 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Executing task PollTaskImpl@6e121efc[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@64412c0d[slaveId=2,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=14,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@604690f] (oneOff=false)! Waiting for connection [operation ID cebdd261-fdf1-419a-94c2-277eed249fa6]
16:44:59.376 [DEBUG] [.wimpi.modbus.net.TCPMasterConnection] - connect()
16:44:59.402 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502] connection TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48314]] -> true
16:44:59.430 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - borrowing connection (got Optional[TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48314]]]) for endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502] took 55 ms
16:44:59.459 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Executing task PollTaskImpl@6e121efc[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@64412c0d[slaveId=2,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=14,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@604690f] (oneOff=false)! Connection received in 84 ms [operation ID cebdd261-fdf1-419a-94c2-277eed249fa6]
16:44:59.508 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 [operation ID cebdd261-fdf1-419a-94c2-277eed249fa6]
16:44:59.524 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 02 03 00 00 00 0e [operation ID cebdd261-fdf1-419a-94c2-277eed249fa6]
16:44:59.551 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 37225: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@617f8625
16:44:59.588 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 37225
16:44:59.600 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=37225): 91 69 00 00 00 1f 02 03 1c 00 ed 00 00 00 cd 01 19 00 de 00 00 00 db 00 00 00 d4 00 00 00 e4 00 00 00 f3 01 17 [operation ID cebdd261-fdf1-419a-94c2-277eed249fa6]
16:44:59.633 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 2 out of 3 [operation ID cebdd261-fdf1-419a-94c2-277eed249fa6]
16:44:59.649 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping [operation ID cebdd261-fdf1-419a-94c2-277eed249fa6]
16:44:59.669 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Sleep ended [operation ID cebdd261-fdf1-419a-94c2-277eed249fa6]
16:44:59.685 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 02 03 00 00 00 0e [operation ID cebdd261-fdf1-419a-94c2-277eed249fa6]
16:44:59.713 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 37226: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@22405e06
16:44:59.785 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 37226
16:44:59.801 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=37226): 91 6a 00 00 00 1f 02 03 1c 00 ed 00 00 00 cd 01 19 00 de 00 00 00 db 00 00 00 d4 00 00 00 e4 00 00 00 f3 01 17 [operation ID cebdd261-fdf1-419a-94c2-277eed249fa6]
16:44:59.837 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 3 out of 3 [operation ID cebdd261-fdf1-419a-94c2-277eed249fa6]
16:44:59.857 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping [operation ID cebdd261-fdf1-419a-94c2-277eed249fa6]
16:44:59.876 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Sleep ended [operation ID cebdd261-fdf1-419a-94c2-277eed249fa6]
16:44:59.890 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 02 03 00 00 00 0e [operation ID cebdd261-fdf1-419a-94c2-277eed249fa6]
16:44:59.930 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 37227: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@19598ab7
16:45:00.008 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 37227
16:45:00.024 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=37227): 91 6b 00 00 00 1f 02 03 1c 00 ed 00 00 00 cd 01 19 00 de 00 00 00 db 00 00 00 d4 00 00 00 e4 00 00 00 f3 01 17 [operation ID cebdd261-fdf1-419a-94c2-277eed249fa6]
16:45:00.080 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502] connection TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48314]] -> true
16:45:00.139 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Passivating connection TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48314]] for endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502]...
16:45:00.197 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - (passivate) Connection TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48314]] (endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502]) age 798ms is over the reconnectAfterMillis=0ms limit or has been connection time (1510325099399) is after the "disconnectBeforeConnectedMillis"=1510325041339 -> disconnecting.
16:45:00.309 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - ...Passivated connection TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48314]] for endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502]
16:45:00.362 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - returned connection for endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502]
16:45:00.414 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Connection was returned to the pool, ending operation [operation ID cebdd261-fdf1-419a-94c2-277eed249fa6]
16:45:04.241 [DEBUG] [ort.modbus.internal.ModbusManagerImpl] - Executing scheduled (5000ms) poll task PollTaskImpl@6e121efc[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@64412c0d[slaveId=2,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=14,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@604690f]
16:45:04.326 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Executing task PollTaskImpl@6e121efc[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@64412c0d[slaveId=2,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=14,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@604690f] (oneOff=false)! Waiting for connection [operation ID 1ac20635-1114-453d-97d7-1fc4b576afe7]
16:45:04.371 [DEBUG] [.wimpi.modbus.net.TCPMasterConnection] - connect()
16:45:04.414 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502] connection TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48315]] -> true
16:45:04.455 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - borrowing connection (got Optional[TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48315]]]) for endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502] took 84 ms
16:45:04.495 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Executing task PollTaskImpl@6e121efc[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@64412c0d[slaveId=2,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=14,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@604690f] (oneOff=false)! Connection received in 124 ms [operation ID 1ac20635-1114-453d-97d7-1fc4b576afe7]
16:45:04.546 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 [operation ID 1ac20635-1114-453d-97d7-1fc4b576afe7]
16:45:04.560 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 02 03 00 00 00 0e [operation ID 1ac20635-1114-453d-97d7-1fc4b576afe7]
16:45:04.584 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 37228: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@5ffe9d73
16:45:04.664 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 37228
16:45:04.679 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=37228): 91 6c 00 00 00 1f 02 03 1c 00 ed 00 00 00 cd 01 19 00 de 00 00 00 dc 00 00 00 d4 00 00 00 e4 00 00 00 f3 01 17 [operation ID 1ac20635-1114-453d-97d7-1fc4b576afe7]
16:45:04.716 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 2 out of 3 [operation ID 1ac20635-1114-453d-97d7-1fc4b576afe7]
16:45:04.734 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping [operation ID 1ac20635-1114-453d-97d7-1fc4b576afe7]
16:45:04.758 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Sleep ended [operation ID 1ac20635-1114-453d-97d7-1fc4b576afe7]
16:45:04.777 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 02 03 00 00 00 0e [operation ID 1ac20635-1114-453d-97d7-1fc4b576afe7]
16:45:04.809 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 37229: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@5bc11254
16:45:04.955 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 37229
16:45:04.968 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=37229): 91 6d 00 00 00 1f 02 03 1c 00 ed 00 00 00 cd 01 19 00 de 00 00 00 dc 00 00 00 d4 00 00 00 e4 00 00 00 f3 01 17 [operation ID 1ac20635-1114-453d-97d7-1fc4b576afe7]
16:45:05.007 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 3 out of 3 [operation ID 1ac20635-1114-453d-97d7-1fc4b576afe7]
16:45:05.038 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping [operation ID 1ac20635-1114-453d-97d7-1fc4b576afe7]
16:45:05.078 [INFO ] [smarthome.event.ItemStateChangedEvent] - modbusMakuuhuone2 changed from 21.9 to 22.0
16:45:05.087 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Sleep ended [operation ID 1ac20635-1114-453d-97d7-1fc4b576afe7]
16:45:05.109 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 02 03 00 00 00 0e [operation ID 1ac20635-1114-453d-97d7-1fc4b576afe7]
16:45:05.133 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 37230: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@1ec39748
16:45:05.196 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 37230
16:45:05.221 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=37230): 91 6e 00 00 00 1f 02 03 1c 00 ed 00 00 00 cd 01 19 00 de 00 00 00 dc 00 00 00 d4 00 00 00 e4 00 00 00 f3 01 17 [operation ID 1ac20635-1114-453d-97d7-1fc4b576afe7]
16:45:05.277 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502] connection TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48315]] -> true
16:45:05.343 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Passivating connection TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48315]] for endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502]...
16:45:05.401 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - (passivate) Connection TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48315]] (endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502]) age 987ms is over the reconnectAfterMillis=0ms limit or has been connection time (1510325104414) is after the "disconnectBeforeConnectedMillis"=1510325041339 -> disconnecting.
16:45:05.518 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - ...Passivated connection TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48315]] for endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502]
16:45:05.574 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - returned connection for endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502]
16:45:05.607 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Connection was returned to the pool, ending operation [operation ID 1ac20635-1114-453d-97d7-1fc4b576afe7]
16:45:05.781 [INFO ] [smarthome.event.ItemStateChangedEvent] - cpuLoad changed from 20.2 to 10.2
16:45:09.239 [DEBUG] [ort.modbus.internal.ModbusManagerImpl] - Executing scheduled (5000ms) poll task PollTaskImpl@6e121efc[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@64412c0d[slaveId=2,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=14,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@604690f]
16:45:09.332 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Executing task PollTaskImpl@6e121efc[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@64412c0d[slaveId=2,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=14,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@604690f] (oneOff=false)! Waiting for connection [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.377 [DEBUG] [.wimpi.modbus.net.TCPMasterConnection] - connect()
16:45:09.401 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502] connection TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48316]] -> true
16:45:09.430 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - borrowing connection (got Optional[TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48316]]]) for endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502] took 53 ms
16:45:09.465 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Executing task PollTaskImpl@6e121efc[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@64412c0d[slaveId=2,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=14,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@604690f] (oneOff=false)! Connection received in 88 ms [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.529 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.548 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 02 03 00 00 00 0e [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.573 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 37231: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@2f972d1e
16:45:09.638 [INFO ] [smarthome.event.ItemStateChangedEvent] - TempOutside changed from 3 to 2
16:45:09.645 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 37231
16:45:09.642 [INFO ] [smarthome.event.ItemStateChangedEvent] - OutEfficiency changed from 75 to 71
16:45:09.660 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=37231): 91 6f 00 00 00 1f 02 03 1c 00 ed 00 00 00 cd 01 19 00 de 00 00 00 dc 00 00 00 d4 00 00 00 e4 00 00 00 f3 01 17 [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.673 [INFO ] [smarthome.event.ItemStateChangedEvent] - AverageEfficiency changed from 80 to 78
16:45:09.725 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 2 out of 3 [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.749 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.779 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Sleep ended [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.796 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 02 03 00 00 00 0e [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.822 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 37232: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@7c97d90a
16:45:09.894 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 37232
16:45:09.908 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=37232): 91 70 00 00 00 1f 02 03 1c 00 ed 00 00 00 cd 01 19 00 de 00 00 00 dc 00 00 00 d4 00 00 00 e4 00 00 00 f3 01 17 [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.939 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 3 out of 3 [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.955 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.975 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Sleep ended [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.991 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 02 03 00 00 00 0e [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:10.026 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 37233: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@7eec6807
16:45:10.114 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 37233
16:45:10.126 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=37233): 91 71 00 00 00 1f 02 03 1c 00 ed 00 00 00 cd 01 19 00 de 00 00 00 dc 00 00 00 d4 00 00 00 e4 00 00 00 f3 01 17 [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:10.164 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502] connection TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48316]] -> true
16:45:10.344 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Passivating connection TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48316]] for endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502]...
16:45:10.400 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - (passivate) Connection TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48316]] (endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502]) age 999ms is over the reconnectAfterMillis=0ms limit or has been connection time (1510325109401) is after the "disconnectBeforeConnectedMillis"=1510325041339 -> disconnecting.
16:45:10.514 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - ...Passivated connection TCPMasterConnection@d88df3[socket=Socket[addr=/192.168.1.100,port=502,localport=48316]] for endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502]
16:45:10.564 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - returned connection for endpoint ModbusTCPSlaveEndpoint@31d95705[address=192.168.1.100,port=502]
16:45:10.603 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Connection was returned to the pool, ending operation [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
Bridge modbus:tcp:endpointTCP [ host="192.168.1.100", port=502, id=2, connectMaxTries=3 ] {
Bridge poller greenlineCoil [ start=3, length=4, refresh=0, type="coil" ] {
Thing data d04 [ readStart="3", writeStart="3", readValueType="bit", writeType="coil" ]
Thing data d05 [ readStart="4", writeStart="4", readValueType="bit", writeType="coil" ]
Thing data d06 [ readStart="5", writeStart="5", readValueType="bit", writeType="coil" ]
Thing data d07 [ readStart="6", writeStart="6", readValueType="bit", writeType="coil" ]
}
Bridge poller holding [ start=0, length=14, refresh=5000, type="holding" ] {
Thing data mh4 [ readStart="0", readValueType="uint16", readTransform="JS(divide.js)" ]
Thing data ph [ readStart="2", readValueType="uint16", readTransform="JS(divide.js)" ]
Thing data phrh [ readStart="3", readValueType="uint16", readTransform="JS(divide.js)" ]
Thing data mh1 [ readStart="4", readValueType="uint16", readTransform="JS(divide.js)" ]
Thing data mh2 [ readStart="6", readValueType="uint16", readTransform="JS(divide.js)" ]
Thing data mh3 [ readStart="8", readValueType="uint16", readTransform="JS(divide.js)" ]
Thing data oh [ readStart="10", readValueType="uint16", readTransform="JS(divide.js)" ]
Thing data tekn [ readStart="12", readValueType="uint16", readTransform="JS(divide.js)" ]
Thing data teknrh [ readStart="13", readValueType="uint16", readTransform="JS(divide.js)" ]
}
}
Continues in next post →
–>
2) TRACE logs with two pollers (holding register and 4 coils) and .things file:
17:02:44.289 [DEBUG] [ort.modbus.internal.ModbusManagerImpl] - Executing scheduled (5000ms) poll task PollTaskImpl@21e3ee75[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@2f04de46[slaveId=2,functionCode=READ_COILS,start=3,length=4,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@52b96366]
17:02:44.374 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Executing task PollTaskImpl@21e3ee75[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@2f04de46[slaveId=2,functionCode=READ_COILS,start=3,length=4,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@52b96366] (oneOff=false)! Waiting for connection [operation ID 8deacf57-16af-401e-b1b9-aace50278baf]
17:02:44.417 [DEBUG] [.wimpi.modbus.net.TCPMasterConnection] - connect()
17:02:44.444 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502] connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48646]] -> true
17:02:44.472 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - borrowing connection (got Optional[TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48646]]]) for endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502] took 55 ms
17:02:44.504 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Executing task PollTaskImpl@21e3ee75[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@2f04de46[slaveId=2,functionCode=READ_COILS,start=3,length=4,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@52b96366] (oneOff=false)! Connection received in 87 ms [operation ID 8deacf57-16af-401e-b1b9-aace50278baf]
17:02:44.555 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 [operation ID 8deacf57-16af-401e-b1b9-aace50278baf]
17:02:44.474 [DEBUG] [ort.modbus.internal.ModbusManagerImpl] - Executing scheduled (5000ms) poll task PollTaskImpl@4c3d0299[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@466a0020[slaveId=2,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=14,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@2adddfcb]
17:02:44.571 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_COILS): 00 00 00 00 00 06 02 01 00 03 00 04 [operation ID 8deacf57-16af-401e-b1b9-aace50278baf]
17:02:44.614 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Executing task PollTaskImpl@4c3d0299[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@466a0020[slaveId=2,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=14,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@2adddfcb] (oneOff=false)! Waiting for connection [operation ID fb334e58-700a-4c58-a7f8-1aba5049fc91]
17:02:44.640 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 38059: net.wimpi.modbus.msg.ReadCoilsRequest@6ba520df
17:02:44.750 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 38059
17:02:44.766 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=1, transaction ID=38059): 94 ab 00 00 00 04 02 01 01 00 [operation ID 8deacf57-16af-401e-b1b9-aace50278baf]
17:02:44.796 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 2 out of 3 [operation ID 8deacf57-16af-401e-b1b9-aace50278baf]
17:02:44.816 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping [operation ID 8deacf57-16af-401e-b1b9-aace50278baf]
17:02:44.797 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #0
17:02:44.842 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Sleep ended [operation ID 8deacf57-16af-401e-b1b9-aace50278baf]
17:02:44.878 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_COILS): 00 00 00 00 00 06 02 01 00 03 00 04 [operation ID 8deacf57-16af-401e-b1b9-aace50278baf]
17:02:44.860 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #1
17:02:44.909 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 38060: net.wimpi.modbus.msg.ReadCoilsRequest@16a6f875
17:02:44.926 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #2
17:02:44.960 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #3
17:02:45.003 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 38060
17:02:45.018 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=1, transaction ID=38060): 94 ac 00 00 00 04 02 01 01 00 [operation ID 8deacf57-16af-401e-b1b9-aace50278baf]
17:02:45.045 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #0
17:02:45.049 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 3 out of 3 [operation ID 8deacf57-16af-401e-b1b9-aace50278baf]
17:02:45.060 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #1
17:02:45.078 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping [operation ID 8deacf57-16af-401e-b1b9-aace50278baf]
17:02:45.092 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #2
17:02:45.116 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Sleep ended [operation ID 8deacf57-16af-401e-b1b9-aace50278baf]
17:02:45.130 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #3
17:02:45.148 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_COILS): 00 00 00 00 00 06 02 01 00 03 00 04 [operation ID 8deacf57-16af-401e-b1b9-aace50278baf]
17:02:45.195 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 38061: net.wimpi.modbus.msg.ReadCoilsRequest@71b01d6b
17:02:45.248 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 38061
17:02:45.265 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=1, transaction ID=38061): 94 ad 00 00 00 04 02 01 01 00 [operation ID 8deacf57-16af-401e-b1b9-aace50278baf]
17:02:45.295 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #0
17:02:45.297 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502] connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48646]] -> true
17:02:45.312 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #1
17:02:45.352 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Passivating connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48646]] for endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502]...
17:02:45.369 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #2
17:02:45.408 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - (passivate) Connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48646]] (endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502]) age 964ms is over the reconnectAfterMillis=0ms limit or has been connection time (1510326164444) is after the "disconnectBeforeConnectedMillis"=1510326144369 -> disconnecting.
17:02:45.425 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #3
17:02:45.501 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - ...Passivated connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48646]] for endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502]
17:02:45.534 [DEBUG] [.wimpi.modbus.net.TCPMasterConnection] - connect()
17:02:45.537 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - returned connection for endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502]
17:02:45.562 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Connection was returned to the pool, ending operation [operation ID 8deacf57-16af-401e-b1b9-aace50278baf]
17:02:45.569 [ERROR] [ling.ModbusSlaveConnectionFactoryImpl] - connect try 1/3 error: Yhteys torjuttu (Connection refused). Connection TCPMasterConnection@2b4765df[socket=Socket[unconnected]]. Endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502]
17:02:45.718 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Waited 100ms (interConnectDelayMillis 0ms, passivateBorrowMinMillis 100ms) before connecting disconnected connection TCPMasterConnection@2b4765df[socket=Socket[unconnected]] for endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502], to allow delay between connections re-connects
17:02:45.816 [DEBUG] [.wimpi.modbus.net.TCPMasterConnection] - connect()
17:02:45.852 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502] connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48648]] -> true
17:02:45.881 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - borrowing connection (got Optional[TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48648]]]) for endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502] took 1189 ms
17:02:45.910 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Executing task PollTaskImpl@4c3d0299[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@466a0020[slaveId=2,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=14,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@2adddfcb] (oneOff=false)! Connection received in 1218 ms [operation ID fb334e58-700a-4c58-a7f8-1aba5049fc91]
17:02:45.957 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 [operation ID fb334e58-700a-4c58-a7f8-1aba5049fc91]
17:02:45.973 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 02 03 00 00 00 0e [operation ID fb334e58-700a-4c58-a7f8-1aba5049fc91]
17:02:46.000 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 38062: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@2c0fc0e4
17:02:46.025 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 38062
17:02:46.039 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=38062): 94 ae 00 00 00 1f 02 03 1c 00 ed 00 00 00 cb 01 19 00 de 00 00 00 db 00 00 00 d4 00 00 00 e4 00 00 00 f3 01 16 [operation ID fb334e58-700a-4c58-a7f8-1aba5049fc91]
17:02:46.073 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 2 out of 3 [operation ID fb334e58-700a-4c58-a7f8-1aba5049fc91]
17:02:46.089 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping [operation ID fb334e58-700a-4c58-a7f8-1aba5049fc91]
17:02:46.109 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Sleep ended [operation ID fb334e58-700a-4c58-a7f8-1aba5049fc91]
17:02:46.125 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 02 03 00 00 00 0e [operation ID fb334e58-700a-4c58-a7f8-1aba5049fc91]
17:02:46.150 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 38063: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@769e7f43
17:02:46.331 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 38063
17:02:46.344 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=38063): 94 af 00 00 00 1f 02 03 1c 00 ed 00 00 00 cb 01 19 00 de 00 00 00 db 00 00 00 d4 00 00 00 e4 00 00 00 f3 01 16 [operation ID fb334e58-700a-4c58-a7f8-1aba5049fc91]
17:02:46.375 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 3 out of 3 [operation ID fb334e58-700a-4c58-a7f8-1aba5049fc91]
17:02:46.392 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping [operation ID fb334e58-700a-4c58-a7f8-1aba5049fc91]
17:02:46.413 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Sleep ended [operation ID fb334e58-700a-4c58-a7f8-1aba5049fc91]
17:02:46.428 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 02 03 00 00 00 0e [operation ID fb334e58-700a-4c58-a7f8-1aba5049fc91]
17:02:46.454 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 38064: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@40198db1
17:02:46.528 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 38064
17:02:46.543 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=38064): 94 b0 00 00 00 1f 02 03 1c 00 ed 00 00 00 cb 01 19 00 de 00 00 00 db 00 00 00 d4 00 00 00 e4 00 00 00 f3 01 16 [operation ID fb334e58-700a-4c58-a7f8-1aba5049fc91]
17:02:46.605 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502] connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48648]] -> true
17:02:46.665 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Passivating connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48648]] for endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502]...
17:02:46.729 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - (passivate) Connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48648]] (endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502]) age 877ms is over the reconnectAfterMillis=0ms limit or has been connection time (1510326165852) is after the "disconnectBeforeConnectedMillis"=1510326144369 -> disconnecting.
17:02:46.806 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - ...Passivated connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48648]] for endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502]
17:02:46.862 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - returned connection for endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502]
17:02:46.901 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Connection was returned to the pool, ending operation [operation ID fb334e58-700a-4c58-a7f8-1aba5049fc91]
17:02:49.289 [DEBUG] [ort.modbus.internal.ModbusManagerImpl] - Executing scheduled (5000ms) poll task PollTaskImpl@21e3ee75[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@2f04de46[slaveId=2,functionCode=READ_COILS,start=3,length=4,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@52b96366]
17:02:49.378 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Executing task PollTaskImpl@21e3ee75[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@2f04de46[slaveId=2,functionCode=READ_COILS,start=3,length=4,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@52b96366] (oneOff=false)! Waiting for connection [operation ID 514b24f6-dd89-4482-8afb-b5d0db37ee71]
17:02:49.446 [DEBUG] [.wimpi.modbus.net.TCPMasterConnection] - connect()
17:02:49.468 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502] connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48649]] -> true
17:02:49.474 [DEBUG] [ort.modbus.internal.ModbusManagerImpl] - Executing scheduled (5000ms) poll task PollTaskImpl@4c3d0299[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@466a0020[slaveId=2,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=14,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@2adddfcb]
17:02:49.548 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Executing task PollTaskImpl@4c3d0299[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@466a0020[slaveId=2,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=14,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@2adddfcb] (oneOff=false)! Waiting for connection [operation ID 2d24b42d-dc4a-47c9-b7b9-ba55dc7491f0]
17:02:49.502 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - borrowing connection (got Optional[TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48649]]]) for endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502] took 56 ms
17:02:49.648 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Executing task PollTaskImpl@21e3ee75[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@2f04de46[slaveId=2,functionCode=READ_COILS,start=3,length=4,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@52b96366] (oneOff=false)! Connection received in 202 ms [operation ID 514b24f6-dd89-4482-8afb-b5d0db37ee71]
17:02:49.691 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 [operation ID 514b24f6-dd89-4482-8afb-b5d0db37ee71]
17:02:49.705 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_COILS): 00 00 00 00 00 06 02 01 00 03 00 04 [operation ID 514b24f6-dd89-4482-8afb-b5d0db37ee71]
17:02:49.727 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 38065: net.wimpi.modbus.msg.ReadCoilsRequest@3d8ac49f
17:02:49.770 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 38065
17:02:49.784 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=1, transaction ID=38065): 94 b1 00 00 00 04 02 01 01 00 [operation ID 514b24f6-dd89-4482-8afb-b5d0db37ee71]
17:02:49.808 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 2 out of 3 [operation ID 514b24f6-dd89-4482-8afb-b5d0db37ee71]
17:02:49.809 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #0
17:02:49.825 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping [operation ID 514b24f6-dd89-4482-8afb-b5d0db37ee71]
17:02:49.839 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #1
17:02:49.860 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Sleep ended [operation ID 514b24f6-dd89-4482-8afb-b5d0db37ee71]
17:02:49.873 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #2
17:02:49.887 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_COILS): 00 00 00 00 00 06 02 01 00 03 00 04 [operation ID 514b24f6-dd89-4482-8afb-b5d0db37ee71]
17:02:49.900 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #3
17:02:49.923 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 38066: net.wimpi.modbus.msg.ReadCoilsRequest@1b9b1c6e
17:02:49.975 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 38066
17:02:49.991 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=1, transaction ID=38066): 94 b2 00 00 00 04 02 01 01 00 [operation ID 514b24f6-dd89-4482-8afb-b5d0db37ee71]
17:02:50.020 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 3 out of 3 [operation ID 514b24f6-dd89-4482-8afb-b5d0db37ee71]
17:02:50.021 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #0
17:02:50.040 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping [operation ID 514b24f6-dd89-4482-8afb-b5d0db37ee71]
17:02:50.083 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Sleep ended [operation ID 514b24f6-dd89-4482-8afb-b5d0db37ee71]
17:02:50.057 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #1
17:02:50.098 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_COILS): 00 00 00 00 00 06 02 01 00 03 00 04 [operation ID 514b24f6-dd89-4482-8afb-b5d0db37ee71]
17:02:50.111 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #2
17:02:50.134 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 38067: net.wimpi.modbus.msg.ReadCoilsRequest@336ea08e
17:02:50.147 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #3
17:02:50.175 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 38067
17:02:50.188 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=1, transaction ID=38067): 94 b3 00 00 00 04 02 01 01 00 [operation ID 514b24f6-dd89-4482-8afb-b5d0db37ee71]
17:02:50.215 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502] connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48649]] -> true
17:02:50.250 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Passivating connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48649]] for endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502]...
17:02:50.287 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - (passivate) Connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48649]] (endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502]) age 819ms is over the reconnectAfterMillis=0ms limit or has been connection time (1510326169468) is after the "disconnectBeforeConnectedMillis"=1510326144369 -> disconnecting.
17:02:50.215 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #0
17:02:50.349 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #1
17:02:50.360 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #2
17:02:50.361 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - ...Passivated connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48649]] for endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502]
17:02:50.372 [TRACE] [net.wimpi.modbus.util.BitVector ] - Get bit #3
17:02:50.401 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - returned connection for endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502]
17:02:50.401 [DEBUG] [.wimpi.modbus.net.TCPMasterConnection] - connect()
17:02:50.434 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Connection was returned to the pool, ending operation [operation ID 514b24f6-dd89-4482-8afb-b5d0db37ee71]
17:02:50.461 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502] connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48650]] -> true
17:02:50.504 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - borrowing connection (got Optional[TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48650]]]) for endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502] took 893 ms
17:02:50.540 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Executing task PollTaskImpl@4c3d0299[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@466a0020[slaveId=2,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=14,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502],callback=java.lang.ref.WeakReference@2adddfcb] (oneOff=false)! Connection received in 929 ms [operation ID 2d24b42d-dc4a-47c9-b7b9-ba55dc7491f0]
17:02:50.592 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 [operation ID 2d24b42d-dc4a-47c9-b7b9-ba55dc7491f0]
17:02:50.608 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 02 03 00 00 00 0e [operation ID 2d24b42d-dc4a-47c9-b7b9-ba55dc7491f0]
17:02:50.635 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 38068: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@7439d04c
17:02:50.667 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 38068
17:02:50.679 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=38068): 94 b4 00 00 00 1f 02 03 1c 00 ed 00 00 00 cb 01 19 00 de 00 00 00 db 00 00 00 d4 00 00 00 e4 00 00 00 f3 01 16 [operation ID 2d24b42d-dc4a-47c9-b7b9-ba55dc7491f0]
17:02:50.709 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 2 out of 3 [operation ID 2d24b42d-dc4a-47c9-b7b9-ba55dc7491f0]
17:02:50.724 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping [operation ID 2d24b42d-dc4a-47c9-b7b9-ba55dc7491f0]
17:02:50.744 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Sleep ended [operation ID 2d24b42d-dc4a-47c9-b7b9-ba55dc7491f0]
17:02:50.868 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 02 03 00 00 00 0e [operation ID 2d24b42d-dc4a-47c9-b7b9-ba55dc7491f0]
17:02:50.892 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 38069: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@2b1267b6
17:02:50.966 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 38069
17:02:50.978 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=38069): 94 b5 00 00 00 1f 02 03 1c 00 ed 00 00 00 cb 01 19 00 de 00 00 00 db 00 00 00 d4 00 00 00 e4 00 00 00 f3 01 16 [operation ID 2d24b42d-dc4a-47c9-b7b9-ba55dc7491f0]
17:02:51.015 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 3 out of 3 [operation ID 2d24b42d-dc4a-47c9-b7b9-ba55dc7491f0]
17:02:51.046 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping [operation ID 2d24b42d-dc4a-47c9-b7b9-ba55dc7491f0]
17:02:51.083 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Sleep ended [operation ID 2d24b42d-dc4a-47c9-b7b9-ba55dc7491f0]
17:02:51.097 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 02 03 00 00 00 0e [operation ID 2d24b42d-dc4a-47c9-b7b9-ba55dc7491f0]
17:02:51.123 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 38070: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@4cd01679
17:02:51.201 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 38070
17:02:51.214 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=38070): 94 b6 00 00 00 1f 02 03 1c 00 ed 00 00 00 cb 01 19 00 de 00 00 00 db 00 00 00 d4 00 00 00 e4 00 00 00 f3 01 16 [operation ID 2d24b42d-dc4a-47c9-b7b9-ba55dc7491f0]
17:02:51.254 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502] connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48650]] -> true
17:02:51.289 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - Passivating connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48650]] for endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502]...
17:02:51.349 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - (passivate) Connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48650]] (endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502]) age 888ms is over the reconnectAfterMillis=0ms limit or has been connection time (1510326170461) is after the "disconnectBeforeConnectedMillis"=1510326144369 -> disconnecting.
17:02:51.463 [TRACE] [ling.ModbusSlaveConnectionFactoryImpl] - ...Passivated connection TCPMasterConnection@2b4765df[socket=Socket[addr=/192.168.1.100,port=502,localport=48650]] for endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502]
17:02:51.494 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - returned connection for endpoint ModbusTCPSlaveEndpoint@61b5c2f3[address=192.168.1.100,port=502]
17:02:51.513 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Connection was returned to the pool, ending operation [operation ID 2d24b42d-dc4a-47c9-b7b9-ba55dc7491f0]
Bridge modbus:tcp:endpointTCP [ host="192.168.1.100", port=502, id=2, connectMaxTries=3, timeBetweenTransactionsMillis=100 ] {
Bridge poller greenlineCoil [ start=3, length=4, refresh=5000, type="coil" ] {
Thing data d04 [ readStart="3", writeStart="3", readValueType="bit", writeType="coil" ]
Thing data d05 [ readStart="4", writeStart="4", readValueType="bit", writeType="coil" ]
Thing data d06 [ readStart="5", writeStart="5", readValueType="bit", writeType="coil" ]
Thing data d07 [ readStart="6", writeStart="6", readValueType="bit", writeType="coil" ]
}
Bridge poller holding [ start=0, length=14, refresh=5000, type="holding" ] {
Thing data mh4 [ readStart="0", readValueType="uint16", readTransform="JS(divide.js)" ]
Thing data ph [ readStart="2", readValueType="uint16", readTransform="JS(divide.js)" ]
Thing data phrh [ readStart="3", readValueType="uint16", readTransform="JS(divide.js)" ]
Thing data mh1 [ readStart="4", readValueType="uint16", readTransform="JS(divide.js)" ]
Thing data mh2 [ readStart="6", readValueType="uint16", readTransform="JS(divide.js)" ]
Thing data mh3 [ readStart="8", readValueType="uint16", readTransform="JS(divide.js)" ]
Thing data oh [ readStart="10", readValueType="uint16", readTransform="JS(divide.js)" ]
Thing data tekn [ readStart="12", readValueType="uint16", readTransform="JS(divide.js)" ]
Thing data teknrh [ readStart="13", readValueType="uint16", readTransform="JS(divide.js)" ]
Thanks for the logs and configs. Will look into those
Adding these data things as switch items and adding them to sitemap doesn’t seem to work. Whole sitemap stops working.
What kind of items and sitemap you have configured? It should work 
@gitMiguel are you sure you have the latest version? It seems you might be using a slightly old version which retries transactions even if they succeed
16:45:09.529 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.548 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 02 03 00 00 00 0e [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.573 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 37231: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@2f972d1e
16:45:09.638 [INFO ] [smarthome.event.ItemStateChangedEvent] - TempOutside changed from 3 to 2
16:45:09.645 [TRACE] [.wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 37231
16:45:09.642 [INFO ] [smarthome.event.ItemStateChangedEvent] - OutEfficiency changed from 75 to 71
16:45:09.660 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=37231): 91 6f 00 00 00 1f 02 03 1c 00 ed 00 00 00 cd 01 19 00 de 00 00 00 dc 00 00 00 d4 00 00 00 e4 00 00 00 f3 01 17 [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.673 [INFO ] [smarthome.event.ItemStateChangedEvent] - AverageEfficiency changed from 80 to 78
16:45:09.725 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Try 2 out of 3 [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.749 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.779 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Sleep ended [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
16:45:09.796 [TRACE] [ort.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 02 03 00 00 00 0e [operation ID 2a766a8d-d63b-4b93-b4f6-4675ee781051]
This bug fixed some time ago, see this comment
Please check that you are using the latest version.
Actually, I cannot reproduce the issue with my S71200 PLC. Could you please ensure you have latest version and try again?
I’ll do those checks in the evening. Can you provide the latest version number so I can verify?
PS Just to learn something new, does the version number come from build date and time? For example 5.11.2017 15:32:09 --> 05112017153209?
Latest one available from Marketplace is from Nov 9, see the download
Index of libs-pullrequest-local/org/openhab/io/org.openhab.io.transport.modbus/2.2.0-SNAPSHOT
Name Last modified Size
../
org.openhab.io.transport.modbus-2.2.0-SNAPSHOT.jar 09-Nov-2017 09:52 350.88 KB
The marketplace should always serve the latest.
I think you are correct with your interpretation of the version number…
Sami
Hi,
I’m on my mobile phone so info is quite limited.
Binding itself was up to date but transport bundle I’m not sure. Now both are updated and error is still there. But not as often as earlier. Aprox every 10th poll. Was able to get this from logs:
20:06:04.070 [ERROR] [ling.ModbusSlaveConnectionFactoryImpl] - connect try 1/3 error: Yhteys torjuttu (Connection refused). Connection TCPMasterConnection@7a97badc[socket=Socket[unconnected]]. Endpoint ModbusTCPSlaveEndpoint@356d41c5[address=192.168.1.100,port=502]
I’m starting to believe that this has something to do with my network setup or the PLC. Because you tested it with no errors and nobody else is reporting any errors. (Hopefully they are reading their logs almost daily as I am 
)
Edit
Just to be sure I updated the whole server and there was and new OH snapshot version. During upgrade it uninstalls market binding so had to reinstall them from PaperUI. Everything is up to date.
Thanks! I will also double check and let it run for few minutes… Let’s see
Btw the logs you pasted show showed that the 100ms was not respected in all cases (due to repeating the request even though it succeeded) which lead slave to refuse the connection (plc cannot handle many connections so fast?). This should not happen or it is a bug.
If you can share the verbose logs I can check if the connection refused correlates with too fast queries this time.
Fyi
I might have found some issues with how the regular polls are setup: when I touch things file, the things are reset as expected. However sometimes only coils are polled, and not holding, or vice versa. It seems to be connected to many connectTries. I don’t really understand yet what happens, have to dig in deeper. Are you seeing any issues like this?
Best
Btw the logs you pasted show showed that the 100ms was not respected in all cases (due to repeating the request even though it succeeded) which lead slave to refuse the connection (plc cannot handle many connections so fast?). This should not happen or it is a bug.
In the beginning when I started testing this I had several errors regarding connection refused. Played around with different looser timings and got those sorted. After that I was quite sure the plc gets “slow” when reconnecting too fast.
If you can share the verbose logs I can check if the connection refused correlates with too fast queries this time.
Hopefully on tuesday I’m back at my desktop so you can get those logs.
I might have found some issues with how the regular polls are setup: when I touch things file, the things are reset as expected. However sometimes only coils are polled, and not holding, or vice versa. It seems to be connected to many connectTries. I don’t really understand yet what happens, have to dig in deeper. Are you seeing any issues like this?
Hmm… Cant remember anything precise but noticed some weird behaviour when i had to modify .things file over and over again when I was testing that inidvidual bits reading.
I have a rule that sets an output on a modbus device, i’m getting this warning in Karif do you have any idea what this is?
10:57:12.357 [WARN ] [internal.profiles.ProfileCallbackImpl] - Cannot delegate command 'OFF' for item 'Smarthouse_Motorventil' to handler for channel 'modbus:data:endpointSmarthouse:Smarthouse_Motorventil:Smarthouse_Motorventil:switch', because no handler is assigned. Maybe the binding is not installed or not propertly initialized.I might have found some issues with how the regular polls are setup: when I touch things file, the things are reset as expected. However sometimes only coils are polled, and not holding, or vice versa. It seems to be connected to many connectTries. I don’t really understand yet what happens, have to dig in deeper. Are you seeing any issues like this?
Found the root cause and fixed in latest version (now brewing up). The bug was only affecting cases where connection is not established successfully. Also updated the connection pooling library, had some bug fixes that might help as well.
Best,
Sami
EDIT: just pushed new version. Now the poller status reflects read errors as well.
Not sure really, how is the thing status? Perhaps something has went wrong migrating thing configuration from one version to another… If you can clean up things and re-init them from things file it might help.
EDIT: just to clarify, that WARN log message comes from openHAB, not from the binding. So that’s why suspected something with migration…
The Thing status is “Online”
I do have other issues after Upgrading to Snapshot Build #1073 (Now on #1077)- I’ll do some more digging on this issue.