Use after free when Modbus TCP slave responds after response timeout (EPROT-57)

[ivobelitz]

Checklist

• Checked the issue tracker for similar issues to ensure this is not a duplicate
• Read the documentation to confirm the issue is not addressed there and your configuration is set correctly
• Tested with the latest version to ensure the issue hasn't been fixed

How often does this bug occurs?

always

Expected behavior

When a response is received, no matter whether it's after the response timeout, the library should handle it gracefully (I assume drop it)

Actual behavior (suspected bug)

The library tries to write the late response to a buffer that has already been freed when the request timed out, causing heap corruption and a crash

Error logs or terminal output

D (720012) mb_driver: 0x3fcaa04c, node #0, socket(#53)(192.168.2.39), connection lost.
D (720022) mb_driver: 0x3fcaa04c, fd event get: 0x40:0, |MB_EVENT_ERROR
D (720032) mb_driver: 0x3fcaa04c, node: 0, sock: 53, IP:192.168.2.39, check connection timeout = ld, rcv_time: ld 0
D (720032) mb_driver: 0x3fcaa04c, node: 0, sock: 53, IP:192.168.2.39, check connection state, time = ld, rcv_time: ld
D (720042) mb_driver: Node #0 (192.168.2.39), connection error, err=(-11).
W (720052) mb_port.tcp.master: 0x3fcaa04c, node #0, socket(#53)(192.168.2.39), error handling.
E (720062) mb_port.tcp.master: Node: 0, try to repair lost connection, err= -11
D (720072) mb_driver: 0x3fcaa04c, fd event get: 0x04:0, |MB_EVENT_RESOLVE
D (720082) mb_port.tcp.master: loop:0x3fcaa04c  mbm_on_resolve: fd: 0
D (720082) mb_port.tcp.master: 0x3fcaa04c, Node: 0, resolve.
D (720092) port.utils: Check name[IP]: "192.168.2.39"[192.168.2.39]
D (720092) mb_port.tcp.master: 0x3fcaa04c, slave: 0, IP address [192.168.2.39], added to connection list.
D (720102) mb_port.tcp.master: loop:0x3fcaa04c  mbm_on_connect: fd: 0
D (720112) mb_port.tcp.master: 0x3fcaa04c, connection phase, slave: #0(-1) [192.168.2.39].
D (720122) port.utils: Socket(#53)(192.168.2.39) connection is pending, errno 119 (Connection already in progress).
D (720132) mb_port.event: mbm_tcp#0x3fca9534, mb take resource, (300 ticks).
I (720142) mb_port.tcp.master: 0x3fcaa04c, slave: #0, sock:53, IP: 192.168.2.39, is connected.
D (720152) mb_port.tcp.master: Opened/connected: 1, 1.
I (720152) mbc_tcp.master: mb controller connection done.
I (720162) mb_port.tcp.master: 0x3fcaa04c, Connected: 1, 1, start polling.
D (720162) mb_driver: 0x3fcaa04c, fd event get: 0x08:0, |MB_EVENT_CONNECT
D (720172) mb_port.tcp.master: loop:0x3fcaa04c  mbm_on_timeout: fd: 256
D (720182) mb_port.tcp.master: 0x3fcaa04c,  send fd: 0, sock_id: 53[192.168.2.39], 0x3fcc9fa7, len: 12
D (720192) mb_port.tcp.master: loop:0x3fcaa04c  mbm_on_send_data: fd: 0
D (720192) mb_port.tcp.master: 0x3fcaa04c, get info: 0, sock_id: 53, queue_state: 0, state: 6.
D (720202) mb_port.tcp.master: 0x3fcaa04c, node #0, socket(#53)(192.168.2.39), send data successful: TID:0x00b2, 12 (bytes), errno 119
D (720212) mb_port.timer: mbm_tcp#0x3fca9534, respond enable timeout (10000).
D (720222) mb_port.event: mbm_tcp#0x3fca9534, mb_port_event_wait_req_finish: returned event = 0x1
D (720232) mbc_tcp.master: mbc_tcp_master_get_parameter: Bad response to get cid(0) = ESP_ERR_TIMEOUT
E (720242) MB_CONTROLLER_MASTER: mbc_master_get_parameter(131): Master get parameter failure, error=(0x107) (ESP_ERR_TIMEOUT).
D (720262) mb_driver: 0x3fcaa04c, fd event get: 0x10:0, |MB_EVENT_SEND_DATA
D (720322) mb_driver: 0x3fcaa04c, socket event active: lx
D (720322) port.utils: Enqueue data, length=251, TID=0xb2
D (720322) mb_driver: 0x3fcaa04c, node #0, socket(#53)(192.168.2.39), frame received.
D (720322) mb_driver: 0x3fcaa04c, fd event get: 0x20:0, |MB_EVENT_RECV_DATA
D (720332) mb_port.tcp.master: loop:0x3fcaa04c  mbm_on_recv_data: fd: 0
D (720342) mb_port.tcp.master: 0x3fcaa04c, slave #0(53) [192.168.2.39], receive data ready.
D (720352) mb_port.tcp.master: 0x3fcaa04c, packet TID: 0x00b2 received.
D (720352) mb_port.tcp.master: 0x3fcaa04c, node #0, socket(#53)(192.168.2.39), get packet TID: 0x00b2:0x00b3, 0x3fcc842c.
D (720362) mb_port.tcp.master: 0x3fcaa04c, node #0, socket(#53)(192.168.2.39), processing time[us] = ju.
CORRUPT HEAP: Invalid data at 0x3fcca868. Expected 0xfefefefe got 0x6e535375
CORRUPT HEAP: Invalid data at 0x3fcca86c. Expected 0xfefefefe got 0x00410001
CORRUPT HEAP: Invalid data at 0x3fcca870. Expected 0xfefefefe got 0x6c61536f
CORRUPT HEAP: Invalid data at 0x3fcca874. Expected 0xfefefefe got 0x64677245
CORRUPT HEAP: Invalid data at 0x3fcca878. Expected 0xfefefefe got 0x00006520
CORRUPT HEAP: Invalid data at 0x3fcca87c. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca880. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca884. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca888. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca88c. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca890. Expected 0xfefefefe got 0x374b5345
CORRUPT HEAP: Invalid data at 0x3fcca894. Expected 0xfefefefe got 0x57302d52
CORRUPT HEAP: Invalid data at 0x3fcca898. Expected 0xfefefefe got 0x42455445
CORRUPT HEAP: Invalid data at 0x3fcca89c. Expected 0xfefefefe got 0x00004e34
CORRUPT HEAP: Invalid data at 0x3fcca8a0. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca8a4. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca8a8. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca8ac. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca8b0. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca8b4. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca8b8. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca8bc. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca8c0. Expected 0xfefefefe got 0x30343030
CORRUPT HEAP: Invalid data at 0x3fcca8c4. Expected 0xfefefefe got 0x30322e30
CORRUPT HEAP: Invalid data at 0x3fcca8c8. Expected 0xfefefefe got 0x3030342e
CORRUPT HEAP: Invalid data at 0x3fcca8cc. Expected 0xfefefefe got 0x00003232
CORRUPT HEAP: Invalid data at 0x3fcca8d0. Expected 0xfefefefe got 0x30373745
CORRUPT HEAP: Invalid data at 0x3fcca8d4. Expected 0xfefefefe got 0x41434246
CORRUPT HEAP: Invalid data at 0x3fcca8d8. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca8dc. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca8e0. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca8e4. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca8e8. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca8ec. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca8f0. Expected 0xfefefefe got 0x00670001
CORRUPT HEAP: Invalid data at 0x3fcca8f4. Expected 0xfefefefe got 0x00000032
CORRUPT HEAP: Invalid data at 0x3fcca8f8. Expected 0xfefefefe got 0x00000000
CORRUPT HEAP: Invalid data at 0x3fcca8fc. Expected 0xfefefefe got 0xfffe0000
CORRUPT HEAP: Invalid data at 0x3fcca900. Expected 0xfefefefe got 0x08f00007
CORRUPT HEAP: Invalid data at 0x3fcca904. Expected 0xfefefefe got 0x005308f0
CORRUPT HEAP: Invalid data at 0x3fcca908. Expected 0xfefefefe got 0x09410052
CORRUPT HEAP: Invalid data at 0x3fcca90c. Expected 0xfefefefe got 0x0000ffff
CORRUPT HEAP: Invalid data at 0x3fcca910. Expected 0xfefefefe got 0x138e0000
CORRUPT HEAP: Invalid data at 0x3fcca914. Expected 0xfefefefe got 0x0000fffe
CORRUPT HEAP: Invalid data at 0x3fcca918. Expected 0
Guru Meditation Error: Core  0 panic'ed (Interrupt wdt timeout on CPU0).

Steps to reproduce the behavior

1. Set up connection with a Modbus TCP slave that takes more time to respond than the Modbus response timeout

Project release version

2.1.1

System architecture

Intel/AMD 64-bit (modern PC, older Mac)

Operating system

MacOS

Operating system version

26.0.1 Tahoe

Shell

ZSH

Additional context

I imagine the fix would be something along those lines

1. Clear mbm_opts->reg_buffer_ptr and mbm_opts->reg_buffer_size in mbc_tcp_master_send_request after the request finishes / times out
2. Drop frames received in mb_master.c with curr_trans_id=0 (no active transaction)
3. Wrap the access to mbm_opts->reg_buffer_ptr and mbm_opts->reg_buffer_size in esp_modbus_master.c and mbc_tcp_master.c in a critical section

[alisitsyn]

@ivobelitz , thank you for report.

The check for incorrect frame is already in the code of mb_master.c but the handling should be fixed for this case. I see that some incorrect merge was applied to the code on some stage. I will check and fix this situation to handle this properly as per regular process.

The status will be updated here accordingly.