Number of registers, coils or discrete inputs to read.
So if you want to read single 32 bit number (e.g. float32), you need to read two registers (length=2). For 16 bit number (e.g. Uint16) single register (length=1) is enough.
another interesting thing: installed EXEC Binding and now cannot connect to ModBus:
2018-01-10 20:27:54.213 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@c6648e8[slaveId=2,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=5,maxTries=3]). Will try again soon. Error was: net.wimpi.modbus.ModbusSlaveException Error Code = 6 [operation ID 5d8e25e8-f361-4c7e-8c53-03983e819cea]
p.s. it was working for a week or so no without a problem.
Does the error code=6 is general modbus tcp ‘thing’ or something special with this binding?
thanks
That is part of modbus protocol, not specific to this binding. Error 6 comes from the slave device. You can find explanations here
Specialized use in conjunction with programming commands.
The slave is engaged in processing a long-duration program command. The master should retransmit the message later when the slave is free…
I have modbus-binding up and running. But I have no glue how I can transform a integer to boolean using transform.js. I read the value 32769 witch means door closed or 32768 witch means door open. Is there a way to transform this using transform.js? thanks for any hint what I had to search for …
@ssalonen, could you please advice what might impact ‘strange’ behavior of the binding?
When I try to change item status (i.e. lower vent unit power) I’m switching the status, meaning writing to a registry different value.
The strange thing is that I see my item is switching back and forth few times:
2018-01-11 14:35:53.475 [ome.event.ItemCommandEvent] - Item ‘komfoCurrentModeWrite’ received command 1
2018-01-11 14:35:53.481 [vent.ItemStateChangedEvent] - komfoCurrentModeWrite changed from 2 to 1
2018-01-11 14:35:56.096 [vent.ItemStateChangedEvent] - komfoCurrentModeWrite changed from 1 to 2
2018-01-11 14:35:56.859 [vent.ItemStateChangedEvent] - komfoCurrentModeWrite changed from 2 to 1
2018-01-11 14:36:00.771 [vent.ItemStateChangedEvent] - komfoCurrentModeWrite changed from 1 to 2
2018-01-11 14:36:01.184 [vent.ItemStateChangedEvent] - komfoCurrentModeWrite changed from 2 to 1
meantime openhab.log shows:
2018-01-11 14:35:46.558 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:CurrentMode:komfoCurrentMode ‘Modbus data’, channel modbus:data:HVAC:CurrentMode:komfoCurrentMode:number will be updated to ‘2’ (type DecimalType). Numeric state ‘2’ and bool value 'true’
2018-01-11 14:35:46.560 [DEBUG] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:CurrentMode:komfoCurrentMode ‘Modbus data’, channel modbus:data:HVAC:CurrentMode:komfoCurrentMode:datetime will not be updated since transformation was unsuccesful
2018-01-11 14:35:46.572 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:CurrentMode:komfoCurrentMode ‘Modbus data’, channel modbus:data:HVAC:CurrentMode:komfoCurrentMode:string will be updated to ‘2’ (type StringType). Numeric state ‘2’ and bool value 'true’
2018-01-11 14:35:46.574 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:CurrentMode:komfoCurrentMode ‘Modbus data’, channel modbus:data:HVAC:CurrentMode:komfoCurrentMode:contact will be updated to ‘OPEN’ (type OpenClosedType). Numeric state ‘2’ and bool value 'true’
2018-01-11 14:35:46.580 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:CurrentMode:komfoCurrentMode ‘Modbus data’, channel modbus:data:HVAC:CurrentMode:komfoCurrentMode:rollershutter will be updated to ‘2’ (type PercentType). Numeric state ‘2’ and bool value ‘true’
Also, it looks like the openhab.log is not from the correct time (ends at 14:35:46, while the events are from 14:35:53) so there’s not much to go on…
This is just a wild guess (correct logs would help!) Please understand that openHAB automatically changes the state of the item when command is received by an item. You can disable this behaviour using autoupdate parameter, refer to openHAB docs: https://docs.openhab.org/configuration/items.html#exception-autoupdate
This could partly explain what’s going on:
Item ‘komfoCurrentModeWrite’ received command 1
komfoCurrentModeWrite changed from 2 to 1 // changed by openhab, since command was received
komfoCurrentModeWrite changed from 1 to 2 // polled value from modbus? (command did not yet have an impact)
komfoCurrentModeWrite changed from 2 to 1 // polled value from modbus updated to new value?
komfoCurrentModeWrite changed from 1 to 2 // ??
komfoCurrentModeWrite changed from 2 to 1 // ??
Looking at the correct logs tells exactly what is polled from the slave.
Best,
Sami
EDIT: also interested to hear more about the CPU usage. How much does it increase with the modbus binding? Do you have stats with 1.x binding?
@narf27 hmm I think you are right modpoll does not work with raspi and mbpoll only supports TCP slaves…
Not sure what to advice. We have seen slaves that do not answer to some specific requests, perhaps this is similar case. Can you read in two parts (two registers + two registers)?
Is there anything in device documentation regarding some limitations with respect to requests?
Edit : realized you previously used the old binding (successfully?) to read values. Please ensure that the serial port parameters are correct. I am curious if you find a case which worked before but anymore.
EDIT2: @narf27 here are two examples using python libraries pymodbus and minimalmodbus
These should work with python 2.7 or higher. The only trick is to install dependencies for these scripts (pymodbus or minimalmodbus). Hope you get the idea and adjust the scripts accordingly.
test_pymodbus.py:
# Installation
# - install dependencies:
# pip install pymodbus six
# or
# easy_install pymodbus six
# Running script:
# python test_pymodbus.py
from pymodbus.client.sync import ModbusSerialClient
# https://github.com/riptideio/pymodbus/blob/master/pymodbus/constants.py
port = '/dev/pts/3'
baudrate = 38400
stopbits = 1
bytesize = 8
parity = 'N' # 'E', 'O' or 'N'
address = 0
count = 5
unit = 1
slave = ModbusSerialClient(method='rtu',
port=port,
baudrate=baudrate,
stopbits=stopbits,
bytesize=bytesize,
parity=parity)
out = slave.read_holding_registers(address, count, unit=unit)
print('%s: %s' % (out, out.registers))
test_minimalmodbus.py:
# Installation
# - install dependencies:
# pip install minimalmodbus
# or
# easy_install minimalmodbus
# Running script:
# python test_minimalmodbus.py
import minimalmodbus
import serial
unit = 1
address = 24
count = 1
port = '/dev/pts/3'
baudrate = 38400
stopbits = 1
bytesize = 8
parity = serial.PARITY_NONE
slave = minimalmodbus.Instrument(port, unit)
slave.serial.port # this is the serial port name
slave.serial.baudrate = baudrate # Baud
slave.serial.bytesize = bytesize
slave.serial.parity = parity
slave.serial.stopbits = stopbits
print(slave.read_register(address, count))
Hi,
thanks for the hint as to how format the log correctly, apologies, I’ve not used much forum before.
Yesterday played a little bit with various options and must say cannot re-produce the same behavior again
What I did is: restarted openhab itself in the first place, then added autoupdate value next to the item, enabled TRACE option in karaf:
So I paste here the log output (matching the time-stamp, thanks @ssalonen! ) as what I can see (sorry if that’s a longer trail than expected):
events.log
2018-01-12 10:39:09.680 [ome.event.ItemCommandEvent] - Item 'komfoCurrentModeWrite' received command 2
2018-01-12 10:39:09.684 [vent.ItemStateChangedEvent] - komfoCurrentModeWrite changed from 1 to 2
2018-01-12 10:39:10.073 [vent.ItemStateChangedEvent] - komfoCurrentMode changed from 1 to 2
openhab.log
2018-01-12 10:39:09.680 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:CurrentModeWrite:komfoCurrentModeWrite 'Modbus data' received command '2' to channel 'modbus:data:HVA
C:CurrentModeWrite:komfoCurrentModeWrite:number'
2018-01-12 10:39:09.681 [TRACE] [odbus.handler.ModbusDataThingHandler] - Submitting write task: WriteTaskImpl@3f424d26[request=ModbusWriteRegisterRequestBlueprintImpl@5e8b40c5[slaveId=254,reference
=4,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(ModbusRegisterImpl(bytes=[0, 2],ushort=2)),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,port=50
2],callback=org.openhab.binding.modbus.handler.ModbusDataThingHandler@5c8857d6]
2018-01-12 10:39:09.684 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Scheduling one-off write task WriteTaskImpl@3f424d26[request=ModbusWriteRegisterRequestBlueprintImpl@5e8b40c5[slaveId=254,re
ference=4,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(ModbusRegisterImpl(bytes=[0, 2],ushort=2)),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,
port=502],callback=org.openhab.binding.modbus.handler.ModbusDataThingHandler@5c8857d6]
2018-01-12 10:39:09.685 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Will now execute one-off write task WriteTaskImpl@3f424d26[request=ModbusWriteRegisterRequestBlueprintImpl@5e8b40c5[slaveId=
254,reference=4,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(ModbusRegisterImpl(bytes=[0, 2],ushort=2)),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.
8.199,port=502],callback=org.openhab.binding.modbus.handler.ModbusDataThingHandler@5c8857d6], waited in thread pool for 2
2018-01-12 10:39:09.686 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Starting new operation with task WriteTaskImpl@3f424d26[request=ModbusWriteRegisterRequestBlueprintImpl@5e8b40c5[slaveId=254
,reference=4,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(ModbusRegisterImpl(bytes=[0, 2],ushort=2)),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.1
99,port=502],callback=org.openhab.binding.modbus.handler.ModbusDataThingHandler@5c8857d6]. Trying to get connection [operation ID a6c4cae0-c17a-48ef-8a32-76eea586cd30]
2018-01-12 10:39:09.686 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Executing task WriteTaskImpl@3f424d26[request=ModbusWriteRegisterRequestBlueprintImpl@5e8b40c5[slaveId=254,reference=4,funct
ionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(ModbusRegisterImpl(bytes=[0, 2],ushort=2)),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,port=502],callb
ack=org.openhab.binding.modbus.handler.ModbusDataThingHandler@5c8857d6] (oneOff=true)! Waiting for connection. Idle connections for this endpoint: 1, and active 0 [operation ID a6c4cae0-c17a-48ef-8
a32-76eea586cd30]
2018-01-12 10:39:09.689 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2018-01-12 10:39:09.690 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '1.5'
2018-01-12 10:39:09.690 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Waited 0ms (interTransactionDelayMillis 100ms) before giving returning connection TCPMasterConnection@438ee00b[socket=Socket
[addr=/192.168.8.199,port=502,localport=32794]] for endpoint ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,port=502], to ensure delay between transactions.
2018-01-12 10:39:09.691 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - borrowing connection (got Optional[TCPMasterConnection@438ee00b[socket=Socket[addr=/192.168.8.199,port=502,localport=32794]]
]) for endpoint ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,port=502] took 4 ms
2018-01-12 10:39:09.691 [DEBUG] [nding.modbus.internal.Transformation] - Could not transform item state '15' (of type DecimalType) to a State (tried the following types: [class org.eclipse.smarthom
e.core.library.types.DateTimeType, class org.eclipse.smarthome.core.types.UnDefType])! Input state as string '15', transformed string '1.5', transformation 'JS(divide10.js)'
2018-01-12 10:39:09.692 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Executing task WriteTaskImpl@3f424d26[request=ModbusWriteRegisterRequestBlueprintImpl@5e8b40c5[slaveId=254,reference=4,funct
ionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(ModbusRegisterImpl(bytes=[0, 2],ushort=2)),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,port=502],callb
ack=org.openhab.binding.modbus.handler.ModbusDataThingHandler@5c8857d6] (oneOff=true)! Connection received in 4 ms [operation ID a6c4cae0-c17a-48ef-8a32-76eea586cd30]
2018-01-12 10:39:09.692 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Operation with task WriteTaskImpl@3f424d26[request=ModbusWriteRegisterRequestBlueprintImpl@5e8b40c5[slaveId=254,reference=4,
functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(ModbusRegisterImpl(bytes=[0, 2],ushort=2)),maxTries=3],endpoint=ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,port=502],
callback=org.openhab.binding.modbus.handler.ModbusDataThingHandler@5c8857d6]. Got a connection successfully [operation ID a6c4cae0-c17a-48ef-8a32-76eea586cd30]
2018-01-12 10:39:09.693 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 [operation ID a6c4cae0-c17a-48ef-8a32-76eea586cd30]
2018-01-12 10:39:09.693 [DEBUG] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding3 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding3:dat
etime will not be updated since transformation was unsuccesful
2018-01-12 10:39:09.695 [DEBUG] [rt.modbus.internal.ModbusManagerImpl] - Executing scheduled (1000ms) poll task PollTaskImpl@786ba83e[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@74
8793f[slaveId=254,functionCode=READ_MULTIPLE_REGISTERS,start=4,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,port=502],callback=org.openhab.binding.modbus.hand
ler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@2fc27b3a]. Current millis: 1515746349695
2018-01-12 10:39:09.693 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping if necessary [operation ID a6c4cae0-c17a-48ef-8a32-76eea586
cd30]
2018-01-12 10:39:09.696 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Starting new operation with task PollTaskImpl@786ba83e[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@748793f[
slaveId=254,functionCode=READ_MULTIPLE_REGISTERS,start=4,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,port=502],callback=org.openhab.binding.modbus.handler.Mo
dbusPollerThingHandlerImpl$ReadCallbackDelegator@2fc27b3a]. Trying to get connection [operation ID abc175ae-335f-48b1-a1ff-6f401cb4ec80]
2018-01-12 10:39:09.696 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Sleep ended, slept a6c4cae0-c17a-48ef-8a32-76eea586cd30 [operation ID 0]
2018-01-12 10:39:09.696 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Executing task PollTaskImpl@786ba83e[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@748793f[slaveId=254,functionCode=READ_MULTIPLE_REGISTERS,start=4,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThingHan
dlerImpl$ReadCallbackDelegator@2fc27b3a] (oneOff=false)! Waiting for connection. Idle connections for this endpoint: 0, and active 1 [operation ID abc175ae-335f-48b1-a1ff-6f401cb4ec80]
2018-01-12 10:39:09.698 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Going execute transaction with read request (FC=WRITE_SINGLE_REGISTER): 00 00 00 00 00 06 fe 06 00 04 00 02 [operation ID a
6c4cae0-c17a-48ef-8a32-76eea586cd30]
2018-01-12 10:39:09.701 [TRACE] [wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 4767: net.wimpi.modbus.msg.WriteSingleRegisterRequest@440f5e09
2018-01-12 10:39:09.707 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '1.5'
2018-01-12 10:39:09.709 [DEBUG] [nding.modbus.internal.Transformation] - Transformed item state '15' (of type DecimalType) to a state 1.5 (of type StringType). Input state as string '15', transform
ed string '1.5', transformation 'JS(divide10.js)'
2018-01-12 10:39:09.711 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding3 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding3:str
ing will be updated to '1.5' (type StringType). Numeric state '15' and bool value 'true'
2018-01-12 10:39:09.722 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '22.0'
2018-01-12 10:39:09.732 [DEBUG] [nding.modbus.internal.Transformation] - Could not transform item state '220' (of type DecimalType) to a State (tried the following types: [class org.eclipse.smartho
me.core.library.types.OpenClosedType, class org.eclipse.smarthome.core.types.UnDefType])! Input state as string '220', transformed string '22.0', transformation 'JS(divide10.js)'
2018-01-12 10:39:09.733 [DEBUG] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:modeSettings:komfoModeIntensiveTempSetpoint 'Modbus data', channel modbus:data:HVAC:modeSettings:komf
oModeIntensiveTempSetpoint:contact will not be updated since transformation was unsuccesful
2018-01-12 10:39:09.745 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '22.0'
2018-01-12 10:39:09.746 [DEBUG] [nding.modbus.internal.Transformation] - Transformed item state '220' (of type DecimalType) to a state 22.0 (of type PercentType). Input state as string '220', trans
formed string '22.0', transformation 'JS(divide10.js)'
2018-01-12 10:39:09.747 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:modeSettings:komfoModeIntensiveTempSetpoint 'Modbus data', channel modbus:data:HVAC:modeSettings:komf
oModeIntensiveTempSetpoint:rollershutter will be updated to '22.0' (type PercentType). Numeric state '220' and bool value 'true'
2018-01-12 10:39:09.759 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '22.0'
2018-01-12 10:39:09.759 [DEBUG] [nding.modbus.internal.Transformation] - Transformed item state '220' (of type DecimalType) to a state 22.0 (of type PercentType). Input state as string '220', trans
formed string '22.0', transformation 'JS(divide10.js)'
2018-01-12 10:39:09.905 [TRACE] [wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 4767
2018-01-12 10:39:09.908 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Response for write request (FC=6, transaction ID=4767): 12 9f 00 00 00 06 fe 06 00 04 00 02 [operation ID a6c4cae0-c17a-48e
f-8a32-76eea586cd30]
2018-01-12 10:39:09.909 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Validating endpoint ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,port=502] connection TCPMasterConnection@438ee00b[
socket=Socket[addr=/192.168.8.199,port=502,localport=32794]] -> true
2018-01-12 10:39:09.912 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Passivating connection TCPMasterConnection@438ee00b[socket=Socket[addr=/192.168.8.199,port=502,localport=32794]] for endpoin
t ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,port=502]...
2018-01-12 10:39:09.760 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:modeSettings:komfoModeIntensiveTempSetpoint 'Modbus data', channel modbus:data:HVAC:modeSettings:komf
oModeIntensiveTempSetpoint:dimmer will be updated to '22.0' (type PercentType). Numeric state '220' and bool value 'true'
2018-01-12 10:39:09.910 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Calling write response callback org.openhab.binding.modbus.handler.ModbusDataThingHandler@5c8857d6 for request ModbusWriteRe
gisterRequestBlueprintImpl@5e8b40c5[slaveId=254,reference=4,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(ModbusRegisterImpl(bytes=[0, 2],ushort=2)),maxTries=3]. Response was
ModbusResponseImpl(responseFC=6)
2018-01-12 10:39:09.916 [DEBUG] [odbus.handler.ModbusDataThingHandler] - Successful write, matching request ModbusWriteRegisterRequestBlueprintImpl@5e8b40c5[slaveId=254,reference=4,functionCode=WRI
TE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(ModbusRegisterImpl(bytes=[0, 2],ushort=2)),maxTries=3]
2018-01-12 10:39:09.917 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Called write response callback org.openhab.binding.modbus.handler.ModbusDataThingHandler@5c8857d6 for request ModbusWriteReg
isterRequestBlueprintImpl@5e8b40c5[slaveId=254,reference=4,functionCode=WRITE_SINGLE_REGISTER,registers=ModbusRegisterArrayImpl(ModbusRegisterImpl(bytes=[0, 2],ushort=2)),maxTries=3]. Response was
ModbusResponseImpl(responseFC=6)
2018-01-12 10:39:09.918 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - (passivate) Connection TCPMasterConnection@438ee00b[socket=Socket[addr=/192.168.8.199,port=502,localport=32794]] (endpoint M
odbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,port=502]) age 227ms is over the reconnectAfterMillis=0ms limit or has been connection time (1515746349690) is after the "disconnectBeforeConnec
tedMillis"=1515746092229 -> disconnecting.
2018-01-12 10:39:09.909 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '1.5'
2018-01-12 10:39:09.922 [DEBUG] [nding.modbus.internal.Transformation] - Could not transform item state '15' (of type DecimalType) to a State (tried the following types: [class org.eclipse.smarthom
e.core.library.types.OpenClosedType, class org.eclipse.smarthome.core.types.UnDefType])! Input state as string '15', transformed string '1.5', transformation 'JS(divide10.js)'
2018-01-12 10:39:09.922 [DEBUG] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding3 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding3:con
tact will not be updated since transformation was unsuccesful
2018-01-12 10:39:09.922 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - ...Passivated connection TCPMasterConnection@438ee00b[socket=Socket[addr=/192.168.8.199,port=502,localport=32794]] for endpo
int ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,port=502]
2018-01-12 10:39:09.925 [DEBUG] [wimpi.modbus.net.TCPMasterConnection] - connect()
2018-01-12 10:39:09.926 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - returned connection to pool for endpoint ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,port=502]
2018-01-12 10:39:09.930 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Connection was returned to the pool, ending operation [operation ID a6c4cae0-c17a-48ef-8a32-76eea586cd30]
2018-01-12 10:39:09.937 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '1.5'
2018-01-12 10:39:09.938 [DEBUG] [nding.modbus.internal.Transformation] - Transformed item state '15' (of type DecimalType) to a state 1.5 (of type PercentType). Input state as string '15', transfor
med string '1.5', transformation 'JS(divide10.js)'
2018-01-12 10:39:09.938 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding3 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding3:rol
lershutter will be updated to '1.5' (type PercentType). Numeric state '15' and bool value 'true'
2018-01-12 10:39:09.964 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '1.5'
2018-01-12 10:39:09.964 [DEBUG] [nding.modbus.internal.Transformation] - Transformed item state '15' (of type DecimalType) to a state 1.5 (of type PercentType). Input state as string '15', transfor
med string '1.5', transformation 'JS(divide10.js)'
2018-01-12 10:39:09.965 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding3 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding3:dim
mer will be updated to '1.5' (type PercentType). Numeric state '15' and bool value 'true'
2018-01-12 10:39:09.970 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '22.0'
2018-01-12 10:39:09.985 [DEBUG] [nding.modbus.internal.Transformation] - Could not transform item state '220' (of type DecimalType) to a State (tried the following types: [class org.eclipse.smartho
me.core.library.types.OnOffType, class org.eclipse.smarthome.core.types.UnDefType])! Input state as string '220', transformed string '22.0', transformation 'JS(divide10.js)'
2018-01-12 10:39:09.986 [DEBUG] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:modeSettings:komfoModeIntensiveTempSetpoint 'Modbus data', channel modbus:data:HVAC:modeSettings:komf
oModeIntensiveTempSetpoint:switch will not be updated since transformation was unsuccesful
2018-01-12 10:39:09.988 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '1.5'
2018-01-12 10:39:09.992 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '0'
2018-01-12 10:39:09.998 [DEBUG] [nding.modbus.internal.Transformation] - Transformed item state '0' (of type DecimalType) to a state 0 (of type DecimalType). Input state as string '0', transformed
string '0', transformation 'default'
2018-01-12 10:39:10.000 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:modeSettings:komfoModeIntensiveHeating 'Modbus data', channel modbus:data:HVAC:modeSettings:komfoMode
IntensiveHeating:number will be updated to '0' (type DecimalType). Numeric state '0' and bool value 'false'
2018-01-12 10:39:10.001 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '0'
2018-01-12 10:39:10.002 [DEBUG] [nding.modbus.internal.Transformation] - Could not transform item state '15' (of type DecimalType) to a State (tried the following types: [class org.eclipse.smarthom
e.core.library.types.OnOffType, class org.eclipse.smarthome.core.types.UnDefType])! Input state as string '15', transformed string '1.5', transformation 'JS(divide10.js)'
2018-01-12 10:39:10.005 [DEBUG] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding3 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding3:swi
tch will not be updated since transformation was unsuccesful
2018-01-12 10:39:10.006 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '20'
2018-01-12 10:39:10.007 [DEBUG] [nding.modbus.internal.Transformation] - Transformed item state '20' (of type DecimalType) to a state 20 (of type DecimalType). Input state as string '20', transform
ed string '20', transformation 'default'
2018-01-12 10:39:10.007 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding4 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding4:num
ber will be updated to '20' (type DecimalType). Numeric state '20' and bool value 'true'
2018-01-12 10:39:10.011 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding4 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding4:str
ing will be updated to '20' (type StringType). Numeric state '20' and bool value 'true'
2018-01-12 10:39:10.017 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding4 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding4:contact will be updated to 'OPEN' (type OpenClosedType). Numeric state '20' and bool value 'true'
2018-01-12 10:39:10.018 [TRACE] [ing.ModbusSlaveConnectionFactoryImpl] - Waited 91ms (interTransactionDelayMillis 100ms) before giving returning connection TCPMasterConnection@438ee00b[socket=Socke
t[addr=/192.168.8.199,port=502,localport=32800]] for endpoint ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,port=502], to ensure delay between transactions.
2018-01-12 10:39:10.018 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '20'
2018-01-12 10:39:10.018 [DEBUG] [nding.modbus.internal.Transformation] - Transformed item state '20' (of type DecimalType) to a state 20 (of type PercentType). Input state as string '20', transform
ed string '20', transformation 'default'
2018-01-12 10:39:10.018 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - borrowing connection (got Optional[TCPMasterConnection@438ee00b[socket=Socket[addr=/192.168.8.199,port=502,localport=32800]]
]) for endpoint ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,port=502] took 321 ms
2018-01-12 10:39:10.019 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding4 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding4:rol
lershutter will be updated to '20' (type PercentType). Numeric state '20' and bool value 'true'
2018-01-12 10:39:10.019 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding4 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding4:dim
mer will be updated to 'ON' (type OnOffType). Numeric state '20' and bool value 'true'
2018-01-12 10:39:10.020 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Operation with task PollTaskImpl@786ba83e[request=ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@748793f[slaveId=254,f
unctionCode=READ_MULTIPLE_REGISTERS,start=4,length=1,maxTries=3],endpoint=ModbusTCPSlaveEndpoint@6ef8c4f2[address=192.168.8.199,port=502],callback=org.openhab.binding.modbus.handler.ModbusPollerThi
ngHandlerImpl$ReadCallbackDelegator@2fc27b3a]. Got a connection successfully [operation ID abc175ae-335f-48b1-a1ff-6f401cb4ec80]
2018-01-12 10:39:10.020 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 [operation ID abc175ae-335f-48b1-a1ff-6f401cb4ec80]
2018-01-12 10:39:10.022 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Ensuring that enough time passes before retrying again. Sleeping if necessary [operation ID abc175ae-335f-48b1-a1ff-6f401cb4
ec80]
2018-01-12 10:39:10.023 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Sleep ended, slept abc175ae-335f-48b1-a1ff-6f401cb4ec80 [operation ID 0]
2018-01-12 10:39:10.024 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Going execute transaction with request request (FC=READ_MULTIPLE_REGISTERS): 00 00 00 00 00 06 fe 03 00 04 00 01 [operation
ID abc175ae-335f-48b1-a1ff-6f401cb4ec80]
2018-01-12 10:39:10.024 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '20'
2018-01-12 10:39:10.025 [TRACE] [wimpi.modbus.io.ModbusTCPTransaction] - Sending request with transaction ID 4768: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@25a225a4
2018-01-12 10:39:10.025 [DEBUG] [nding.modbus.internal.Transformation] - Transformed item state '20' (of type DecimalType) to a state 20 (of type DecimalType). Input state as string '20', transform
ed string '20', transformation 'default'
2018-01-12 10:39:10.026 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding5 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding5:num
ber will be updated to '20' (type DecimalType). Numeric state '20' and bool value 'true'
2018-01-12 10:39:10.026 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '20'
2018-01-12 10:39:10.017 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:modeSettings:komfoModeIntensiveHeating 'Modbus data', channel modbus:data:HVAC:modeSettings:komfoMode
IntensiveHeating:string will be updated to '0' (type StringType). Numeric state '0' and bool value 'false'
2018-01-12 10:39:10.027 [DEBUG] [nding.modbus.internal.Transformation] - Could not transform item state '20' (of type DecimalType) to a State (tried the following types: [class org.eclipse.smarthom
e.core.library.types.DateTimeType, class org.eclipse.smarthome.core.types.UnDefType])! Input state as string '20', transformed string '20', transformation 'default'
2018-01-12 10:39:10.027 [DEBUG] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding5 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding5:dat
etime will not be updated since transformation was unsuccesful
2018-01-12 10:39:10.027 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '20'
2018-01-12 10:39:10.028 [DEBUG] [nding.modbus.internal.Transformation] - Transformed item state '20' (of type DecimalType) to a state 20 (of type StringType). Input state as string '20', transforme
d string '20', transformation 'default'
2018-01-12 10:39:10.028 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding5 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding5:str
ing will be updated to '20' (type StringType). Numeric state '20' and bool value 'true'
2018-01-12 10:39:10.028 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:modeSettings:komfoModeIntensiveHeating 'Modbus data', channel modbus:data:HVAC:modeSettings:komfoMode
IntensiveHeating:contact will be updated to 'CLOSED' (type OpenClosedType). Numeric state '0' and bool value 'false'
2018-01-12 10:39:10.029 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding5 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding5:con
tact will be updated to 'OPEN' (type OpenClosedType). Numeric state '20' and bool value 'true'
2018-01-12 10:39:10.037 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '0'
2018-01-12 10:39:10.037 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '20'
2018-01-12 10:39:10.038 [DEBUG] [nding.modbus.internal.Transformation] - Transformed item state '20' (of type DecimalType) to a state 20 (of type PercentType). Input state as string '20', transformed string '20', transformation 'default'
2018-01-12 10:39:10.038 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding5 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding5:rol
lershutter will be updated to '20' (type PercentType). Numeric state '20' and bool value 'true'
2018-01-12 10:39:10.038 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding5 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding5:dim
mer will be updated to 'ON' (type OnOffType). Numeric state '20' and bool value 'true'
2018-01-12 10:39:10.038 [DEBUG] [nding.modbus.internal.Transformation] - Transformed item state '0' (of type DecimalType) to a state 0 (of type PercentType). Input state as string '0', transformed
string '0', transformation 'default'
2018-01-12 10:39:10.039 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:holding5 'Modbus data', channel modbus:data:HVAC:DetailedInformation:holding5:swi
tch will be updated to 'ON' (type OnOffType). Numeric state '20' and bool value 'true'
2018-01-12 10:39:10.040 [TRACE] [wimpi.modbus.io.ModbusTCPTransaction] - Received response with transaction ID 4768
2018-01-12 10:39:10.042 [TRACE] [rt.modbus.internal.ModbusManagerImpl] - Response for read request (FC=3, transaction ID=4768): 12 a0 00 00 00 05 fe 03 02 00 02 [operation ID abc175ae-335f-48b1-a1
ff-6f401cb4ec80]
2018-01-12 10:39:10.043 [TRACE] [modbus.internal.ModbusLibraryWrapper] - Calling read response callback org.openhab.binding.modbus.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator@2fc27b3
a for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@748793f[slaveId=254,functionCode=READ_MULTIPLE_REGISTERS,start=4,length=1,maxTries=3]. Response was net.wimpi.modbus.msg.ReadMulti
pleRegistersResponse@41689b8f
2018-01-12 10:39:10.046 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '2'
2018-01-12 10:39:10.047 [DEBUG] [nding.modbus.internal.Transformation] - Could not transform item state '2' (of type DecimalType) to a State (tried the following types: [class org.eclipse.smarthome
.core.library.types.DateTimeType, class org.eclipse.smarthome.core.types.UnDefType])! Input state as string '2', transformed string '2', transformation 'default'
2018-01-12 10:39:10.067 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:CurrentMode:komfoCurrentMode 'Modbus data', channel modbus:data:HVAC:CurrentMode:komfoCurrentMode:swi
tch will be updated to 'ON' (type OnOffType). Numeric state '2' and bool value 'true'
2018-01-12 10:39:10.067 [DEBUG] [nding.modbus.internal.Transformation] - transformed response is '20.3'
2018-01-12 10:39:10.068 [DEBUG] [nding.modbus.internal.Transformation] - Transformed item state '203' (of type DecimalType) to a state 20.3 (of type DecimalType). Input state as string '203', trans
formed string '20.3', transformation 'JS(divide10.js)'
2018-01-12 10:39:10.068 [TRACE] [odbus.handler.ModbusDataThingHandler] - Thing modbus:data:HVAC:DetailedInformation:komfoSupplyFanIntensivity 'Modbus data', channel modbus:data:HVAC:DetailedInforma
tion:komfoSupplyFanIntensivity:number will be updated to '20.3' (type DecimalType). Numeric state '203' and bool value 'true'
2018-01-12 10:39:10.073 [DEBUG] [nding.modbus.internal.Transformation] - Transformed item state '100' (of type DecimalType) to a state 100 (of type DecimalType). Input state as string '100', transf
ormed string '100', transformation 'default'
About CPU:
When I set all poller to refresh=1000 I usually see the load of
top - 14:55:54 up 2 day, 11:39, 3 users, load average: 6.79, 5.88, 3.93
Memory: ~1.7Gb...
Today I’ve changed poller to be various numbers, a mix, and can see less cpu/mem usage overall:
Seems like if I try to poll my slave very frequently - it becomes a “hard” task
The only remaining thing to work out left is - how to ensure stable connectivity, as I see time to time unsuccessful connections:
2018-01-12 11:39:25.794 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@748793f[slaveId=254,functionCode=READ_MULTIPLE_REGISTERS,start=4,length=1,maxTries=3]). Will try again soon. Error was: net.wimpi.modbus.ModbusSlaveException Error Code = 6 [operation ID b79dba2d-c16d-407d-81d3-8cbaea985657]
@ssalonen, yes, CPU looks ok now.
Since I put connectMaxTries=3 I only see the message once:
2018-01-12 14:35:13.710 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 3 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@313519cd[slaveId=254,functionCode=READ_MULTIPLE_REGISTERS,start=99,length=24,maxTries=3]). Will try again soon. Error was: net.wimpi.modbus.ModbusSlaveException Error Code = 6 [operation ID ab422011-157f-4673-b9a4-e980c703068a]
do not see 2/3 or 3/3 as an error/warn and the values seems being updated afterwards. So my only guess is that I’m lucky that trying to poll data at the same time when the unit is doing something etc, who knows.
and the error of 6 (advised by you earlier) shows that the slave is busy at that moment.
I have to read holding registers from a wide range of addresses. For that reason I had defined a couple of holding pollers. But only the first holding-poller is working. Dos I have to create for every holding-poller a new *.things-file?