If optimize for performance in menuconfig, modbus failed on incomplete message (IDFGH-2371) #4499
Comments
github-actions
bot
changed the title
|
After compare log, I found that ESP32 reboot +1 then optimize for size. |
|
Hi @keelung-yang, |
|
How the Modbus UART pins configured in your project? I see that your console is configured to use GPIO 18 and 23 which are used for Modbus UART by default. |
|
@alisitsyn Here is pin configure & relevant code: #define MB_PORT_NUM (UART_NUM_0)
#define MB_DEV_ADDR (1)
#define MB_DEV_SPEED (230400)
#define MB_UART_TXD (1)
#define MB_UART_RXD (3)
void dmodbus_start()
{
mbc_slave_init(MB_PORT_SERIAL_SLAVE, &mbc_slave_handler);
mb_communication_info_t comm_info;
ESP_ERROR_CHECK(uart_set_pin(MB_PORT_NUM, MB_UART_TXD, MB_UART_RXD,
UART_PIN_NO_CHANGE, UART_PIN_NO_CHANGE));
comm_info.mode = MB_MODE_RTU;
comm_info.slave_addr = MB_DEV_ADDR;
comm_info.port = MB_PORT_NUM;
comm_info.baudrate = MB_DEV_SPEED;
comm_info.parity = MB_PARITY_NONE;
ESP_ERROR_CHECK(mbc_slave_setup((void*)&comm_info));
mb_register_area_descriptor_t reg_area;
reg_area.type = MB_PARAM_HOLDING;
reg_area.start_offset = MB_DIAG_MB_START;
reg_area.address = (void*)&diag_mb;
reg_area.size = sizeof(diag_mb);
ESP_ERROR_CHECK(mbc_slave_set_descriptor(reg_area));
ESP_ERROR_CHECK(mbc_slave_start());
ESP_ERROR_CHECK(uart_set_mode(MB_PORT_NUM, UART_MODE_UART));
}
void dmodbus_print_regs()
{
uint32_t can = (uint32_t)((uint8_t*)diag_mb.can);
uint32_t ecu = (uint32_t)((uint8_t*)diag_mb.ecu);
uint32_t frame = (uint32_t)((uint8_t*)diag_mb.frame);
uint32_t ftx = (uint32_t)((uint8_t*)&diag_mb.ftx);
uint32_t trace = (uint32_t)((uint8_t*)&diag_mb.trace);
uint32_t sim = (uint32_t)((uint8_t*)&diag_mb.sim);
uint32_t count = \
MB_DIAG_CAN_COUNT + \
MB_DIAG_ECU_COUNT + \
MB_DIAG_FRAME_COUNT + \
1 + 1 + 1;
printf(\
"\nModbus Register Address:\n" \
"--------------------------------------\n" \
"\tcan:\t%04X\t%4d\t%4d\n" \
"\tecu:\t%04X\t%4d\t%4d\n" \
"\tdiag:\t%04X\t%4d\t%4d\n" \
"\tftx:\t%04X\t%4d\t%4d\n" \
"\ttrace:\t%04X\t%4d\t%4d\n" \
" + sim:\t%04X\t%4d\t%4d\n" \
"--------------------------------------\n" \
"\t\t\t%4d\t%4d\n\n" \
"Available memory: %18d\n\n", \
(can - can) / 2, MB_DIAG_CAN_COUNT, MB_DIAG_CAN_COUNT * sizeof(diag_can_t),
(ecu - can) / 2, MB_DIAG_ECU_COUNT, MB_DIAG_ECU_COUNT * sizeof(diag_ecu_t),
(frame - can) / 2, MB_DIAG_FRAME_COUNT, MB_DIAG_FRAME_COUNT * sizeof(diag_frame_t),
(ftx - can) / 2, 1, sizeof(diag_ftx_t),
(trace - can) / 2, 1, sizeof(diag_trace_t),
(sim - can) / 2, 1, sizeof(diag_sim_t),
count, sizeof(diag_mb), esp_get_free_heap_size()
);
}
void dmodbus_loop(bool cantp_started)
{
dmodbus_print_regs();
while (true) {
mb_event_group_t ev_filter = MB_EVENT_HOLDING_REG_RD | MB_EVENT_HOLDING_REG_WR;
mb_event_group_t event = mbc_slave_check_event(ev_filter);
mb_param_info_t reg_info;
ESP_ERROR_CHECK(mbc_slave_get_param_info(®_info, MB_PAR_INFO_GET_TIMEOUT));
dmodbus_log_register(event, ®_info);
if (event & MB_EVENT_HOLDING_REG_RD) {
continue;
}
else if (event & MB_EVENT_HOLDING_REG_WR) {
if (reg_info.address == (uint8_t*)&diag_mb.frame) {
dmodbus_frame(&diag_mb.frame[0]);
}
else if (reg_info.address == (uint8_t*)&diag_mb.can) {
if (cantp_started)
cantp_stop();
dmodbus_can(&diag_mb.can[0]);
cantp_started = cantp_start(diag_mb.ecu[0].rxid) == 0;
}
...
void app_main()
{
esp_log_level_set(LOG_TAG, ESP_LOG_INFO);
led_setup();
led_blink(LED_MD_SYS, LED_FREQ_RUNNING);
led_on(LED_MD_DIAG);
bool cantp_started = false;
bool sd_ready = sd_connect() == 0;
if (sd_ready)
cantp_started = sd_download();
else
ESP_LOGW(LOG_TAG, "SD Card is not ready");
led_on(LED_MD_SYS);
dmodbus_start();
dmodbus_loop(cantp_started);
dmodbus_stop();
} |
|
@keelung-yang, |
|
@alisitsyn |
|
@keelung-yang, |
|
@alisitsyn |
|
@alisitsyn I rewrite the test script and modified some c source posted in yesterday. |
|
@keelung-yang, |
|
@alisitsyn Sorry. I cann't generate core dump: I set core dump to UART in menuconfig, but got an error: No core dump partition found at boot time. Even running test.py -n 57, ESP32 rebooted but not dumped |
|
@keelung-yang, |
|
@alisitsyn import minimalmodbus as minimd
client = minimd.Instrument('COM32', 1) # port name, slave address
client.serial.baudrate = 230400
addr = 0
count = 56 # 55 works, 56 failed
print('Read: ', client.read_registers(addr, count))
client.write_registers(addr, [0x1234] * count)
print('Read: ', client.read_registers(addr, count))Read: [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, 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]
Traceback (most recent call last):
File "C:\Users\jyang37\Desktop\test_minimd.py", line 9, in <module>
client.write_registers(0, [0x1234] * count)
File "C:\Python\lib\site-packages\minimalmodbus.py", line 895, in write_registers
self._generic_command(
File "C:\Python\lib\site-packages\minimalmodbus.py", line 1170, in _generic_command
payload_from_slave = self._perform_command(functioncode, payload_to_slave)
File "C:\Python\lib\site-packages\minimalmodbus.py", line 1240, in _perform_command
response = self._communicate(request, number_of_bytes_to_read)
File "C:\Python\lib\site-packages\minimalmodbus.py", line 1406, in _communicate
raise NoResponseError("No communication with the instrument (no answer)")
minimalmodbus.NoResponseError: No communication with the instrument (no answer)Please note, both pymodbus and minimalmodbus are using pyserial as serial port backend. I also tried pyserial v3.4 and master branch v3.4.1, both of them failed too. I checked modbus-tk and umodbus, they also use pyserial. Now, there are some doubtful points:
For CP210x driver, there are some official ESP32 boards using FTDI USB chip, but I've no such board. |
|
@alisitsyn |
|
@keelung-yang, |
|
Hi @keelung-yang, Sorry for late response. I investigated the issue and have some results. Let me explain finding step by step.
Please let me know if you have any questions. |
|
@alisitsyn Thanks for your digging! I'm in Chinese New Year holidays now, and will try it once back into office after 10 days. |
|
@alisitsyn Sorry for delayed validation, my holidays extended by coronavirus outbreak. The patch works now, and improved our ECU download speed from 2.8 to 3.3KB/s. THANKS for your digging again! |
|
@keelung-yang, |
|
@alisitsyn Seems we back to starting point in this issue's title:
I noticed freemodbus long buffer issue has been fixed and merged into master , and I tested it on master branch today, it works now. But the optimize for performance issue still exists, optimize for size works. C:\dev\esp\bootloader\test\modbus>test.py -p COM4
Namespace(addr=0, baudrate=230400, data=4660, n=56, port='COM4', strict=False, unit=1)
Write Error: Modbus Error: [Input/Output] Modbus Error: [Invalid Message] Incomplete message received, expected at least 2 bytes (0 received)
Read Error: Modbus Error: [Input/Output] No Response received from the remote unit/Unable to decode response |
|
@keelung-yang, |
|
Could you also try to reproduce the issue on your side with original examples (do not modify console output pins)? If it exists, please send me extended modbus logs. |
|
@alisitsyn If set log output level to Debug, my board reboot again and again, even if I changed uart pins from tx(1) / rx(3) to tx(25) / rx(26). Here are log outputs and updated sdkconfig(enable static allocation) since #5046 cause compiling problem. I'll try original example ASAP. sdkconfig.txt |
|
There is critical exception when your boards start. The only coredump output in the log that can be useful.
|
|
@alisitsyn Here is coredump output for my app: coredump.txt For original example, if no any change and disconnect all devices except USB cable from my board, idf -p COM4 flash monitor seems OK. And BTW, I'm using ESP32-PICO-KIT V4.1, if you cann't reproduce it, trying same board please. |
|
I have exactly the same board and do not have any issues when debugging is enabled. |
|
But unstable in #5050 if blocksize == 1000 and optimize for performance, after applying this patch. It's weird. I'm trying back to status in last week, no error output in #5050. so I reset this patch, and optimize for size in menuconfig, but still get error randomly. 10 blocksize=1000 baudrate=115200 bps=78058.70 upto=67.76% 9.8 KB/s
11 Error
12 Error
20 blocksize=1000 baudrate=115200 bps=78267.54 upto=67.94% 9.8 KB/s
21 Error
22 Error
23 Error
30 blocksize=1000 baudrate=115200 bps=78424.12 upto=68.08% 9.8 KB/s
40 blocksize=1000 baudrate=115200 bps=78359.66 upto=68.02% 9.8 KB/s
50 blocksize=1000 baudrate=115200 bps=78602.23 upto=68.23% 9.8 KB/s
51 Error
52 Error |
|
@keelung-yang,
|
|
@alisitsyn I'll check the fourth if I have enough time. |
|
I checked the fix as per option four with optimization for performance. It works for some time then starts failing: 31:(c3,1b) - means two different bytes at index 31 of data array when compare sent and received data of echo example. Data from 0 up to 30 is the same. For this fix the bytes (one or two) are inserted in the middle of packet that looks like known hardware issue with reading the RXFIFO through the AHB address. I saw the same behavior before appying the fix but the duplicated byte was inserted in FIFO at index 0 when read FIFO using DPORT. The patch is attached: |
|
@alisitsyn Maybe there are something about Windows 10 version: On my home computer win10 1909, I got almost same results, 5.0x KB/s, before and after applying your patch. But on my work computer, before applying your patch, there is 4.0 KB/s. I'll check it's OS version tomorrow, it's older then 1909. UpdateIt's win10 1809 on my work computer. |
|
It can be dependent of Windows serial driver when you use communication over USB bridge. I think it is more important to solve Errors during communication. I will let you know when have new information related to this topic but its cause is rare enough. Thanks for update. |
|
@alisitsyn I bought a new ESP32 board ESP-WROVER-KIT V4.1, which using FTDI FT2232HL chip as USB bridge. And benchmarked it as in #5050 once it arrived today. But no obvious improvement. So maybe it's not about windows serial driver since wrover board is using a different USB bridge chip. I agree solving errors is more important then improving performance, whether developing drivers or apps. But our aplication is aware of performance: we use esp32 to download ECU by CAN bus on vehicle, the battery in both notebook computer and vehicle are limited. For example, need about 10 minutes to download a 5MB S-Record file, only 3~4KB/s on 500kbps CAN bus, and UART communication takes too more time. |
|
@keelung-yang,
|
|
@alisitsyn I don't think it's solved. UART_ISR_IN_IRAM cann't enable on latest master. And there are still some failed cases without UART_ISR_IN_IRAM. If you doubt Windows driver, you can bypass ESP32 board by shorting Tx/Rx pins, and then run test script without any modifying. Hear are my test results:
|
Do you have issues with the uart_echo example crashes when CONFIG_UART_ISR_IN_IRAM is set? In my case it crashes and increasing the stack usStackDepth for the echo_task helps. Please clarify what kind of issue you have with the setting of CONFIG_UART_ISR_IN_IRAM. On my side it can be set and works without failures after solving the above issue. |
|
@alisitsyn Yes. It's crashing. Here are my settings & log |
|
Is there any update? This reoccurable issue have been fired almost half a year. |
|
This issue is closed. In order to track progress appropriately please open new separate issue for this. Thanks. |
|
@alisitsyn But why? It's not solved. |
|
The issue you mentioned is about uart-echo example and uart driver in master branch. It is not about freemodbus component itself and I propose to open new issue. |
|
@alisitsyn OK then. I'll split it into uart and freemodbus issues, and rewrite reoccurable scripts/steps/setting ... on master branch, once it updated in this week. |
|
Ok. Thanks. |
|
Hi @keelung-yang, |
|
Hi @keelung-yang, The fixes for issues discussed here have been merged. Could you check it on your side? In case it still exists please reopen separate issues against UART performance, freemodbus or something else. Thanks. |
|
@alisitsyn Optimizing for performance setting has no infinite reboot loop now on my board. But sending modbus message still get incomplete message in PyModbus (board rebooted I guess). I'm not sure whether the cause is in my app or esp-idf. I think I need to reproduce it on official examples before firing a new issue, but I'm on other projects in full-time. I'll dig this once released from other projects. If reproducable issuse still exists then I'll fire a new issue. Thank you very very much! |
|
I will try to reproduce your issue on my side little bit later. I will be waiting for your test results as well. Thank you for your feedback and feel free to open new issues. |
|
@alisitsyn I tried on my simplified modbus test app. It still failed on optimizing for performance setting. C:\dev\esp\PicoBox\test\modbus>test.py -p COM5
Namespace(addr=0, baudrate=230400, data=4660, n=56, port='COM5', strict=False, unit=1)
Write Error: Modbus Error: [Input/Output] Modbus Error: [Invalid Message] Incomplete message received, expected at least 2 bytes (0 received)
Read Error: Modbus Error: [Input/Output] No Response received from the remote unit/Unable to decode responseAs shown in output of |
|
Thank you for information. I was able to reproduce this. The issue is related to side effects when access FIFOs. The required fix for this was dropped from my MR because it was implemented in updated version of 2020r2 toolchain (compiler inserts memw instrruction as it was in patch above). |
|
Update for the issue: The bug happens only when CONFIG_ESP32_DEFAULT_CPU_FREQ_240=y and CONFIG_COMPILER_OPTIMIZATION_PERF=y, otherwise the UART works just fine. |
|
@alisitsyn I've test This one line patch works! THANKS! |
|
@keelung-yang, |
|
The uart fix is in 3a51584, maybe this issue should be closed? |
|
Thanks for reporting and sharing the notes @AxelLin , feel free to reopen. |
On latest master.
Optimize for size works, but if set to Optimize for performance, I got:
Just change sdkconfig, no source code modified.
I'm using baudrate 230400, and I tried 115200 but still failed on the same error.
ModbusSerialClient(strict=False or True) also have no effect.
Here is my test script in Python3(>=3.6):
sdkconfig and esp32 debug log also attached:
SDKConfig & Log.zip
The text was updated successfully, but these errors were encountered: