Can't read more than 9 to 10 values at once with Modbus

[Gvico]

PROBLEM DESCRIPTION

I'm trying to read 24 registers from a Modbus slave, but can't get to read more than 9-10 at a time.
If i try to go higher, i don't get any answer.

REQUESTED INFORMATION

• Read the Contributing Guide and Policy and the Code of Conduct
• Searched the problem in issues
• Searched the problem in discussions
• Searched the problem in the docs
• Searched the problem in the chat
• Device used (e.g., Sonoff Basic): Kincony KC868-A16 Rev1.5
• Tasmota binary firmware version number used: 12.4.0
  • Pre-compiled
  • Self-compiled
• Flashing tools used: PlatformIO on Windows
• Provide the output of command: Backlog Template; Module; GPIO 255:

  Configuration output here:
12:26:56.406 MQT: stat/ACIT_A3BE0C/RESULT = {"NAME":"KC868-A16 rev 1.4","GPIO":[32,1,1,1,640,608,1,1,1,9408,1,1,9440,1,5600,1,0,1,1,5568,0,1,1,1,0,0,0,0,1,1,1,1,1,0,0,1],"FLAG":0,"BASE":1}
12:26:56.645 MQT: stat/ACIT_A3BE0C/RESULT = {"Module":{"0":"KC868-A16 rev 1.4"}}
12:26:56.858 MQT: stat/ACIT_A3BE0C/RESULT = {"GPIO0":{"32":"Button1"},"GPIO1":{"0":"None"},"GPIO2":{"0":"None"},"GPIO3":{"0":"None"},"GPIO4":{"640":"I2C SDA1"},"GPIO5":{"608":"I2C SCL1"},"GPIO6":{"0":"None"},"GPIO7":{"0":"None"},"GPIO8":{"0":"None"},"GPIO9":{"0":"None"},"GPIO10":{"0":"None"},"GPIO11":{"0":"None"},"GPIO12":{"0":"None"},"GPIO13":{"9408":"ModBr Tx"},"GPIO14":{"0":"None"},"GPIO15":{"0":"None"},"GPIO16":{"9440":"ModBr Rx"},"GPIO17":{"0":"None"},"GPIO18":{"5600":"ETH MDIO"},"GPIO19":{"0":"None"},"GPIO20":{"0":"None"},"GPIO21":{"0":"None"},"GPIO22":{"0":"None"},"GPIO23":{"5568":"ETH MDC"},"GPIO24":{"0":"None"},"GPIO25":{"0":"None"},"GPIO26":{"0":"None"},"GPIO27":{"0":"None"},"GPIO32":{"0":"None"},"GPIO33":{"0":"None"},"GPIO34":{"0":"None"},"GPIO35":{"0":"None"},"GPIO36":{"0":"None"},"GPIO37":{"0":"None"},"GPIO38":{"0":"None"},"GPIO39":{"0":"None"}}

• If using rules, provide the output of this command: Backlog Rule1; Rule2; Rule3:

  Rules output here:

• Provide the output of this command: Status 0:

  STATUS 0 output here:
