Modus Binding crashes after several hours

MatziBrow · March 7, 2020, 6:50pm

Hi there!

I face an issue with the my modbus setup.
I am using USR-M511 module interface to my Fröling Heating that has a serial modbus interface. It converts it to a modbus TCP signal that I read out with my openhab server.
I am using openhab version 2.5.2. Release Build, running on an Intel NUC with Ubuntu 18.04.4 LTS.
The whole setup principally works fine with the configuration below, all values are correct and make sense. Unfortunately it crashes after 5-20 hours. After the crash I have to restart the openhab binding and the USR-M511. Resetting only one of them does not work.
I read through similar posts, tried several configurations (e.g. the ones that I commented out in the config below), but it did not help. Same result, the uptime differed a little. The config below had the longest uptime.

Below you can find the code, the log and the USR-M511 configuration.

My code:

Bridge modbus:tcp:Heizungsanlage [ host="192.168.179.132", 
                                   port=502, id=1, 
                                   connectMaxTries=10 
                                   //reconnectAfterMillis=60000
                                   //timeBetweenReconnectMillis=1000,
                                   //timeBetweenTransactionsMillis=200 
                                 ] {
    
    Bridge poller AnlagenWerte [ start=0, length=88, refresh=10000, maxTries=5, type="input" ] {
        Thing data cKesselTemperatur                [ readStart="0", readTransform="JS(TeileDurch2.js)", readValueType="int16" ]
        Thing data cAbgasTemperatur                 [ readStart="1", readValueType="int16" ]
        Thing data cRestsauerstoffgehalt            [ readStart="3", readTransform="JS(TeileDurch10.js)", readValueType="int16" ]
        Thing data cBetriebsstunden                 [ readStart="20", readValueType="int16" ]
        Thing data cFuellstandPelletbehaelter       [ readStart="21", readTransform="JS(TeileDurch207.js)", readValueType="int16" ]
        Thing data cStundenSeitLetzterWartung       [ readStart="55", readValueType="int16" ]
        Thing data cPelletverbrauchKGZaehler        [ readStart="81", readValueType="int16" ]
        Thing data cPelletverbrauchTZaehler         [ readStart="82", readValueType="int16" ]
        Thing data cPelletVerbrauchGesamt           [ readStart="83", readValueType="int16" ]
        Thing data cTagesertrag                     [ readStart="84", readValueType="int16" ]
        Thing data cGesamtErtrag                    [ readStart="85", readValueType="int16" ]
        Thing data cHeizstundenBisAscheEntleerung   [ readStart="86", readValueType="int16" ]
    }

    Bridge poller AnlagenWerte2 [ start=1000, length=1, refresh=10000, maxTries=5, type="input" ] {
        Thing data cAussenTemperatur        [ readStart="1000", readTransform="JS(TeileDurch2.js)", readValueType="int16" ]
    }

    Bridge poller HeizkreisWerte [ start=1030, length=65, refresh=10000, maxTries=5, type="input" ] {
        Thing data cHeizkreisWandVorlaufIstTemperatur              [ readStart="1030", readTransform="JS(TeileDurch2.js)", readValueType="int16" ]
        Thing data cHeizkreisWandVorlaufSollTemperatur             [ readStart="1031", readTransform="JS(TeileDurch2.js)", readValueType="int16" ]
        Thing data cHeizkreisFussbodenVorlaufIstTemperatur         [ readStart="1060", readTransform="JS(TeileDurch2.js)", readValueType="int16" ]
        Thing data cHeizkreisFussbodenVorlaufSollTemperatur        [ readStart="1061", readTransform="JS(TeileDurch2.js)", readValueType="int16" ]
    }

    Bridge poller BoilerWerte [ start=1630, length=3, refresh=10000, maxTries=5, type="input" ] {
        Thing data cBoilerTemperatur                      [ readStart="1630", readTransform="JS(TeileDurch2.js)", readValueType="int16" ]
        Thing data cBoilerPumpenansteuerung               [ readStart="1632", readValueType="int16" ]
    }

    Bridge poller PufferWerte [ start=2000, length=8, refresh=10000, maxTries=5, type="input" ] {
        Thing data cPufferTemperaturOben      [ readStart="2000", readTransform="JS(TeileDurch2.js)", readValueType="int16" ]
        Thing data cPufferTemperaturMitte     [ readStart="2001", readTransform="JS(TeileDurch2.js)", readValueType="int16" ]
        Thing data cPufferTemperaturUnten     [ readStart="2002", readTransform="JS(TeileDurch2.js)", readValueType="int16" ]
        Thing data cPufferPumpenansteuerung   [ readStart="2003", readValueType="int16" ]
        Thing data cPufferLadezustand         [ readStart="2006", readValueType="int16" ]
    }

    Bridge poller AnlagenParameter [ start=0, length=1, refresh=10000, maxTries=5, type="holding" ] {
        Thing data cKesselSollTemperatur    [ readStart="0", readTransform="JS(TeileDurch2.js)", readValueType="int16" ]
    }

    Bridge poller AnlagenParameter2 [ start=319, length=1, refresh=10000, maxTries=5, type="holding" ] {
        Thing data cPelletRestbestand       [ readStart="319", readTransform="JS(TeileDurch10.js)", readValueType="int16" ]
    }

    Bridge poller KesselFernsteuerungParameter [ start=8000, length=50, refresh=10000, maxTries=5, type="holding" ] {
        Thing data cHeizkreisWandVorlaufSolltemperatur        [ readStart="8000", readTransform="JS(TeileDurch2.js)", readValueType="int16" ] // Min: 0, Max:75
        Thing data cHeizkreisFussbodenVorlaufSolltemperatur   [ readStart="8001", readTransform="JS(TeileDurch2.js)", readValueType="int16" ] // Min: 0, Max:75
        Thing data cBoilerSolltemperatur                      [ readStart="8018", readTransform="JS(TeileDurch2.js)", readValueType="int16" ] // Min: 10, Max:65
        Thing data cHeizkreisWandBetriebsmodus                [ readStart="8046", readValueType="int16" ]
        Thing data cHeizkreisFussbodenBetriebsmodus           [ readStart="8047", readValueType="int16" ] 
    }
    
    Bridge poller HeizkreisParameter [ start=1030, length=64, refresh=10000, maxTries=5, type="holding" ] {
        Thing data cWandVorlaufWunschPlus10GRad           [ readStart="1031", readTransform="JS(TeileDurch2.js)", readValueType="int16" ] // Min: 10, Max:110
        Thing data cWandVorlaufWunschMinus10GRad          [ readStart="1032", readTransform="JS(TeileDurch2.js)", readValueType="int16" ] // Min: 10, Max:110
        Thing data cWandVorlaufTemperaturAbsenkung        [ readStart="1033", readTransform="JS(TeileDurch2.js)", readValueType="int16" ] // Min:  0, Max: 70
        Thing data cFussbodenVorlaufWunschMinus10GRad     [ readStart="1062", readTransform="JS(TeileDurch2.js)", readValueType="int16" ] // Min: 10, Max:110
        Thing data cFussbodenVorlaufTemperaturAbsenkung   [ readStart="1063", readTransform="JS(TeileDurch2.js)", readValueType="int16" ] // Min:  0, Max: 70
    }

    Bridge poller BoilerParameter [ start=1631, length=3, refresh=10000, maxTries=5, type="holding" ] {
        Thing data cBoilerSollTemperatur                        [ readStart="1631", readTransform="JS(TeileDurch2.js)", readValueType="int16" ] // Min: 10, Max:110
        Thing data cBoilerNachladenStartTemperatur              [ readStart="1632", readTransform="JS(TeileDurch2.js)", readValueType="int16" ] // Min:  1, Max:90
    }

}

Here is the log file:

