[SOLVED] Many(+100) modbus pollers, is it slowing down the binding?

Your slave does to need to be able to deal with registers included in a block / span that might not be defined. Some slaves reject such reads, yours is presumably under your control?

I know that slaves can reject such requests,I will make some tests how SH2WEB reacts. It is also possible to rearrange the modbusmap manually in it, but I’d prefer not to touch it, since I am aiming for a generic solution for other users of the system as well.

cheekily paging @mbs38 as the Modbus “demanding network” experienced user . Any further advice for us?

Unfortunately not. Everything I would have suggested has already been proposed by you. For example decreasing the amount of pollers. However I do not think it is really going to solve the problem because I am having similiar issues with my serial setup. Actually, this is why I am still delaying a move towards the 2.x binding on my productive systems.

In my setup something like this

Bridge modbus:serial:hut22 [ port="/dev/ttyUSB0", baud=38400, id=22, stopBits="1.0", parity="none",dataBits=8, echo=false, encoding="rtu", flowControlIn="none", flowControlOut="none", receiveTimeoutMillis=200, timeBetweenTransactionsMillis=5 ]
{

        Bridge poller coils [ start=0, length=99, refresh=20, type="coil" ]
        {
                Thing data out0 [ readStart="0", readValueType="bit", writeStart="0", writeValueType="bit", writeType="coil" ]
                Thing data out1 [ readStart="1", readValueType="bit", writeStart="1", writeValueType="bit", writeType="coil" ]
                Thing data out2 [ readStart="2", readValueType="bit", writeStart="2", writeValueType="bit", writeType="coil" ]
                Thing data out3 [ readStart="3", readValueType="bit", writeStart="3", writeValueType="bit", writeType="coil" ]
                Thing data out4 [ readStart="4", readValueType="bit", writeStart="4", writeValueType="bit", writeType="coil" ]
                Thing data out5 [ readStart="5", readValueType="bit", writeStart="5", writeValueType="bit", writeType="coil" ]
                  .
                  .
                  .
                  .
                Thing data out95 [ readStart="95", readValueType="bit", writeStart="95", writeValueType="bit", writeType="coil" ]                                    
        }
        
        Bridge poller sensor    [ start=52, length=7, refresh=20, type="holding" ]
        {
                Thing data voltage              [ readStart="52", readValueType="uint16" ]
        
        }
}

causes high CPU load and also responds kind of sluggishly. In fact both CPUs on my Intel NUC (N3050 cpu) are at around 80% all the time causing the system to heat up and therefore increase fanspeed to audible levels. With the old 1.x binding the load was negligible even with >50 modbus transactions per second.

Ssalonen and I are already in a private conversation about this. I have given him access to one of my system so he can do some real world tests. He is working on a solution and, if I have understood correctly, part of the problem has been identified.

Maybe @ssalonen can clarify?

Best regards,
Max

Thanks for opening this up here.

Yes, we are investigating where the bottleneck is… It’s a bit too early to conclude anything for sure. At this stage it looks like the things and channels of new bindings brings lot of overhead.

Will update when I have more time to work on this, and have something solid to share

Best
Sami

There’s some discussion ongoing in Eclipse Smarthome project on this: https://github.com/eclipse/smarthome/issues/6416#issuecomment-433983134 . Follow this for updates

There might be some performance issues with the openHAB core itself.

1 Like

The new openHAB 2.4 snapshot should now include the framework improvements (see link above), please try it out and feel free to comment.

Hi,

I have done changes in two steps.

First I removed all unnesscesary writes according to previous suggestions. This resulted in removing write-command from 41 pollers out of 129. I also reduced refreshtime of some signals to 10000ms instead of 1000ms. I didi not notice any improvement in responsetime.

I have now updated to the snapshot 2.4.0~20181109205612-1 (Build #1418).

I do not experience any improvement regarding responsetimes compared with before the update. This is my perception only. How would I go about to measure it in a better way so you can get better feedback?

Sorry that you are still seeing poor behavior. Thanks for trying out all this, I think this is really valuable test case to improve the performance.

Before proceeding further, in addition to updating openHAB to snapshot, I would update the modbus binding and transport to latest snapshot. The latest version has a fix for the “queue” accumulating, something discussed earlier in this thread. Ensure you have the latest version active (check the date) by using bundle:list | grep -i modbus karaf console command.

If you are still experiencing problems, please share the full configuration here (with latest changes).

Then I would you to set the logging to verbose (check documentation for details) and record the slow response event (both events.log and general openhab.log is of interest).

I understand that the main problem is that after changing a Dimmer item from sitemap, it takes a long time for something to change in real world

I find that the responsetime is now much longer, appr 8-10 seconds from changing for example a dimmer in the site-map until it happen IRL.

From the verbose logs we can see how long delay there is between “item receiving a command” and “binding writing to slave”.

From the logs we will also see whether the polling is following the expected cycle, or whether is lagging behind due to sheets amount of different requests. The polling and writes might be competing for the communication channel with the slaves.

Best
Sami

@Pe_Man
I’m facing a similar problem. My is caused by a misconfigured persistance.

I had done this:

 Items {
    * : strategy = everyUpdate

I see no performance problems before I use MODBUS-Binding. But it is clear what is happen. MODBUS-Binding is my first binding which polls. So I get item updates for nearly 100 items every 1sec. This causes my OH to response very slow.

I changed it to

Items {
    * : strategy = everyChange

and the problems are gone.

Maybe it is the same on your installation.

2 Likes

That’s well spotted !

Hi,

I too have recently moved from Modbus 1 to 2 binding and am reading and writing many addresses to an SH2WEB the same as @Pe_Man . Modbus 1 binding was almost instant response. Modbus 2 binding is taking about 10 seconds. Please let me know if there has been any developments to solve this.

Thanks

Hi

There has been progress, please have a look at my previous responses and report back.

I wasn’t sure where to find this but I found this documentation: https://www.openhab.org/docs/configuration/persistence.html#persistence
and found that I had no persistence activated. I followed the recommendations and added rrd4j as default persistence, added the file with the default recommended values:

Strategies {
        everyHour : "0 0 * * * ?"
        everyDay  : "0 0 0 * * ?"

        // if no strategy is specified for an Item entry below, the default list will be used
       default = everyChange
}

/*
 * Each line in this section defines for which Item(s) which strategy(ies) should be applied.
 * You can list single items, use "*" for all items or "groupitem*" for all members of a group
 * Item (excl. the group Item itself).
 */
Items {
        // persist the Item state of Heating_Mode and Notifications_Active on every change and restore them from the db at startup
        * : strategy = everyChange, restoreOnStartup

        // additionally, persist all temperature and weather values every hour
        Temperature*, Weather* : strategy = everyHour
}

But after doing this I did not see any improvement of the performance.

/per

The persistence issue was about IF you had persistence running, THEN Modbus frequent polls could cause frequent updates, triggering persistence to do its work, with an effect of adding load to the system and causing apparent poor performance (because there is more work being done)

If you didn’t have persistence, then adding it will not make anything work better.

It’s probably time to share some logs?

1 Like

I see and understand that, but since I had not persistanse added and I understood the documentation that it was important to have a default persistance I thought it would be good to mention this.

Default Persistence Service

It is important to select a default persistence service. You should do this even if you have only one persistence add-on installed.

To select a default persistence service, in paper UI, select Configuration and then System from the side menu. Scroll down to “Persistence”, and select your default service from the drop-down list. Note that you must first install a persistence add-on before you make this selection. Be sure to save your choice once you have selected your default service.

I suppose the docs are not very clear that you need not have any persistence installed at all, but if you do have one you then should specify the default one.

Anyway, most people do end up with one even if its only for restore-on-startup, I wouldn’t worry about it. It works happily alongside Modbus for most people.

To look into your problem, I think Sami will need to see those verbose logs of your Dimmer example

1 Like

@Pe_Man & @Tim2016 any updates?

Looking forward to your report.

@Pe_Man please see this post above for the next steps.

Latest snapshot is now logging more clearly where the time goes, verbose logs will tell. See https://github.com/openhab/openhab2-addons/pull/4304

Hi,

I have some other issues with the modbus-slave at the moment, I will fix that, then test and come back with the results

Hey,

This weekend I switched to the new modbus binding ever since I notice that the cpu load is much higher when I frequently pol around 10ms.With the previous binding this was not the happening.I read the tread and you where asking for the verbose log’s?In de karaf console i can not set it to verbose so i set it to debug for the modbus binding and this is what came out.Is this what jou need to analyze it?Normaly my cpu load is around 8% with the new binding it is around 35%.

2018-12-26 18:06:31.354 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave11:slave11Inputs:di23 channels updated: {modbus:data:slave11:slave11Inputs:di23:contact=CLOSED}. readValueType=bit, readIndex=Optional[7] -> numeric value 0 and boolValue=false. Bits BitArrayWrappingBitVector(bits=0000000001000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7db2b478[slaveId=11,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

2018-12-26 18:06:31.354 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave11:slave11Inputs:di24 channels updated: {modbus:data:slave11:slave11Inputs:di24:contact=CLOSED}. readValueType=bit, readIndex=Optional[8] -> numeric value 0 and boolValue=false. Bits BitArrayWrappingBitVector(bits=0000000001000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7db2b478[slaveId=11,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

2018-12-26 18:06:31.355 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave11:slave11Inputs:di25 channels updated: {modbus:data:slave11:slave11Inputs:di25:contact=OPEN}. readValueType=bit, readIndex=Optional[9] -> numeric value 1 and boolValue=true. Bits BitArrayWrappingBitVector(bits=0000000001000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7db2b478[slaveId=11,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

2018-12-26 18:06:31.356 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave11:slave11Inputs:di26 channels updated: {modbus:data:slave11:slave11Inputs:di26:contact=CLOSED}. readValueType=bit, readIndex=Optional[10] -> numeric value 0 and boolValue=false. Bits BitArrayWrappingBitVector(bits=0000000001000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7db2b478[slaveId=11,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

2018-12-26 18:06:31.357 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave11:slave11Inputs:di27 channels updated: {modbus:data:slave11:slave11Inputs:di27:contact=CLOSED}. readValueType=bit, readIndex=Optional[11] -> numeric value 0 and boolValue=false. Bits BitArrayWrappingBitVector(bits=0000000001000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7db2b478[slaveId=11,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

2018-12-26 18:06:31.357 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave11:slave11Inputs:di28 channels updated: {modbus:data:slave11:slave11Inputs:di28:contact=CLOSED}. readValueType=bit, readIndex=Optional[12] -> numeric value 0 and boolValue=false. Bits BitArrayWrappingBitVector(bits=0000000001000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7db2b478[slaveId=11,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

2018-12-26 18:06:31.358 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave11:slave11Inputs:di29 channels updated: {modbus:data:slave11:slave11Inputs:di29:contact=CLOSED}. readValueType=bit, readIndex=Optional[13] -> numeric value 0 and boolValue=false. Bits BitArrayWrappingBitVector(bits=0000000001000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7db2b478[slaveId=11,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

2018-12-26 18:06:31.358 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave11:slave11Inputs:di30 channels updated: {}. readValueType=bit, readIndex=Optional[14] -> numeric value 0 and boolValue=false. Bits BitArrayWrappingBitVector(bits=0000000001000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7db2b478[slaveId=11,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

2018-12-26 18:06:31.359 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave11:slave11Inputs:di31 channels updated: {modbus:data:slave11:slave11Inputs:di31:contact=CLOSED}. readValueType=bit, readIndex=Optional[15] -> numeric value 0 and boolValue=false. Bits BitArrayWrappingBitVector(bits=0000000001000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@7db2b478[slaveId=11,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

2018-12-26 18:06:31.410 [DEBUG] [handler.ModbusPollerThingHandlerImpl] - Thing modbus:poller:slave10:slave10Inputs received coils BitArrayWrappingBitVector(bits=0000000000000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@50255960[slaveId=10,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

2018-12-26 18:06:31.411 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave10:slave10Inputs:di00 channels updated: {modbus:data:slave10:slave10Inputs:di00:contact=CLOSED}. readValueType=bit, readIndex=Optional[0] -> numeric value 0 and boolValue=false. Bits BitArrayWrappingBitVector(bits=0000000000000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@50255960[slaveId=10,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

2018-12-26 18:06:31.411 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave10:slave10Inputs:di01 channels updated: {modbus:data:slave10:slave10Inputs:di01:contact=CLOSED}. readValueType=bit, readIndex=Optional[1] -> numeric value 0 and boolValue=false. Bits BitArrayWrappingBitVector(bits=0000000000000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@50255960[slaveId=10,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

2018-12-26 18:06:31.412 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave10:slave10Inputs:di02 channels updated: {modbus:data:slave10:slave10Inputs:di02:contact=CLOSED}. readValueType=bit, readIndex=Optional[2] -> numeric value 0 and boolValue=false. Bits BitArrayWrappingBitVector(bits=0000000000000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@50255960[slaveId=10,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

2018-12-26 18:06:31.413 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave10:slave10Inputs:di03 channels updated: {modbus:data:slave10:slave10Inputs:di03:contact=CLOSED}. readValueType=bit, readIndex=Optional[3] -> numeric value 0 and boolValue=false. Bits BitArrayWrappingBitVector(bits=0000000000000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@50255960[slaveId=10,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

2018-12-26 18:06:31.414 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave10:slave10Inputs:di04 channels updated: {modbus:data:slave10:slave10Inputs:di04:contact=CLOSED}. readValueType=bit, readIndex=Optional[4] -> numeric value 0 and boolValue=false. Bits BitArrayWrappingBitVector(bits=0000000000000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@50255960[slaveId=10,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

2018-12-26 18:06:31.415 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave10:slave10Inputs:di05 channels updated: {modbus:data:slave10:slave10Inputs:di05:contact=CLOSED}. readValueType=bit, readIndex=Optional[5] -> numeric value 0 and boolValue=false. Bits BitArrayWrappingBitVector(bits=0000000000000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@50255960[slaveId=10,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

2018-12-26 18:06:31.420 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave10:slave10Inputs:di06 channels updated: {modbus:data:slave10:slave10Inputs:di06:contact=CLOSED}. readValueType=bit, readIndex=Optional[6] -> numeric value 0 and boolValue=false. Bits BitArrayWrappingBitVector(bits=0000000000000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@50255960[slaveId=10,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

2018-12-26 18:06:31.421 [DEBUG] [ernal.handler.ModbusDataThingHandler] - Thing modbus:data:slave10:slave10Inputs:di07 channels updated: {modbus:data:slave10:slave10Inputs:di07:contact=CLOSED}. readValueType=bit, readIndex=Optional[7] -> numeric value 0 and boolValue=false. Bits BitArrayWrappingBitVector(bits=0000000000000000) for request ModbusPollerThingHandlerImpl.ModbusPollerReadRequest@50255960[slaveId=10,functionCode=READ_INPUT_DISCRETES,start=0,length=16,maxTries=3]

Hi @Rado1, appreciate if you will test with openHAB 2.4 release, using 2.4 release version of the binding.

Please configure logging as adviced in the docs. You can use pastebin.com to share longer logs

Finally, can you please share the thing and item configurations