12:27:44.586 MQT: stat/ACIT_A3BE0C/STATUS = {"Status":{"Module":0,"DeviceName":"KC868-A16","FriendlyName":["KC868-A16","KC868-A162","KC868-A163","KC868-A164","","","",""],"Topic":"ACIT_A3BE0C","ButtonTopic":"0","Power":0,"PowerOnState":3,"LedState":1,"LedMask":"FFFF","SaveData":1,"SaveState":1,"SwitchTopic":"0","SwitchMode":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"ButtonRetain":0,"SwitchRetain":0,"SensorRetain":0,"PowerRetain":0,"InfoRetain":0,"StateRetain":0,"StatusRetain":0}}
12:27:44.641 MQT: stat/ACIT_A3BE0C/STATUS1 = {"StatusPRM":{"Baudrate":115200,"SerialConfig":"8N1","GroupTopic":"tasmotas","OtaUrl":"http://ota.tasmota.com/tasmota32/release/tasmota32.bin","RestartReason":"Vbat power on reset","Uptime":"0T00:01:08","StartupUTC":"2023-03-02T11:26:36","Sleep":50,"CfgHolder":4618,"BootCount":46,"BCResetTime":"2023-02-21T09:30:14","SaveCount":181}}
12:27:44.683 MQT: stat/ACIT_A3BE0C/STATUS2 = {"StatusFWR":{"Version":"12.4.0.1(tasmota)","BuildDateTime":"2023-02-21T09:27:20","Core":"2_0_6","SDK":"4.4.3.20230129","CpuFrequency":160,"Hardware":"ESP32-D0WD-V3 rev.3","CR":"465/699"}}
12:27:44.705 MQT: stat/ACIT_A3BE0C/STATUS3 = {"StatusLOG":{"SerialLog":2,"WebLog":2,"MqttLog":0,"SysLog":0,"LogHost":"","LogPort":514,"SSId":["IoTLab",""],"TelePeriod":300,"Resolution":"558180C0","SetOption":["00008009","2805C80001000600003C5A0A192800000000","80000080","00206000","00044000","00000000"]}}
12:27:44.746 MQT: stat/ACIT_A3BE0C/STATUS4 = {"StatusMEM":{"ProgramSize":1487,"Free":1392,"Heap":124,"StackLowMark":1,"PsrMax":0,"PsrFree":0,"ProgramFlashSize":4096,"FlashSize":4096,"FlashChipId":"16405E","FlashFrequency":40,"FlashMode":"DIO","Features":["00000809","9F9AD7CF","0015A001","B7F7BFCF","05DA9BC0","E0360FC7","480840D2","20200000","D43C482D","000080B1"],"Drivers":"1,2,3,4,5,7,8,9,10,11,12,14,16,17,20,21,24,26,27,28,29,34,35,38,50,52,59,60,62,63,66,82,86,87,88","Sensors":"1,2,3,5,6,7,8,9,10,11,12,13,14,15,17,18,19,20,21,22,26,31,34,37,39,40,42,43,45,51,52,55,56,58,59,64,66,67,74,85,92,95,98,103,127"}}
12:27:44.814 MQT: stat/ACIT_A3BE0C/STATUS5 = {"StatusNET":{"Hostname":"ACIT-A3BE0C-7692","IPAddress":"192.168.16.169","Gateway":"192.168.16.1","Subnetmask":"255.255.255.0","DNSServer1":"192.168.16.3","DNSServer2":"0.0.0.0","Mac":"90:38:0C:A3:BE:0C","IP6Global":"","IP6Local":"fe80::9238:cff:fea3:be0c","Ethernet":{"Hostname":"ACIT-A3BE0C-7692-eth","IPAddress":"0.0.0.0","Gateway":"0.0.0.0","Subnetmask":"0.0.0.0","DNSServer1":"192.168.16.3","DNSServer2":"0.0.0.0","Mac":"90:38:0C:A3:BE:0F","IP6Global":"","IP6Local":""},"Webserver":2,"HTTP_API":1,"WifiConfig":4,"WifiPower":17.0}}
12:27:44.868 MQT: stat/ACIT_A3BE0C/STATUS6 = {"StatusMQT":{"MqttHost":"52507c7516ed42a89075e988760b132c.s1.eu.hivemq.cloud","MqttPort":8883,"MqttClientMask":"DVES_%06X","MqttClient":"DVES_A3BE0C","MqttUser":"user1235","MqttCount":1,"MAX_PACKET_SIZE":1200,"KEEPALIVE":30,"SOCKET_TIMEOUT":4}}
12:27:44.900 MQT: stat/ACIT_A3BE0C/STATUS7 = {"StatusTIM":{"UTC":"2023-03-02T11:27:44","Local":"2023-03-02T12:27:44","StartDST":"2023-03-26T02:00:00","EndDST":"2023-10-29T03:00:00","Timezone":"+01:00","Sunrise":"07:30","Sunset":"18:33"}}
12:27:44.928 MQT: stat/ACIT_A3BE0C/STATUS10 = {"StatusSNS":{"Time":"2023-03-02T12:27:44","PCF8574-1":{"D0":1,"D1":1,"D2":1,"D3":1,"D4":1,"D5":1,"D6":1,"D7":1},"PCF8574-2":{"D0":1,"D1":1,"D2":1,"D3":1,"D4":1,"D5":1,"D6":1,"D7":1},"PCF8574-3":{"D0":1,"D1":1,"D2":1,"D3":1,"D4":1,"D5":1,"D6":1,"D7":1},"PCF8574-4":{"D0":1,"D1":1,"D2":1,"D3":1,"D4":1,"D5":1,"D6":1,"D7":1}}}
12:27:44.979 MQT: stat/ACIT_A3BE0C/STATUS11 = {"StatusSTS":{"Time":"2023-03-02T12:27:44","Uptime":"0T00:01:08","UptimeSec":68,"Heap":126,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":20,"MqttCount":1,"Berry":{"HeapUsed":3,"Objects":43},"POWER1":"OFF","POWER2":"OFF","POWER3":"OFF","POWER4":"OFF","POWER5":"OFF","POWER6":"OFF","POWER7":"OFF","POWER8":"OFF","POWER9":"OFF","POWER10":"OFF","POWER11":"OFF","POWER12":"OFF","POWER13":"OFF","POWER14":"OFF","POWER15":"OFF","POWER16":"OFF","Wifi":{"AP":1,"SSId":"IoTLab","BSSId":"02:EC:DA:11:55:DC","Channel":1,"Mode":"11n","RSSI":86,"Signal":-57,"LinkCount":1,"Downtime":"0T00:00:04"}}}

• Set weblog to 4 and then, when you experience your issue, provide the output of the Console log:

  Console output here:
13:01:31.314 CMD: Grp 0, Cmd 'MODBUSSEND', Idx 1, Len 88, Pld -99, Data '{"deviceaddress": 1, "functioncode": 3, "startaddress": 26, "type":"uint16", "count":24}'
13:01:31.328 MQT: stat/ACIT_A3BE0C/RESULT = {"ModbusSend":"Done"}
13:01:31.371 MBS: MBR Driver receive error 9
13:01:31.405 MBS: MBR Driver receive error 7

TO REPRODUCE

• Have a Modbus slave device to read from (in my case, i'm trying to read 24 registers starting from the 26th)
• Go to the console
• Run the command ModBusSend {"deviceaddress": 1, "functioncode": 3, "startaddress": 26, "type":"uint16", "count":24}

EXPECTED BEHAVIOUR

A response like {"ModbusReceived":{"DeviceAddress":1,"FunctionCode":3,"StartAddress":26,"Length":21,"Count":8,"Values":[x,x,x,x...]}}

SCREENSHOTS

If applicable, add screenshots to help explain your problem.

ADDITIONAL CONTEXT

Add any other context about the problem here.

(Please, remember to close the issue when the problem has been addressed)

[barbudor]

Hi @jeroenst
I have some suspicions regarding the test here:

Tasmota/tasmota/tasmota_xdrv_driver/xdrv_63_modbus_bridge.ino

Line 245 in fe46f4d

if (modbusBridge.byteCount == 0) modbusBridge.byteCount = modbusBridge.dataCount * 2;

As there are possible exits from ModbusBridgeHandle() without passing by the line 319 (for exemple in case of receive error),
could it be possible that in some cases, modbusBridge.byteCount contains an old value not related to modbusBridge.dataCount and leading to a wrong malloc size ?

Wouldn't be better to always compute byteCount there (without the test) ?
Or set it properly along with dataCount depending on each type size ?

Or may be go once and for all with a single alloc which would handle maximum expected size (64 registers)

By the way I think line is wrong:

Tasmota/tasmota/tasmota_xdrv_driver/xdrv_63_modbus_bridge.ino

Line 756 in fe46f4d

if (bitMode) modbusBridge.byteCount = (modbusBridge.count / 8) + 1;

IMHO it should be:

if (bitMode) modbusBridge.byteCount = (modbusBridge.count + 7) / 8;

[jeroenst]

The MBR driver error is thrown by the existing modbus driver in Tasmota as far as I remember.

Error codes are documented at https://tasmota.github.io/docs/Modbus-Bridge/#driver-errors which states it's an crc error combined with an not enough data error. My first suspicion is that the modbus driver in Tasmota can't handle that much data at once.

About the code in line 245 I think it's actually correct, but I will take a look at it.

About the count in line 756 I think you are correct although I did test this afaik.

I will take a further look at this next week after my holiday.

[jeroenst]

After digging into the code I suspect that the modbus receive timeout in TasmotaMobus.cpp is to low causing the CRC error followed by a not enough data error because not all data is received fast enough. Maybe the modbus device is sending the data in chunks.

Tasmota/lib/lib_basic/TasmotaModbus-3.6.0/src/TasmotaModbus.cpp

Line 206 in 7167884

timeout = millis() + 10;

@Gvico Can you maybe change it to 100ms and retry to read 10+ registers?

Maybe we can make the receiving process not waiting for timeout but waiting for the specified number of bytes to receive (with a longer timeout if an receive error occurs).

[Gvico]

I updated this line (along with line 189 of the same file), it now reliably reads up to 43 registers, which is more than enough for me.
It will timeout if i try to read more though, so waiting for the specified number of bytes seems like a good idea.

[jeroenst]

The 100ms timeout seems fine to me, the code already starts processing the received packet immediately when the nr of bytes expected are received.

@barbudor is it fine to change this timeout to 100ms and make a pull request? I also will fix line 245 and 756 in xdrv_63_modbus_bridge.ino

[jeroenst]

@Gvico Can you try my latest commit in https://github.com/jeroenst/Tasmota?

If it works ok I will create a pull request. Can you maybe also try the using function code 1,2 or 15 to test bitmode? I don't have a setup over here currently to test the code.

[jeroenst]

@TheChatty I remember that we had a long conversation about bitmode while reading coils and inputs, do you have time to check if my changes don't disturb your setup?

[barbudor]

@jeroenst

1. The timeout

The timeout is not on the overall of the message as it is recomputed at every reception so it doesn't make sense to increase it because of larger expected message. This timeout hits when the delay between bytes within the message itself is greater than 10ms.
It could then be adapted to the baudrate. But even at 9600 baud it is equivalent to the duration of 10 bytes.
Why would the meter make a pause of 10 ms within the message ?

I wouldn't go for a possible breaking change before hooking up a scope and having a look at the timing of the message.
Or introduce a setting to allow changing it ?

2. byteCount logic

Beside the timeout problem, I believe there is a problem with that logic here:

Tasmota/tasmota/tasmota_xdrv_driver/xdrv_63_modbus_bridge.ino

Lines 245 to 246 in 7167884

	if (modbusBridge.byteCount == 0) modbusBridge.byteCount = modbusBridge.dataCount * 2;
	buffer = (uint8_t *)malloc(9 + modbusBridge.byteCount); // Addres(1), Function(1), Length(1), Data(1..n), CRC(2)

On a normal execution, you clear modbusBridge.byteCount here:

Tasmota/tasmota/tasmota_xdrv_driver/xdrv_63_modbus_bridge.ino

Line 319 in 7167884

modbusBridge.byteCount = 0;

But you have 2 cases where you could exit the function without clearing it:

Tasmota/tasmota/tasmota_xdrv_driver/xdrv_63_modbus_bridge.ino

Lines 247 to 251 in 7167884

	if (nullptr == buffer)
	{
	ModbusBridgeAllocError(PSTR("read"));
	return;
	}

Tasmota/tasmota/tasmota_xdrv_driver/xdrv_63_modbus_bridge.ino

Lines 312 to 317 in 7167884

	if (error)
	{
	AddLog(LOG_LEVEL_DEBUG, PSTR("MBS: MBR Driver receive error %d"), error);
	free(buffer);
	return;
	}

Which means the next time you reach line 245, modbusBridge.byteCount would not be zero and may not match the current request. Which could lead to a bad allocation size if the request is different
Imagine the scenario:

• A 1st request with 1 register (dataCount = 1 => byteCount = 2) fails because of a tlmeout (meter busy for some reason)
• A 2nd request comes for 10 registers (dataCount = 10 but byteCount is alerady = 2) => bad allocation

So I think that at least byteCount should be clear in every exit of the function (until line 319)

3. dynamic allocation on each request

My experience with embedded system is that dynamic memory allocation creates more problem that it solves as it can create memory fragmentation which is much more critical on small systems that on system that support virtual memory.
Why not allocation the biggest possible buffer (64 registers ? so around 140 bytes) once for all during the driver init. Once it's done, you are safe and you have no risk of further memory allocation problems.

[jeroenst]

@barbudor

1. Possible the device has a hickup during sending back the bytes requested. As @Gvico confirmed, increasing the timeout solves the issue.

2. I will change that but I doubt if that solves the reported bug because if this is creating the issue increasing the timeout wouldn't make a difference, but I'll give it a try.

3. I will change this, my initial thought was that reserving the memory forever would take away memory space for allocation in other functions in Tasmota.

Thank you for helping.

[Gvico]

@jeroenst I tried the commit and it works just fine!
I didn't get an answer using the other function codes, but that's probably because of my setup, i only know the addresses of my holding registers

[jeroenst]

@Gvico can you try my latest commit with all the proposed changes of @barbudor with a 10ms timeout? If the 10ms timeout doesn't solve the problem that was fixed I propose we change it back to 100ms.

[TheChatty]

@jeroenst You are mistaken. I'm using ModBrTCP and mainly holding registers.

I flashed 38af70f and quickly tried to read a single holding register: works. I started TrovisView (the bulk data reading software): it started to connect but after a few seconds it failed - like before. Still need to investigate further with Wireshark when having more free time...

[jeroenst]

I have connected a hardware modbus plc to an esp32.

When I'm done testing I will submit a PR.

[jeroenst]

The new proposed changes of @barbudor work, but the 10ms timeout is still to small to read many registers.

With 10ms timeout I can read up to 12 uint16 registers.
With 20ms I can read 48 uint16 registers.
Using a 100ms timeout doesn't make a difference (on 9600 baud)

I will create a PR with the changes and a 20ms timeout.

[jeroenst]

#18228

[jeroenst]

@arendst This issue can be closed now the solution is merged into development branch