2020-03-07 17:16:41.001 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:BoilerWerte received registers RegisterArrayWrappingInputRegister(00 61 00 fe 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@4a7fd8e2[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1630,length=3,maxTries=5]
2020-03-07 17:16:41.006 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:BoilerWerte:cBoilerTemperatur channels updated: {modbus:data:Heizungsanlage:BoilerWerte:cBoilerTemperatur:number=48.5}. readValueType=int16, readIndex=Optional[1630], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 97 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 61 00 fe 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@4a7fd8e2[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1630,length=3,maxTries=5]
2020-03-07 17:16:41.007 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:BoilerWerte:cBoilerPumpenansteuerung channels updated: {modbus:data:Heizungsanlage:BoilerWerte:cBoilerPumpenansteuerung:number=0}. readValueType=int16, readIndex=Optional[1632], readSubIndex(or 0)=0, extractIndex=2 -> numeric value 0 and boolValue=false. Registers RegisterArrayWrappingInputRegister(00 61 00 fe 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@4a7fd8e2[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1630,length=3,maxTries=5]
2020-03-07 17:16:44.080 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@527c90cd (unit id 1 & transaction 2161). Address: /192.168.179.132:502
2020-03-07 17:16:44.081 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInputRegistersRequest@527c90cd (unit id 1 & transaction 2161). Address: /192.168.179.132:502
2020-03-07 17:16:44.083 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 5 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@674eafd3[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=2000,length=8,maxTries=5]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID 79deca8f-925e-402e-a72d-2e061d836317]
2020-03-07 17:16:47.157 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@7d89deec (unit id 1 & transaction 2162). Address: /192.168.179.132:502
2020-03-07 17:16:47.160 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadMultipleRegistersRequest@7d89deec (unit id 1 & transaction 2162). Address: /192.168.179.132:502
2020-03-07 17:16:47.161 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 5 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@113aded0[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=0,length=1,maxTries=5]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOException I/O exception: SocketTimeoutException Read timed out [operation ID c2bb0efd-30e4-4720-a629-289f3cecff1c]
2020-03-07 17:16:47.227 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:AnlagenParameter2 received registers RegisterArrayWrappingInputRegister(00 8c) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7dde8633[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=319,length=1,maxTries=5]
2020-03-07 17:16:47.232 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:AnlagenParameter2:cPelletRestbestand channels updated: {modbus:data:Heizungsanlage:AnlagenParameter2:cPelletRestbestand:number=14.0}. readValueType=int16, readIndex=Optional[319], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 140 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 8c) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7dde8633[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=319,length=1,maxTries=5]
2020-03-07 17:16:47.295 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:KesselFernsteuerungParameter received registers RegisterArrayWrappingInputRegister(00 1e) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@221110fe[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=8000,length=50,maxTries=5]
2020-03-07 17:16:47.296 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:KesselFernsteuerungParameter:cHeizkreisWandVorlaufSolltemperatur channels updated: {}. readValueType=int16, readIndex=Optional[8000], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 30 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 1e) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@221110fe[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=8000,length=50,maxTries=5]
2020-03-07 17:16:47.306 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
2020-03-07 17:16:47.364 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:HeizkreisParameter received registers RegisterArrayWrappingInputRegister(00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 01 00 00 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@f7d5fc9[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=1030,length=64,maxTries=5]
2020-03-07 17:16:47.366 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:HeizkreisParameter:cWandVorlaufWunschPlus10GRad channels updated: {}. readValueType=int16, readIndex=Optional[1031], readSubIndex(or 0)=0, extractIndex=1 -> numeric value 0 and boolValue=false. Registers RegisterArrayWrappingInputRegister(00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 01 00 00 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@f7d5fc9[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=1030,length=64,maxTries=5]

Here is the USR-M511 configuration:

Thanks a lot for your support!

Best regards,
Matthias

rossko57 · March 7, 2020, 7:14pm

That’s a recoverable error. What do you mean by “crash”?

MatziBrow · March 7, 2020, 7:22pm

2020-03-07 17:16:47.364 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:HeizkreisParameter received registers RegisterArrayWrappingInputRegister(00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 01 00 00 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@f7d5fc9[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=1030,length=64,maxTries=5]
2020-03-07 17:16:47.366 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:HeizkreisParameter:cWandVorlaufWunschPlus10GRad channels updated: {}. readValueType=int16, readIndex=Optional[1031], readSubIndex(or 0)=0, extractIndex=1 -> numeric value 0 and boolValue=false. Registers RegisterArrayWrappingInputRegister(00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 01 00 00 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@f7d5fc9[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=1030,length=64,maxTries=5]

You are right. It does not crash. However, the values are not correct anymore. After the error it does not seem to recover. The values received afterwards are e.g. only 0 like in the log above.
Basically they are stalled.

MatziBrow · March 7, 2020, 7:26pm

2020-03-07 17:16:57.243 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.ClassCastException: net.wimpi.modbus.msg.ReadInputRegistersResponse cannot be cast to net.wimpi.modbus.msg.ReadMultipleRegistersResponse
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:284) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]
2020-03-07 17:16:57.377 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:HeizkreisParameter received registers RegisterArrayWrappingInputRegister(00 1e) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@f7d5fc9[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=1030,length=64,maxTries=5]
2020-03-07 17:16:57.379 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.IllegalArgumentException: Index=1 with type=int16 is out-of-bounds given registers of size 1
        at org.openhab.io.transport.modbus.ModbusBitUtilities.extractStateFromRegisters(ModbusBitUtilities.java:108) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler.onRegisters(ModbusDataThingHandler.java:686) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.lambda$0(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891) ~[?:1.8.0_163]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.onRegisters(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:283) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]
2020-03-07 17:17:00.711 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.ClassCastException: net.wimpi.modbus.msg.ReadMultipleRegistersResponse cannot be cast to net.wimpi.modbus.msg.ReadInputRegistersResponse
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:287) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]
2020-03-07 17:17:01.037 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:BoilerWerte received registers RegisterArrayWrappingInputRegister(00 0a) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@4a7fd8e2[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1630,length=3,maxTries=5]
2020-03-07 17:17:01.042 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:BoilerWerte:cBoilerTemperatur channels updated: {modbus:data:Heizungsanlage:BoilerWerte:cBoilerTemperatur:number=5.0}. readValueType=int16, readIndex=Optional[1630], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 10 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 0a) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@4a7fd8e2[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1630,length=3,maxTries=5]
2020-03-07 17:17:01.044 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.IllegalArgumentException: Index=2 with type=int16 is out-of-bounds given registers of size 1
        at org.openhab.io.transport.modbus.ModbusBitUtilities.extractStateFromRegisters(ModbusBitUtilities.java:108) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler.onRegisters(ModbusDataThingHandler.java:686) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.lambda$0(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891) ~[?:1.8.0_163]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.onRegisters(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:286) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]

It also throws these logs and then it stops polling.

rossko57 · March 7, 2020, 8:30pm

I very much doubt the binding is creating false data.
It is possible your gateway is passing rubbish from the serial side, I don’t know how much validation it does of serial data.
It is possible your gateway is generating the rubbish, but it seems unlikely.
(I use the simpler USR-TCP232-410s okay, by the way)

You could give everything an easier workload by re-instating those TCP Bridge Thing parameters you commented out. You’re not going to fix it with random settings.

I’ll ask @ssalonen opinion on this, but I’d guess it means the response to a poll is not what was expected.

I’ll note the unusual thing about the USR-M511 is that it can independently poll the serial devices and keep a cache. When queried by a TCP master (openHAB), it can return a response from cache very quickly
You seem to have that feature turned off (“Modbus Command Store”), which is a good thing while you have problems.

MatziBrow · March 7, 2020, 10:44pm

I used those settings, but it got actually did not help. It got worse if I keep the connection all the time.

Why do you think it stops polling after the warnings above? This must be coming from the binding, right?
My guess is that the rubbish is just the first step before the binding actually stops working.

I am not so sure what to try next…

ssalonen · March 8, 2020, 1:44pm

This tell that we got unexpected response from slave. Slave was supposed to return holding registers but it returned input registers instead. Basically slave responded with a function code that does not match the request. Interesingly, transaction number (unique to each request-response pair) and CRC was correct, otherwise error would have been raised before.

This time slave responded with the correct function code but the number of registers do not match what was queried, violating basic contract of modbus.

Both of these errors are something that indicate weird problems with slave device and there is not much that can be done on the binding side. As far as I can tell, the errors arise from bad responses from slave.

The zero data you saw in the logs would mean that slave has actually responded with zeros. I cannot think any other option - the binding should not create any dummy data.

It’s quite odd that you have to restart the USR to fix the issues. Would that indicate that the USR goes in some sort of bad state?

Does the error messages change on openhab side when you restart the USR?

rossko57 · March 8, 2020, 2:36pm

My money’s on the gateway messing up. It clearly keeps a cache of Modbus responses - supposedly not using it here, but something’s going wrong.

I think the observation that changing the TCP handling params changes the effect is a clue as well; the device on the serial side won’t be affected by any of that.
Maybe closing/opening a TCP connection resets the gateway’s cache mechanism. Doing it less, it messes up quicker.

MatziBrow · March 9, 2020, 6:22pm

Hi!

Thanks a lot for your analysis!
This was really a good step forward even though the solution is not obvious

I made another log with the comment settings enabled. For whatever reason it lasted longer this time.
The error now looks a bit different. It seems to recover first, but then stops polling again.
Below you can find the log!

Further I resetted the USR-M511 afterwards, but this did not help on the binding side. It does not start polling again.

I was wondering why the binding stops polling?
Shouldn’t it be robust enough to survive it?

Best regards,
Matthias

2020-03-09 09:03:30.177 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:AnlagenWerte2 received registers RegisterArrayWrappingInputRegister(00 0f ff ff)
for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@3818a30f[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1000,length=2,maxTries=5]
2020-03-09 09:03:30.181 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:AnlagenWerte2:cAussenTemperatur channels updated: {modbus:data:Heizungsanlage:Anlag
enWerte2:cAussenTemperatur:number=7.5}. readValueType=int16, readIndex=Optional[1000], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 15 and boolValue=true. Registers RegisterArrayWr
appingInputRegister(00 0f ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@3818a30f[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1000,length=2,maxTries=5]
2020-03-09 09:03:33.425 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInput
RegistersRequest@78278b80 (unit id 1 & transaction 25084). Address: /192.168.179.132:502
2020-03-09 09:03:33.426 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net
.wimpi.modbus.msg.ReadInputRegistersRequest@78278b80 (unit id 1 & transaction 25084). Address: /192.168.179.132:502
2020-03-09 09:03:33.426 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 1 out of 5 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@56dda554[slaveId=
1,functionCode=READ_INPUT_REGISTERS,start=1030,length=65,maxTries=5]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOExceptio
n I/O exception: SocketTimeoutException Read timed out [operation ID 5b9d50db-dfd8-44a2-b9e3-70ab4cd2f594]
2020-03-09 09:03:36.637 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute try 1/1 error: I/O exception: SocketTimeoutException Read timed out. Request: net.wimpi.modbus.msg.ReadInput
RegistersRequest@4ac0d71c (unit id 1 & transaction 25085). Address: /192.168.179.132:502
2020-03-09 09:03:36.637 [ERROR] [wimpi.modbus.io.ModbusTCPTransaction] - execute reached max tries 1, throwing last error: I/O exception: SocketTimeoutException Read timed out. Request: net
.wimpi.modbus.msg.ReadInputRegistersRequest@4ac0d71c (unit id 1 & transaction 25085). Address: /192.168.179.132:502
2020-03-09 09:03:36.638 [WARN ] [rt.modbus.internal.ModbusManagerImpl] - Try 2 out of 5 failed when executing request (ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@56dda554[slaveId=
1,functionCode=READ_INPUT_REGISTERS,start=1030,length=65,maxTries=5]). Will try again soon. Error was I/O error, so reseting the connection. Error details: net.wimpi.modbus.ModbusIOExceptio
n I/O exception: SocketTimeoutException Read timed out [operation ID 5b9d50db-dfd8-44a2-b9e3-70ab4cd2f594]
2020-03-09 09:03:36.846 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:HeizkreisWerte received registers RegisterArrayWrappingInputRegister(00 45 00 5c
00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 48 00 3c 00 28 ff
ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 00 00 00 00 00 ff ff ff ff)
 for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@56dda554[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1030,length=65,maxTries=5]
2020-03-09 09:03:36.849 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:HeizkreisWerte:cHeizkreisWandVorlaufIstTemperatur channels updated: {modbus:data:He
izungsanlage:HeizkreisWerte:cHeizkreisWandVorlaufIstTemperatur:number=34.5}. readValueType=int16, readIndex=Optional[1030], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 69 and bool
Value=true. Registers RegisterArrayWrappingInputRegister(00 45 00 5c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 48 00 3c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
ff ff ff ff ff ff ff ff ff ff ff ff ff 00 00 00 00 00 00 ff ff ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@56dda554[slaveId=1,functionCode=READ_INPUT_REGISTERS,s
tart=1030,length=65,maxTries=5]
2020-03-09 09:03:36.852 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:HeizkreisWerte:cHeizkreisWandVorlaufSollTemperatur channels updated: {modbus:data:H
eizungsanlage:HeizkreisWerte:cHeizkreisWandVorlaufSollTemperatur:number=46.0}. readValueType=int16, readIndex=Optional[1031], readSubIndex(or 0)=0, extractIndex=1 -> numeric value 92 and bo
olValue=true. Registers RegisterArrayWrappingInputRegister(00 45 00 5c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff f
f ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 48 00 3c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff f
f ff ff ff ff ff ff ff ff ff ff ff ff ff 00 00 00 00 00 00 ff ff ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@56dda554[slaveId=1,functionCode=READ_INPUT_REGISTERS
,start=1030,length=65,maxTries=5]
2020-03-09 09:03:36.855 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:HeizkreisWerte:cHeizkreisFussbodenVorlaufIstTemperatur channels updated: {modbus:da
ta:Heizungsanlage:HeizkreisWerte:cHeizkreisFussbodenVorlaufIstTemperatur:number=36.0}. readValueType=int16, readIndex=Optional[1060], readSubIndex(or 0)=0, extractIndex=30 -> numeric value
72 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 45 00 5c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff f
f ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 48 00 3c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff f
f ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 00 00 00 00 00 ff ff ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@56dda554[slaveId=1,functionCode=READ_INPUT_
REGISTERS,start=1030,length=65,maxTries=5]
2020-03-09 09:03:36.858 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:HeizkreisWerte:cHeizkreisFussbodenVorlaufSollTemperatur channels updated: {modbus:d
ata:Heizungsanlage:HeizkreisWerte:cHeizkreisFussbodenVorlaufSollTemperatur:number=30.0}. readValueType=int16, readIndex=Optional[1061], readSubIndex(or 0)=0, extractIndex=31 -> numeric valu
e 60 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 45 00 5c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 48 00 3c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 00 00 00 00 00 ff ff ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@56dda554[slaveId=1,functionCode=READ_INPU
T_REGISTERS,start=1030,length=65,maxTries=5]
2020-03-09 09:03:37.922 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:AnlagenWerte received registers RegisterArrayWrappingInputRegister(00 45 00 5c 00
 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 48 00 3c 00 28 ff ff
 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 00 00 00 00 00 ff ff ff ff) f
or request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@36359493[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=88,maxTries=5]
2020-03-09 09:03:37.926 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:AnlagenWerte:cKesselTemperatur channels updated: {modbus:data:Heizungsanlage:Anlage
nWerte:cKesselTemperatur:number=34.5}. readValueType=int16, readIndex=Optional[0], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 69 and boolValue=true. Registers RegisterArrayWrappi
ngInputRegister(00 45 00 5c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
 ff ff 00 48 00 3c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00
 00 00 00 00 00 ff ff ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@36359493[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=88,maxTries=5]
2020-03-09 09:03:37.927 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:AnlagenWerte:cAbgasTemperatur channels updated: {modbus:data:Heizungsanlage:Anlagen
Werte:cAbgasTemperatur:number=92}. readValueType=int16, readIndex=Optional[1], readSubIndex(or 0)=0, extractIndex=1 -> numeric value 92 and boolValue=true. Registers RegisterArrayWrappingIn
putRegister(00 45 00 5c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
ff 00 48 00 3c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 00
00 00 00 00 ff ff ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@36359493[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=88,maxTries=5]
2020-03-09 09:03:37.933 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:AnlagenWerte:cRestsauerstoffgehalt channels updated: {modbus:data:Heizungsanlage:An
lagenWerte:cRestsauerstoffgehalt:number=-0.1}. readValueType=int16, readIndex=Optional[3], readSubIndex(or 0)=0, extractIndex=3 -> numeric value -1 and boolValue=true. Registers RegisterArr
ayWrappingInputRegister(00 45 00 5c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
ff ff ff ff ff 00 48 00 3c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff
ff ff 00 00 00 00 00 00 ff ff ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@36359493[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=88,maxTries=5]
2020-03-09 09:03:37.933 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:AnlagenWerte:cBetriebsstunden channels updated: {}. readValueType=int16, readIndex=
Optional[20], readSubIndex(or 0)=0, extractIndex=20 -> numeric value -1 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 45 00 5c 00 28 ff ff ff ff ff ff ff ff ff ff ff f
f ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 48 00 3c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff f
f ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 00 00 00 00 00 ff ff ff ff) for request ModbusPollerThingHandlerImp
l.ModbusPollerReadRequest@36359493[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=88,maxTries=5]
2020-03-09 09:03:37.938 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:AnlagenWerte:cFuellstandPelletbehaelter channels updated: {modbus:data:Heizungsanla
ge:AnlagenWerte:cFuellstandPelletbehaelter:number=-0.004830917874396135}. readValueType=int16, readIndex=Optional[21], readSubIndex(or 0)=0, extractIndex=21 -> numeric value -1 and boolValu
e=true. Registers RegisterArrayWrappingInputRegister(00 45 00 5c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff f
f ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 48 00 3c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff f
f ff ff ff ff ff ff ff ff ff ff ff 00 00 00 00 00 00 ff ff ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@36359493[slaveId=1,functionCode=READ_INPUT_REGISTERS,start
=0,length=88,maxTries=5]
2020-03-09 09:03:37.939 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:AnlagenWerte:cStundenSeitLetzterWartung channels updated: {}. readValueType=int16,
readIndex=Optional[55], readSubIndex(or 0)=0, extractIndex=55 -> numeric value -1 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 45 00 5c 00 28 ff ff ff ff ff ff ff ff
ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 48 00 3c 00 28 ff ff ff ff ff ff ff ff ff ff ff
ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 00 00 00 00 00 ff ff ff ff) for request ModbusPollerThing
HandlerImpl.ModbusPollerReadRequest@36359493[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=0,length=88,maxTries=5]
2020-03-09 09:03:37.944 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.IllegalArgumentException: Index=81 with type=int16 is out-of-bounds given registers of size 65
        at org.openhab.io.transport.modbus.ModbusBitUtilities.extractStateFromRegisters(ModbusBitUtilities.java:108) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler.onRegisters(ModbusDataThingHandler.java:686) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.lambda$0(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891) ~[?:1.8.0_163]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.onRegisters(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:286) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]
2020-03-09 09:03:38.150 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:BoilerWerte received registers RegisterArrayWrappingInputRegister(00 59 00 28 00
37 00 00 00 62 00 5f 00 00 00 5c ff 9e 00 00 01 c6 00 00 00 00 00 00 00 62 00 32 00 3f 00 39 ff 9e 01 fe 09 ea 3a 83 05 15 05 15 00 00 00 00 00 00 00 8c 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 04 46 00 00 00 00 00 00 1b 27 00 0b 00 34 01 08 0a 14 00 08 00 00 00 00 00 00 00 00 00 00 15 54 09 ea 00 00 00 00 00 00 00 00 00 00 15 54 07 5e 07 5e 00 00 00
00 00 00 00 00 00 00 00 00 09 c1 ff fb 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 03 65 00 00 00 3e 00 00 00 00 02 7d ff ff) for request ModbusPollerThingHandlerImpl.ModbusPoller
ReadRequest@60b75489[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1630,length=4,maxTries=5]
2020-03-09 09:03:38.154 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:BoilerWerte:cBoilerTemperatur channels updated: {modbus:data:Heizungsanlage:BoilerW
erte:cBoilerTemperatur:number=44.5}. readValueType=int16, readIndex=Optional[1630], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 89 and boolValue=true. Registers RegisterArrayWrapp
ingInputRegister(00 59 00 28 00 37 00 00 00 62 00 5f 00 00 00 5c ff 9e 00 00 01 c6 00 00 00 00 00 00 00 62 00 32 00 3f 00 39 ff 9e 01 fe 09 ea 3a 83 05 15 05 15 00 00 00 00 00 00 00 8c 00 0
0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 04 46 00 00 00 00 00 00 1b 27 00 0b 00 34 01 08 0a 14 00 08 00 00 00 00 00 00 00 00 00 00 15 54 09 ea 00 00 00 00 00 00 00 00 0
0 00 15 54 07 5e 07 5e 00 00 00 00 00 00 00 00 00 00 00 00 09 c1 ff fb 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 03 65 00 00 00 3e 00 00 00 00 02 7d ff ff) for request ModbusPol
lerThingHandlerImpl.ModbusPollerReadRequest@60b75489[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1630,length=4,maxTries=5]
2020-03-09 09:03:38.155 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:BoilerWerte:cBoilerPumpenansteuerung channels updated: {modbus:data:Heizungsanlage:
BoilerWerte:cBoilerPumpenansteuerung:number=55}. readValueType=int16, readIndex=Optional[1632], readSubIndex(or 0)=0, extractIndex=2 -> numeric value 55 and boolValue=true. Registers Regist
erArrayWrappingInputRegister(00 59 00 28 00 37 00 00 00 62 00 5f 00 00 00 5c ff 9e 00 00 01 c6 00 00 00 00 00 00 00 62 00 32 00 3f 00 39 ff 9e 01 fe 09 ea 3a 83 05 15 05 15 00 00 00 00 00 0
0 00 8c 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 04 46 00 00 00 00 00 00 1b 27 00 0b 00 34 01 08 0a 14 00 08 00 00 00 00 00 00 00 00 00 00 15 54 09 ea 00 00 00 00 0
0 00 00 00 00 00 15 54 07 5e 07 5e 00 00 00 00 00 00 00 00 00 00 00 00 09 c1 ff fb 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 03 65 00 00 00 3e 00 00 00 00 02 7d ff ff) for reque
st ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@60b75489[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1630,length=4,maxTries=5]
2020-03-09 09:03:38.377 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:PufferWerte received registers RegisterArrayWrappingInputRegister(00 68 00 fe 00
00 ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@5e656454[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=2000,length=10,maxTries=5]
2020-03-09 09:03:38.380 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:PufferWerte:cPufferTemperaturOben channels updated: {modbus:data:Heizungsanlage:Puf
ferWerte:cPufferTemperaturOben:number=52.0}. readValueType=int16, readIndex=Optional[2000], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 104 and boolValue=true. Registers RegisterA
rrayWrappingInputRegister(00 68 00 fe 00 00 ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@5e656454[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=2000,length=10
,maxTries=5]
2020-03-09 09:03:38.383 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:PufferWerte:cPufferTemperaturMitte channels updated: {modbus:data:Heizungsanlage:Pu
fferWerte:cPufferTemperaturMitte:number=127.0}. readValueType=int16, readIndex=Optional[2001], readSubIndex(or 0)=0, extractIndex=1 -> numeric value 254 and boolValue=true. Registers Regist
erArrayWrappingInputRegister(00 68 00 fe 00 00 ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@5e656454[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=2000,length
=10,maxTries=5]
2020-03-09 09:03:38.387 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:PufferWerte:cPufferTemperaturUnten channels updated: {modbus:data:Heizungsanlage:Pu
fferWerte:cPufferTemperaturUnten:number=0.0}. readValueType=int16, readIndex=Optional[2002], readSubIndex(or 0)=0, extractIndex=2 -> numeric value 0 and boolValue=false. Registers RegisterA
rrayWrappingInputRegister(00 68 00 fe 00 00 ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@5e656454[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=2000,length=10
,maxTries=5]
2020-03-09 09:03:38.388 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:PufferWerte:cPufferPumpenansteuerung channels updated: {modbus:data:Heizungsanlage:
PufferWerte:cPufferPumpenansteuerung:number=-1}. readValueType=int16, readIndex=Optional[2003], readSubIndex(or 0)=0, extractIndex=3 -> numeric value -1 and boolValue=true. Registers Regist
erArrayWrappingInputRegister(00 68 00 fe 00 00 ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@5e656454[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=2000,length
=10,maxTries=5]
2020-03-09 09:03:38.389 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.IllegalArgumentException: Index=6 with type=int16 is out-of-bounds given registers of size 4
        at org.openhab.io.transport.modbus.ModbusBitUtilities.extractStateFromRegisters(ModbusBitUtilities.java:108) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler.onRegisters(ModbusDataThingHandler.java:686) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.lambda$0(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891) ~[?:1.8.0_163]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.onRegisters(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:286) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]
2020-03-09 09:03:38.602 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.ClassCastException: net.wimpi.modbus.msg.ReadInputRegistersResponse cannot be cast to net.wimpi.modbus.msg.ReadMultipleRegistersResponse
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:284) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]
2020-03-09 09:03:38.829 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:AnlagenParameter2 received registers RegisterArrayWrappingInputRegister(00 8c 00
10) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@4ceb15b0[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=319,length=2,maxTries=5]
2020-03-09 09:03:38.832 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:AnlagenParameter2:cPelletRestbestand channels updated: {modbus:data:Heizungsanlage:
AnlagenParameter2:cPelletRestbestand:number=14.0}. readValueType=int16, readIndex=Optional[319], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 140 and boolValue=true. Registers Regi
sterArrayWrappingInputRegister(00 8c 00 10) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@4ceb15b0[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=319,length=2,maxTr
ies=5]
2020-03-09 09:03:39.074 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:KesselFernsteuerungParameter received registers RegisterArrayWrappingInputRegiste
r(00 1e 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@5c25ce24[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=8000,length=50,maxTries=5]
2020-03-09 09:03:39.075 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:KesselFernsteuerungParameter:cHeizkreisWandVorlaufSolltemperatur channels updated:
{}. readValueType=int16, readIndex=Optional[8000], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 30 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 1e 00 00) for
 request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@5c25ce24[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=8000,length=50,maxTries=5]
2020-03-09 09:03:39.075 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:KesselFernsteuerungParameter:cHeizkreisFussbodenVorlaufSolltemperatur channels upda
ted: {}. readValueType=int16, readIndex=Optional[8001], readSubIndex(or 0)=0, extractIndex=1 -> numeric value 0 and boolValue=false. Registers RegisterArrayWrappingInputRegister(00 1e 00 00
) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@5c25ce24[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=8000,length=50,maxTries=5]
2020-03-09 09:03:39.082 [INFO ] [e.smarthome.model.script.Beleuchtung] - Wohnzimmer Trigger ausgel▒st: 211.0333948429994
2020-03-09 09:03:39.076 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.IllegalArgumentException: Index=18 with type=int16 is out-of-bounds given registers of size 2
        at org.openhab.io.transport.modbus.ModbusBitUtilities.extractStateFromRegisters(ModbusBitUtilities.java:108) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler.onRegisters(ModbusDataThingHandler.java:686) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.lambda$0(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891) ~[?:1.8.0_163]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.onRegisters(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:283) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]
2020-03-09 09:03:39.091 [INFO ] [e.smarthome.model.script.Beleuchtung] - Wohnzimmer Status Lampen: OFF
2020-03-09 09:03:39.734 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:HeizkreisParameter received registers RegisterArrayWrappingInputRegister(00 00 00
 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 01 00 00 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6e70b6ef[slaveId=1,f
unctionCode=READ_MULTIPLE_REGISTERS,start=1030,length=64,maxTries=5]
2020-03-09 09:03:39.736 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:HeizkreisParameter:cWandVorlaufWunschPlus10GRad channels updated: {}. readValueType
=int16, readIndex=Optional[1031], readSubIndex(or 0)=0, extractIndex=1 -> numeric value 0 and boolValue=false. Registers RegisterArrayWrappingInputRegister(00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 01 00 00 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6e70b6ef[slaveId=1,functionCode=READ_MULTIPLE
_REGISTERS,start=1030,length=64,maxTries=5]
2020-03-09 09:03:39.737 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:HeizkreisParameter:cWandVorlaufWunschMinus10GRad channels updated: {}. readValueTyp
e=int16, readIndex=Optional[1032], readSubIndex(or 0)=0, extractIndex=2 -> numeric value 0 and boolValue=false. Registers RegisterArrayWrappingInputRegister(00 00 00 00 00 00 00 00 00 00 00
 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 01 00 00 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6e70b6ef[slaveId=1,functionCode=READ_MULTIPL
E_REGISTERS,start=1030,length=64,maxTries=5]
2020-03-09 09:03:39.738 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:HeizkreisParameter:cWandVorlaufTemperaturAbsenkung channels updated: {}. readValueT
ype=int16, readIndex=Optional[1033], readSubIndex(or 0)=0, extractIndex=3 -> numeric value 0 and boolValue=false. Registers RegisterArrayWrappingInputRegister(00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 01 00 00 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6e70b6ef[slaveId=1,functionCode=READ_MULTI
PLE_REGISTERS,start=1030,length=64,maxTries=5]
2020-03-09 09:03:39.738 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:HeizkreisParameter:cFussbodenVorlaufWunschMinus10GRad channels updated: {}. readVal
ueType=int16, readIndex=Optional[1062], readSubIndex(or 0)=0, extractIndex=32 -> numeric value 0 and boolValue=false. Registers RegisterArrayWrappingInputRegister(00 00 00 00 00 00 00 00 00
 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 01 00 00 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6e70b6ef[slaveId=1,functionCode=READ_M
ULTIPLE_REGISTERS,start=1030,length=64,maxTries=5]
2020-03-09 09:03:39.739 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:HeizkreisParameter:cFussbodenVorlaufTemperaturAbsenkung channels updated: {}. readV
alueType=int16, readIndex=Optional[1063], readSubIndex(or 0)=0, extractIndex=33 -> numeric value 0 and boolValue=false. Registers RegisterArrayWrappingInputRegister(00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 01 00 00 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6e70b6ef[slaveId=1,functionCode=READ
_MULTIPLE_REGISTERS,start=1030,length=64,maxTries=5]
2020-03-09 09:03:39.958 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:BoilerParameter received registers RegisterArrayWrappingInputRegister(ff ff 00 5a
 00 78 00 14 00 96 00 28 00 24 00 1a 00 14 00 28 00 24 00 3c 00 8c 00 00 00 01 00 00 00 96 00 78 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 3c 00 46 00
 10 00 5a 00 28 00 24 00 1a 00 14 00 28 00 20 00 14 00 8c 00 00 00 01 00 00 ff ff 00 96 00 78 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 50 00 78 00 1e) for
request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@49939ce8[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=1631,length=4,maxTries=5]
2020-03-09 09:03:39.959 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:BoilerParameter:cBoilerSollTemperatur channels updated: {}. readValueType=int16, re
adIndex=Optional[1631], readSubIndex(or 0)=0, extractIndex=0 -> numeric value -1 and boolValue=true. Registers RegisterArrayWrappingInputRegister(ff ff 00 5a 00 78 00 14 00 96 00 28 00 24 0
0 1a 00 14 00 28 00 24 00 3c 00 8c 00 00 00 01 00 00 00 96 00 78 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 3c 00 46 00 10 00 5a 00 28 00 24 00 1a 00 1
4 00 28 00 20 00 14 00 8c 00 00 00 01 00 00 ff ff 00 96 00 78 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 50 00 78 00 1e) for request ModbusPollerThingHandler
Impl.ModbusPollerReadRequest@49939ce8[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=1631,length=4,maxTries=5]
2020-03-09 09:03:39.960 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:BoilerParameter:cBoilerNachladenStartTemperatur channels updated: {}. readValueType
=int16, readIndex=Optional[1632], readSubIndex(or 0)=0, extractIndex=1 -> numeric value 90 and boolValue=true. Registers RegisterArrayWrappingInputRegister(ff ff 00 5a 00 78 00 14 00 96 00
28 00 24 00 1a 00 14 00 28 00 24 00 3c 00 8c 00 00 00 01 00 00 00 96 00 78 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 3c 00 46 00 10 00 5a 00 28 00 24
00 1a 00 14 00 28 00 20 00 14 00 8c 00 00 00 01 00 00 ff ff 00 96 00 78 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 50 00 78 00 1e) for request ModbusPollerTh
ingHandlerImpl.ModbusPollerReadRequest@49939ce8[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=1631,length=4,maxTries=5]

MatziBrow · March 9, 2020, 6:22pm

The log did not fit into one post.
Here is the rest:

2020-03-09 09:03:40.186 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.ClassCastException: net.wimpi.modbus.msg.ReadMultipleRegistersResponse cannot be cast to net.wimpi.modbus.msg.ReadInputRegistersResponse
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:287) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]
2020-03-09 09:03:46.861 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:HeizkreisWerte received registers RegisterArrayWrappingInputRegister(00 0f ff ff)
 for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@56dda554[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1030,length=65,maxTries=5]
2020-03-09 09:03:46.864 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:HeizkreisWerte:cHeizkreisWandVorlaufIstTemperatur channels updated: {modbus:data:He
izungsanlage:HeizkreisWerte:cHeizkreisWandVorlaufIstTemperatur:number=7.5}. readValueType=int16, readIndex=Optional[1030], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 15 and boolV
alue=true. Registers RegisterArrayWrappingInputRegister(00 0f ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@56dda554[slaveId=1,functionCode=READ_INPUT_REGISTERS,st
art=1030,length=65,maxTries=5]
2020-03-09 09:03:46.868 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:HeizkreisWerte:cHeizkreisWandVorlaufSollTemperatur channels updated: {modbus:data:H
eizungsanlage:HeizkreisWerte:cHeizkreisWandVorlaufSollTemperatur:number=-0.5}. readValueType=int16, readIndex=Optional[1031], readSubIndex(or 0)=0, extractIndex=1 -> numeric value -1 and bo
olValue=true. Registers RegisterArrayWrappingInputRegister(00 0f ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@56dda554[slaveId=1,functionCode=READ_INPUT_REGISTERS
,start=1030,length=65,maxTries=5]
2020-03-09 09:03:46.869 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.IllegalArgumentException: Index=30 with type=int16 is out-of-bounds given registers of size 2
        at org.openhab.io.transport.modbus.ModbusBitUtilities.extractStateFromRegisters(ModbusBitUtilities.java:108) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler.onRegisters(ModbusDataThingHandler.java:686) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.lambda$0(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891) ~[?:1.8.0_163]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.onRegisters(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:286) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]
2020-03-09 09:03:48.162 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:BoilerWerte received registers RegisterArrayWrappingInputRegister(00 45 00 5c 00
28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 48 00 3c 00 28 ff ff
ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 00 00 00 00 00 ff ff ff ff) fo
r request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@60b75489[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1630,length=4,maxTries=5]
2020-03-09 09:03:48.165 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:BoilerWerte:cBoilerTemperatur channels updated: {modbus:data:Heizungsanlage:BoilerW
erte:cBoilerTemperatur:number=34.5}. readValueType=int16, readIndex=Optional[1630], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 69 and boolValue=true. Registers RegisterArrayWrapp
ingInputRegister(00 45 00 5c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff f
f ff ff 00 48 00 3c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 0
0 00 00 00 00 00 ff ff ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@60b75489[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1630,length=4,maxTries=5]
2020-03-09 09:03:48.168 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:BoilerWerte:cBoilerPumpenansteuerung channels updated: {modbus:data:Heizungsanlage:
BoilerWerte:cBoilerPumpenansteuerung:number=40}. readValueType=int16, readIndex=Optional[1632], readSubIndex(or 0)=0, extractIndex=2 -> numeric value 40 and boolValue=true. Registers Regist
erArrayWrappingInputRegister(00 45 00 5c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff f
f ff ff ff ff ff ff 00 48 00 3c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff f
f ff ff ff 00 00 00 00 00 00 ff ff ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@60b75489[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1630,length=4,maxTries=
5]
2020-03-09 09:03:48.838 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.ClassCastException: net.wimpi.modbus.msg.ReadInputRegistersResponse cannot be cast to net.wimpi.modbus.msg.ReadMultipleRegistersResponse
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:284) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]
2020-03-09 09:03:49.746 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:HeizkreisParameter received registers RegisterArrayWrappingInputRegister(00 1e 00
 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6e70b6ef[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=1030,length=64,maxTries=5]
2020-03-09 09:03:49.747 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:HeizkreisParameter:cWandVorlaufWunschPlus10GRad channels updated: {}. readValueType
=int16, readIndex=Optional[1031], readSubIndex(or 0)=0, extractIndex=1 -> numeric value 0 and boolValue=false. Registers RegisterArrayWrappingInputRegister(00 1e 00 00) for request ModbusPo
llerThingHandlerImpl.ModbusPollerReadRequest@6e70b6ef[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=1030,length=64,maxTries=5]
2020-03-09 09:03:49.749 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.IllegalArgumentException: Index=2 with type=int16 is out-of-bounds given registers of size 2
        at org.openhab.io.transport.modbus.ModbusBitUtilities.extractStateFromRegisters(ModbusBitUtilities.java:108) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler.onRegisters(ModbusDataThingHandler.java:686) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.lambda$0(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891) ~[?:1.8.0_163]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.onRegisters(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:283) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]
2020-03-09 09:03:49.966 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:BoilerParameter received registers RegisterArrayWrappingInputRegister(ff ff 00 5a
 00 78 00 14 00 96 00 28 00 24 00 1a 00 14 00 28 00 24 00 3c 00 8c 00 00 00 01 00 00 00 96 00 78 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 3c 00 46 00
 10 00 5a 00 28 00 24 00 1a 00 14 00 28 00 20 00 14 00 8c 00 00 00 01 00 00 ff ff 00 96 00 78 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 50 00 78 00 1e) for
request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@49939ce8[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=1631,length=4,maxTries=5]
2020-03-09 09:03:49.967 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:BoilerParameter:cBoilerSollTemperatur channels updated: {}. readValueType=int16, re
adIndex=Optional[1631], readSubIndex(or 0)=0, extractIndex=0 -> numeric value -1 and boolValue=true. Registers RegisterArrayWrappingInputRegister(ff ff 00 5a 00 78 00 14 00 96 00 28 00 24 0
0 1a 00 14 00 28 00 24 00 3c 00 8c 00 00 00 01 00 00 00 96 00 78 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 3c 00 46 00 10 00 5a 00 28 00 24 00 1a 00 1
4 00 28 00 20 00 14 00 8c 00 00 00 01 00 00 ff ff 00 96 00 78 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 50 00 78 00 1e) for request ModbusPollerThingHandler
Impl.ModbusPollerReadRequest@49939ce8[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=1631,length=4,maxTries=5]
2020-03-09 09:03:49.967 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:BoilerParameter:cBoilerNachladenStartTemperatur channels updated: {}. readValueType
=int16, readIndex=Optional[1632], readSubIndex(or 0)=0, extractIndex=1 -> numeric value 90 and boolValue=true. Registers RegisterArrayWrappingInputRegister(ff ff 00 5a 00 78 00 14 00 96 00
28 00 24 00 1a 00 14 00 28 00 24 00 3c 00 8c 00 00 00 01 00 00 00 96 00 78 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 3c 00 46 00 10 00 5a 00 28 00 24
00 1a 00 14 00 28 00 20 00 14 00 8c 00 00 00 01 00 00 ff ff 00 96 00 78 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 50 00 78 00 1e) for request ModbusPollerTh
ingHandlerImpl.ModbusPollerReadRequest@49939ce8[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=1631,length=4,maxTries=5]
2020-03-09 09:03:58.174 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.ClassCastException: net.wimpi.modbus.msg.ReadMultipleRegistersResponse cannot be cast to net.wimpi.modbus.msg.ReadInputRegistersResponse
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:287) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]
2020-03-09 09:03:59.973 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.ClassCastException: net.wimpi.modbus.msg.ReadInputRegistersResponse cannot be cast to net.wimpi.modbus.msg.ReadMultipleRegistersResponse
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:284) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]

rossko57 · March 9, 2020, 7:25pm

I’d suspect your poller Things have a terminal error. Have a look in PaperUI and find out what your Things status are.

It’s all going wrong because of stuff like this

2020-03-09 09:03:46.861 [DEBUG] …received registers RegisterArrayWrappingInputRegister(00 0f ff ff)
for request … READ_INPUT_REGISTERS,start=1030,length=65,maxTries=5]

The poller asked for 65 registers and got 4.
But not four random bytes - this came all wrapped up in a properly formatted Modbus-TCP packet.
Strongly suggests the gateway is either messing the data up before sending to openHAB, or it is accepting corrupt serial data and passing that along instead of flagging an error.

@ssalonen - I’m guessing this is not some consequence of TCP fragmenation? Surely that would throw an invalid packet error and not get to this point in the binding.

ssalonen · March 9, 2020, 7:56pm

Yep, I would expect CRC and other errors in case of some fragmentation

ssalonen · March 9, 2020, 8:11pm

Hmm it indeed looks like the binding needs to handle the invalid responses better, to make it try again and not halt.

The fact that we have “Scheduled runnable ended with an exception” looks like not all errors are handled properly, which seems to halt the regular polling java - ScheduledExecutorService Exception handling - Stack Overflow

MatziBrow · March 9, 2020, 9:13pm

I checked. All tings are online. They are not terminating.

MatziBrow · March 9, 2020, 9:15pm

Could you recommend a gateway that you know works reliable?
I could order it and check if the error still appears. If not, I take the new gateway, if yes, I will approach the heating manufacturer and explain them the error.

rossko57 · March 9, 2020, 9:18pm

see

I have a couple of these NNZN working as well, but the setup software is horrible

ssalonen · March 10, 2020, 4:58am

Yes… If my hypothesis above is correct, they would indeed remain online but there is internal error that stopped the polling.

By disabling and then enabling the pollers should resume polling I think.

I will come up with a proper fix for this in a week or two.

But yeah, despite this bug in the binding, the root cause of bad data remains, and it’s probably a good idea to try some other gateway as well.

MatziBrow · March 10, 2020, 9:00pm

I ordered a new gateway. Let’s see if this helps.

I found something interesting that might help. After the “crash” I just restarted the binding. Attached is the result. It looks like the “wrong” telegrams are coming again immediately.

After some of these warnings about “wrong” telegrams, only one poller survives and continues polling. This happens a view minutes later, it is not covered by the log.


2020-03-10 21:53:02.833 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'modbus.things'
2020-03-10 21:53:02.917 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler Modbus tcp
2020-03-10 21:53:02.923 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler Modbus poller
2020-03-10 21:53:02.926 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Registering polling with ModbusManager
2020-03-10 21:53:02.927 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler Modbus poller
2020-03-10 21:53:02.930 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Registering polling with ModbusManager
2020-03-10 21:53:02.929 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.ClassCastException: net.wimpi.modbus.msg.ReadMultipleRegistersResponse cannot be cast to net.wimpi.modbus.msg.ReadInputRegistersResponse
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:287) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]
2020-03-10 21:53:02.932 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler Modbus poller
2020-03-10 21:53:02.935 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Registering polling with ModbusManager
2020-03-10 21:53:02.936 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler Modbus poller
2020-03-10 21:53:02.939 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Registering polling with ModbusManager
2020-03-10 21:53:02.940 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler Modbus poller
2020-03-10 21:53:02.943 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Registering polling with ModbusManager
2020-03-10 21:53:02.944 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler Modbus poller
2020-03-10 21:53:02.947 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Registering polling with ModbusManager
2020-03-10 21:53:02.948 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler Modbus poller
2020-03-10 21:53:02.951 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Registering polling with ModbusManager
2020-03-10 21:53:02.952 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler Modbus poller
2020-03-10 21:53:02.955 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Registering polling with ModbusManager
2020-03-10 21:53:02.956 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler Modbus poller
2020-03-10 21:53:02.959 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Registering polling with ModbusManager
2020-03-10 21:53:02.960 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler Modbus poller
2020-03-10 21:53:02.964 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Registering polling with ModbusManager
2020-03-10 21:53:02.965 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:02.969 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:02.973 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:AnlagenWerte received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:02.973 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:AnlagenWerte received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:02.974 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:02.978 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:AnlagenWerte received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:02.978 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:02.982 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:02.986 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:02.988 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:AnlagenWerte received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:02.991 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:02.994 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:AnlagenWerte received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:02.995 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:02.999 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.001 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:AnlagenWerte received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:03.004 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.008 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.012 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.017 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.021 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:AnlagenWerte2 received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:03.030 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.036 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:HeizkreisWerte received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:03.039 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.046 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:HeizkreisWerte received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:03.047 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.057 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:HeizkreisWerte received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:03.058 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.068 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:HeizkreisWerte received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:03.069 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.074 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:BoilerWerte received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:03.075 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.081 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:BoilerWerte received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:03.082 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.087 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:PufferWerte received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:03.088 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.092 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:PufferWerte received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:03.093 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.098 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:PufferWerte received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:03.099 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.103 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:PufferWerte received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:03.104 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.108 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:PufferWerte received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:03.108 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.113 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.117 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Poller modbus:poller:Heizungsanlage:AnlagenParameter2 received refresh() but the cache is not applicable. Polling new data
2020-03-10 21:53:03.118 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.122 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.125 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.129 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.134 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:AnlagenWerte2 received registers RegisterArrayWrappingInputRegister(00 5e 00 29 00 37 00 00 00 62 00 5f 00 00 00 5f ff 9e 00 00 01 c6 00 00 00 00 00 00 00 58 00 33 00 40 00 3a ff 9e 02 fd 09 ef 50 dc 05 18 05 18 00 00 00 00 00 00 00 8c 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 04 48 00 00 00 00 00 00 1b 38 00 0b 00 34 01 09 0a 1a 00 08 00 00 00 00 00 00 00 00 00 00 15 54 09 ef 00 00 00 00 00 00 00 00 00 00 15 54 07 62 07 62 00 00 00 00 00 00 00 00 00 00 00 00 09 c1 ff fb 00 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 03 73 00 00 00 3e 00 00 00 00 02 79 ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@392756f9[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1000,length=2,maxTries=5]
2020-03-10 21:53:03.141 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:AnlagenWerte2:cAussenTemperatur channels updated: {modbus:data:Heizungsanlage:AnlagenWerte2:cAussenTemperatur:number=47.0}. readValueType=int16, readIndex=Optional[1000], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 94 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 5e 00 29 00 37 00 00 00 62 00 5f 00 00 00 5f ff 9e 00 00 01 c6 00 00 00 00 00 00 00 58 00 33 00 40 00 3a ff 9e 02 fd 09 ef 50 dc 05 18 05 18 00 00 00 00 00 00 00 8c 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 04 48 00 00 00 00 00 00 1b 38 00 0b 00 34 01 09 0a 1a 00 08 00 00 00 00 00 00 00 00 00 00 15 54 09 ef 00 00 00 00 00 00 00 00 00 00 15 54 07 62 07 62 00 00 00 00 00 00 00 00 00 00 00 00 09 c1 ff fb 00 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 03 73 00 00 00 3e 00 00 00 00 02 79 ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@392756f9[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1000,length=2,maxTries=5]
2020-03-10 21:53:03.142 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.147 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.151 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.156 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.160 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.165 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.169 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.173 [DEBUG] [modbus.internal.ModbusHandlerFactory] - createHandler data
2020-03-10 21:53:03.345 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:HeizkreisWerte received registers RegisterArrayWrappingInputRegister(00 14 ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@531526a9[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1030,length=65,maxTries=5]
2020-03-10 21:53:03.348 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:HeizkreisWerte:cHeizkreisWandVorlaufIstTemperatur channels updated: {modbus:data:Heizungsanlage:HeizkreisWerte:cHeizkreisWandVorlaufIstTemperatur:number=10.0}. readValueType=int16, readIndex=Optional[1030], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 20 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 14 ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@531526a9[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1030,length=65,maxTries=5]
2020-03-10 21:53:03.350 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:HeizkreisWerte:cHeizkreisWandVorlaufSollTemperatur channels updated: {modbus:data:Heizungsanlage:HeizkreisWerte:cHeizkreisWandVorlaufSollTemperatur:number=-0.5}. readValueType=int16, readIndex=Optional[1031], readSubIndex(or 0)=0, extractIndex=1 -> numeric value -1 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 14 ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@531526a9[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1030,length=65,maxTries=5]
2020-03-10 21:53:03.351 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.IllegalArgumentException: Index=30 with type=int16 is out-of-bounds given registers of size 2
        at org.openhab.io.transport.modbus.ModbusBitUtilities.extractStateFromRegisters(ModbusBitUtilities.java:108) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler.onRegisters(ModbusDataThingHandler.java:686) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.lambda$0(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891) ~[?:1.8.0_163]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.onRegisters(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:286) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]
2020-03-10 21:53:03.558 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:BoilerWerte received registers RegisterArrayWrappingInputRegister(00 3f 00 5a 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 46 00 3c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 00 00 00 00 00 ff ff ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6e9cb1e0[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1630,length=4,maxTries=5]
2020-03-10 21:53:03.560 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:BoilerWerte:cBoilerTemperatur channels updated: {modbus:data:Heizungsanlage:BoilerWerte:cBoilerTemperatur:number=31.5}. readValueType=int16, readIndex=Optional[1630], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 63 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 3f 00 5a 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 46 00 3c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 00 00 00 00 00 ff ff ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6e9cb1e0[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1630,length=4,maxTries=5]
2020-03-10 21:53:03.562 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:BoilerWerte:cBoilerPumpenansteuerung channels updated: {modbus:data:Heizungsanlage:BoilerWerte:cBoilerPumpenansteuerung:number=40}. readValueType=int16, readIndex=Optional[1632], readSubIndex(or 0)=0, extractIndex=2 -> numeric value 40 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 3f 00 5a 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 46 00 3c 00 28 ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff 00 00 00 00 00 00 ff ff ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@6e9cb1e0[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=1630,length=4,maxTries=5]
2020-03-10 21:53:03.765 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:PufferWerte received registers RegisterArrayWrappingInputRegister(00 6b 00 fe 00 00 ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7c98663e[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=2000,length=10,maxTries=5]
2020-03-10 21:53:03.768 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:PufferWerte:cPufferTemperaturOben channels updated: {modbus:data:Heizungsanlage:PufferWerte:cPufferTemperaturOben:number=53.5}. readValueType=int16, readIndex=Optional[2000], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 107 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 6b 00 fe 00 00 ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7c98663e[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=2000,length=10,maxTries=5]
2020-03-10 21:53:03.771 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:PufferWerte:cPufferTemperaturMitte channels updated: {modbus:data:Heizungsanlage:PufferWerte:cPufferTemperaturMitte:number=127.0}. readValueType=int16, readIndex=Optional[2001], readSubIndex(or 0)=0, extractIndex=1 -> numeric value 254 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 6b 00 fe 00 00 ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7c98663e[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=2000,length=10,maxTries=5]
2020-03-10 21:53:03.774 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:PufferWerte:cPufferTemperaturUnten channels updated: {modbus:data:Heizungsanlage:PufferWerte:cPufferTemperaturUnten:number=0.0}. readValueType=int16, readIndex=Optional[2002], readSubIndex(or 0)=0, extractIndex=2 -> numeric value 0 and boolValue=false. Registers RegisterArrayWrappingInputRegister(00 6b 00 fe 00 00 ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7c98663e[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=2000,length=10,maxTries=5]
2020-03-10 21:53:03.775 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:PufferWerte:cPufferPumpenansteuerung channels updated: {modbus:data:Heizungsanlage:PufferWerte:cPufferPumpenansteuerung:number=-1}. readValueType=int16, readIndex=Optional[2003], readSubIndex(or 0)=0, extractIndex=3 -> numeric value -1 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 6b 00 fe 00 00 ff ff) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7c98663e[slaveId=1,functionCode=READ_INPUT_REGISTERS,start=2000,length=10,maxTries=5]
2020-03-10 21:53:03.777 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.IllegalArgumentException: Index=6 with type=int16 is out-of-bounds given registers of size 4
        at org.openhab.io.transport.modbus.ModbusBitUtilities.extractStateFromRegisters(ModbusBitUtilities.java:108) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler.onRegisters(ModbusDataThingHandler.java:686) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.lambda$0(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891) ~[?:1.8.0_163]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.onRegisters(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:286) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]
2020-03-10 21:53:03.982 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.ClassCastException: net.wimpi.modbus.msg.ReadInputRegistersResponse cannot be cast to net.wimpi.modbus.msg.ReadMultipleRegistersResponse
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:284) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]
2020-03-10 21:53:04.185 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:AnlagenParameter2 received registers RegisterArrayWrappingInputRegister(00 8c 00 10) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@37e0afad[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=319,length=2,maxTries=5]
2020-03-10 21:53:04.197 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:AnlagenParameter2:cPelletRestbestand channels updated: {modbus:data:Heizungsanlage:AnlagenParameter2:cPelletRestbestand:number=14.0}. readValueType=int16, readIndex=Optional[319], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 140 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 8c 00 10) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@37e0afad[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=319,length=2,maxTries=5]
2020-03-10 21:53:04.405 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:KesselFernsteuerungParameter received registers RegisterArrayWrappingInputRegister(00 1e 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@3113f18d[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=8000,length=50,maxTries=5]
2020-03-10 21:53:04.407 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:KesselFernsteuerungParameter:cHeizkreisWandVorlaufSolltemperatur channels updated: {}. readValueType=int16, readIndex=Optional[8000], readSubIndex(or 0)=0, extractIndex=0 -> numeric value 30 and boolValue=true. Registers RegisterArrayWrappingInputRegister(00 1e 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@3113f18d[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=8000,length=50,maxTries=5]
2020-03-10 21:53:04.408 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:Heizungsanlage:KesselFernsteuerungParameter:cHeizkreisFussbodenVorlaufSolltemperatur channels updated: {}. readValueType=int16, readIndex=Optional[8001], readSubIndex(or 0)=0, extractIndex=1 -> numeric value 0 and boolValue=false. Registers RegisterArrayWrappingInputRegister(00 1e 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@3113f18d[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=8000,length=50,maxTries=5]
2020-03-10 21:53:04.409 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.IllegalArgumentException: Index=18 with type=int16 is out-of-bounds given registers of size 2
        at org.openhab.io.transport.modbus.ModbusBitUtilities.extractStateFromRegisters(ModbusBitUtilities.java:108) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusDataThingHandler.onRegisters(ModbusDataThingHandler.java:686) ~[?:?]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.lambda$0(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891) ~[?:1.8.0_163]
        at org.openhab.binding.modbus.internal.handler.ModbusPollerThingHandlerImpl$ReadCallbackDelegator.onRegisters(ModbusPollerThingHandlerImpl.java:95) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusLibraryWrapper.invokeCallbackWithResponse(ModbusLibraryWrapper.java:283) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.lambda$1(ModbusManagerImpl.java:167) ~[?:?]
        at org.openhab.io.transport.modbus.internal.SimpleStopWatch.timeRunnable(SimpleStopWatch.java:152) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:166) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl$PollOperation.accept(ModbusManagerImpl.java:1) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.executeOperation(ModbusManagerImpl.java:575) ~[?:?]
        at org.openhab.io.transport.modbus.internal.ModbusManagerImpl.lambda$15(ModbusManagerImpl.java:723) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_163]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_163]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_163]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_163]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_163]
2020-03-10 21:53:04.645 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:Heizungsanlage:HeizkreisParameter received registers RegisterArrayWrappingInputRegister(00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 01 00 00 00 00) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@605b5243[slaveId=1,functionCode=READ_MULTIPLE_REGISTERS,start=1030,length=64,maxTries=5]

rossko57 · March 10, 2020, 11:52pm

Pretty much what we’d expect.

I had a closer look at the M511 ; it’s not a new model, wouldn’t really expect troubles. You might try asking USR if your firmware is up to date.

The docs are a bit sparse (but beat many Chinese products). They don’t update docs to keep up with firmware changes.

One thing the docs show is an “Enable Memory Function” option for the MODBUS_RTU_SLAVE mode screen. You don’t seem to have that option (I’d want to turn it off and stop caching!) but maybe that option only appears when you have the serial command store thingy ticked as well. We don’t want that either, that’s the autonomous polling thing.

The UART packet time/length settings look good ; the gateway should detect the end of a data packet on serial by a 4-byte silence, and build a TCP packet out of it. Seems reasonable.
I would turn off sync baudrate but do not expect that to help.

I’m pretty sure that unless there is a serious design flaw in the gateway, if you were getting rubbish data on the serial line (e.g. interference or bad termination) you would be seeing plenty of TCP timeouts (if it discarded rubbish) or modbus Exception Code rejections in your openhab.log in between successful transfers. No sign of that??

EDIT - thinking on it, that might be exactly the part that goes wrong. Say there’s a transient serial error, not the end of the world, but instead of failing the transfer, the gateway serves data from its cache instead. It’s gone wrong already in doing that, no reason it’s going to serve anything like the correct data. And the unwanted transfer could mess up cache pointers forever.

ssalonen · March 11, 2020, 5:34am

Thank you @MatziBrow

This indeed fits with the story we have been discussing above.

I should be able to fix the error recovery for these errors in a pretty straightforward way. Then at least would keep on retrying the polling… Might not be enough to solve the root issue considering that the issues seem to stick with the gateway. Hopefully configuration advice above helps out