ModbusRTU result: E4, Mem: XXXXX RTU Timeout

[Eduardo-bat]

Hi!

I'm testing the following code as a link between https://sourceforge.net/projects/qmodmaster/ and https://pypi.org/project/pyModSlave/. As hardware, I'm using a NodeMCU 1.0 and a USB/TTL converter.

#include <ESP8266WiFi.h>
#include <ModbusTCP.h>
#include <ModbusRTU.h>

ModbusRTU rtu;
ModbusTCP tcp;

IPAddress srcIp;

uint16_t transRunning = 0;
uint8_t slaveRunning = 0;

uint16_t ModbusBaudRate = 19200;

const char* ssid     = "<SSID>";
const char* password = "<PASSWORD>";

Modbus::ResultCode cbTcpRaw(uint8_t* data, uint8_t len, void* custom) {
  auto src = (Modbus::frame_arg_t*) custom;

  srcIp = src->ipaddr;
  slaveRunning = src->slaveId;
  transRunning = src->transactionId;

  rtu.rawRequest(slaveRunning, data, len);

  return Modbus::EX_SUCCESS;
}

Modbus::ResultCode cbRtuRaw(uint8_t* data, uint8_t len, void* custom) {
  tcp.setTransactionId(transRunning);
  tcp.rawResponce(srcIp, data, len, slaveRunning);

  transRunning = 0;
  slaveRunning = 0;
  srcIp = (0,0,0,0);
  return Modbus::EX_PASSTHROUGH;
}

void setup() {
  WiFi.begin(ssid, password);
  while (WiFi.status() != WL_CONNECTED)
    delay(1000);

  tcp.server();
  tcp.onRaw(cbTcpRaw);

  Serial.begin(ModbusBaudRate, SERIAL_8E1);
  rtu.begin(&Serial);
  rtu.master();
  rtu.onRaw(cbRtuRaw);
}

void loop() {
  rtu.task();
  tcp.task();
  yield();
}

When I make any request from the TCP client, I receive an RTU Timeout.

I've already tried using hard and soft Serial, baudrates of 9600 and 19200 and powering the board with a regulated supply @ 5 V-1 A.

Both programs work normally when I communicate them directly with the ESP, either reading from the RTU slave or receiving reads from the TCP client.

When I use ESP as a bridge, the RTU slave receives the request normally and responds correctly in < 5 ms, but the timeout occurs.

Please, any hint on what to test or what else to investigate? Thanks.

[emelianov]

Probably this will help #298.
Otherwise I'll back later

[Eduardo-bat]

Hi @emelianov. Thank you for the direction. Haven't had time to thoroughly test it yet, but already gotten some promising results. When I get to proceed, I will provide more details.

[Eduardo-bat]

Unfortunately, the problem persists when RTU is connected over a Serial.
By the following code, it seems like the problem happens before the library calls:

#include <ESP8266WiFi.h>

#include <ModbusTCP.h>
#include <ModbusRTU.h>

#include <SoftwareSerial.h>
#include <StreamBuf.h>

#define BSIZE 1024

const unsigned long baudrate = 19200;
const unsigned long chtimeus = (8 + 3) * 1000000 / baudrate;

ModbusRTU rtu;
ModbusTCP tcp;

IPAddress srcIp;

SoftwareSerial debug_serial(D1, D2);

uint8_t serialw_rtur[BSIZE];
uint8_t serialr_rtuw[BSIZE];

StreamBuf serialw_rtur_sb(serialw_rtur, BSIZE);
StreamBuf serialr_rtuw_sb(serialr_rtuw, BSIZE);

DuplexBuf modbus_db(&serialw_rtur_sb, &serialr_rtuw_sb);
DuplexBuf serial_db(&serialr_rtuw_sb, &serialw_rtur_sb);

uint8_t com_buf[BSIZE];
uint8_t log_buf[BSIZE];

StreamBuf com_sbuf(com_buf, BSIZE);
StreamBuf log_sbuf(log_buf, BSIZE);

uint16_t transRunning = 0;
uint8_t slaveRunning = 0;

bool cbRtuTrans(Modbus::ResultCode event, uint16_t transactionId, void* data) {
  if (event != Modbus::EX_SUCCESS) {
    debug_serial.printf("modbusRTU transaction result: %02X\n\r", event);
    transRunning = 0;
  }
  return true;
}

Modbus::ResultCode cbTcpRaw(uint8_t* data, uint8_t len, void* custom) {
  auto src = (Modbus::frame_arg_t*) custom;
  
  debug_serial.print("received a TCP request from ");
  debug_serial.print(IPAddress(src->ipaddr));
  debug_serial.printf("-> Fn: %02X, len: %d\n\r", data[0], len);

  if (transRunning) {
    tcp.setTransactionId(src->transactionId);
    tcp.errorResponce(IPAddress(src->ipaddr), (Modbus::FunctionCode)data[0], Modbus::EX_SLAVE_DEVICE_BUSY);
    return Modbus::EX_SLAVE_DEVICE_BUSY;
  }

  rtu.rawRequest(src->unitId, data, len, cbRtuTrans);
  
  if (!src->unitId) {
    tcp.setTransactionId(src->transactionId);
    tcp.errorResponce(IPAddress(src->ipaddr), (Modbus::FunctionCode)data[0], Modbus::EX_ACKNOWLEDGE);

    transRunning = 0;
    slaveRunning = 0;
    return Modbus::EX_ACKNOWLEDGE;
  }
  
  srcIp = IPAddress(src->ipaddr);
  
  slaveRunning = src->unitId;
  
  transRunning = src->transactionId;
  
  return Modbus::EX_SUCCESS;  
  
}

Modbus::ResultCode cbRtuRaw(uint8_t* data, uint8_t len, void* custom) {
  auto src = (Modbus::frame_arg_t*)custom;
  
  debug_serial.printf("received RTU response from %d-> Fn: %02X, len: %d\n\r", src->slaveId, data[0], len);

  tcp.setTransactionId(transRunning);
  uint16_t succeed = tcp.rawResponce(srcIp, data, len, slaveRunning);
  if (!succeed) {
    debug_serial.print("failed to");
  }

  debug_serial.print("respond to TCP: ");
  debug_serial.println(srcIp);

  transRunning = 0;
  slaveRunning = 0;
  return Modbus::EX_PASSTHROUGH;
}

void print_log(const char *msg) {
  debug_serial.print(msg);
  debug_serial.print(": ");
  while(log_sbuf.available()) {
    debug_serial.print(log_sbuf.read(), HEX);
    debug_serial.print(' ');    
  }
  debug_serial.println();
}

void process_from_to(Stream *from_s, Stream *to_s, unsigned delay_us = 0) {
  while(from_s->available()) {
    
    char c = from_s->read();

    com_sbuf.write(c);
    log_sbuf.write(c);

    if(delay_us != 0)
      delayMicroseconds(delay_us);

  }

  while(com_sbuf.available())
    to_s->write(com_sbuf.read());
}

void setup() {
  Serial.begin(baudrate, SERIAL_8E1);
  debug_serial.begin(baudrate, SWSERIAL_8E1);

  WiFi.begin("<SSID>", "<PASSWORD>");
  while (WiFi.status() != WL_CONNECTED) {
    delay(1000);
    debug_serial.print(".");
  }

  debug_serial.println("");
  debug_serial.println("IP address: ");
  debug_serial.println(WiFi.localIP());

  tcp.server();
  tcp.onRaw(cbTcpRaw);

  rtu.begin((Stream*)&modbus_db);
  rtu.master();
  rtu.onRaw(cbRtuRaw);
}

void loop() {
  rtu.task();
  tcp.task();
  yield();

  if(Serial.available()) {

    process_from_to(&Serial, &serial_db, chtimeus << 1);

    print_log("received response from RTU");

  }

  if(serial_db.available()) {

    process_from_to(&serial_db, &Serial);

    print_log("sent request to RTU");

  }

}

qModMaster has the following configs:

Modbus Mode: TCP

• Slave Addr: 1
• Scan Rate: 5 s
• Function Code: 0x03
• Start Address: 0x00
• Register Number: 10
• Slave IP: my ESP's IP in the network
• Slave Port: 502
• pyModSlave has the following configs:

Modbus Mode: RTU

• Slave Address: 1
• SimCycle: 5 s
• Port: my ESP's Serial's USB port
• Baudrate: 19200
• Data Bits: 8
• Stop Bits: 1
• Parity: None

output from the TCP monitor:

Sys > 08:44:00:433 - Connecting to IP : 192.168.003.165:502 OK
[TCP]>Tx > 08:44:13:640 - 00  01  00  00  00  06  01  03  00  00  00  0A  
Sys > 08:44:14:143 - Error : Timeout
[TCP]>Tx > 08:44:18:641 - 00  02  00  00  00  06  01  03  00  00  00  0A  
[TCP]>Rx > 08:44:18:956 - 00  02  00  00  00  03  FF  83  06  
Sys > 08:44:18:956 - Error : Slave device or server is busy
[TCP]>Tx > 08:44:23:635 - 00  03  00  00  00  06  01  03  00  00  00  0A  
Sys > 08:44:24:147 - Error : Timeout
[TCP]>Tx > 08:44:28:652 - 00  04  00  00  00  06  01  03  00  00  00  0A  
[TCP]>Rx > 08:44:28:883 - 00  04  00  00  00  03  FF  83  06  
Sys > 08:44:28:883 - Error : Slave device or server is busy
[TCP]>Tx > 08:44:33:646 - 00  05  00  00  00  06  01  03  00  00  00  0A  
Sys > 08:44:34:157 - Error : Timeout
[TCP]>Tx > 08:44:38:661 - 00  06  00  00  00  06  01  03  00  00  00  0A  
[TCP]>Rx > 08:44:38:735 - 00  06  00  00  00  03  FF  83  06  
Sys > 08:44:38:736 - Error : Slave device or server is busy
[TCP]>Tx > 08:44:43:667 - 00  07  00  00  00  06  01  03  00  00  00  0A  
Sys > 08:44:44:177 - Error : Timeout
[TCP]>Tx > 08:44:48:667 - 00  08  00  00  00  06  01  03  00  00  00  0A  
[TCP]>Rx > 08:44:48:769 - 00  08  00  00  00  03  FF  83  06  
Sys > 08:44:48:769 - Error : Slave device or server is busy
[TCP]>Tx > 08:44:53:667 - 00  09  00  00  00  06  01  03  00  00  00  0A  
Sys > 08:44:54:174 - Error : Timeout
[TCP]>Tx > 08:44:58:683 - 00  0A  00  00  00  06  01  03  00  00  00  0A  
[TCP]>Rx > 08:44:58:886 - 00  0A  00  00  00  03  FF  83  06  
Sys > 08:44:58:887 - Error : Slave device or server is busy
[TCP]>Tx > 08:45:03:689 - 00  0B  00  00  00  06  01  03  00  00  00  0A  
Sys > 08:45:04:193 - Error : Timeout
[TCP]>Tx > 08:45:08:690 - 00  0C  00  00  00  06  01  03  00  00  00  0A  
[TCP]>Rx > 08:45:08:737 - 00  0C  00  00  00  03  FF  83  06  
Sys > 08:45:08:737 - Error : Slave device or server is busy

output from the RTU monitor:

[RTU]>Rx > 08:44:13:772 - 01 03 00 00 00 0A C5 CD 
[RTU]>Tx > 08:44:13:773 - 01 03 14 2F 0B 03 BF A1 B4 43 51 BE 10 EC D3 36 93 14 AE F3 E7 9C BA F8 08 
[RTU]>Rx > 08:44:23:922 - 01 03 00 00 00 0A C5 CD 
[RTU]>Tx > 08:44:23:923 - 01 03 14 D8 D6 E6 A5 04 8F 43 D6 D0 BC BC 3F 7F B4 D4 3F AC E6 A3 9F D0 3D 
[RTU]>Rx > 08:44:33:740 - 01 03 00 00 00 0A C5 CD 
[RTU]>Tx > 08:44:33:740 - 01 03 14 C6 F4 2E FD EE 13 8C FF C6 2E 8D A8 9F 18 0C 38 34 2D 95 B4 5A 69 
[RTU]>Rx > 08:44:43:770 - 01 03 00 00 00 0A C5 CD 
[RTU]>Tx > 08:44:43:771 - 01 03 14 49 4F 4D E2 61 B3 16 FA B3 12 BA AF 54 32 46 F7 15 CB 0C F2 93 6D 
[RTU]>Rx > 08:44:53:796 - 01 03 00 00 00 0A C5 CD 
[RTU]>Tx > 08:44:53:796 - 01 03 14 FF 61 62 11 19 50 A7 A2 05 D8 B6 38 C7 41 78 A0 EF 8A FC A2 40 6B 
[RTU]>Rx > 08:45:03:834 - 01 03 00 00 00 0A C5 CD 
[RTU]>Tx > 08:45:03:835 - 01 03 14 39 0C BE B0 B6 C0 6A BE F4 40 C6 91 CE 1F 64 CB 50 A4 AB B0 AF 16 

output from debug_serial:

08:44:13.713 -> received a TCP request from 192.168.3.111-> Fn: 03, len: 5
08:44:13.787 -> sent request to RTU: 1 3 0 0 0 A C5 CD 
08:44:13.820 -> received response from RTU: 1 20 D1 69 3 B B4 A8 E5 83 EC 3A D3 46 AE BE 1E A6 C3 8 
08:44:18.755 -> received a TCP request from 192.168.3.111-> Fn: 03, len: 5
08:44:18.787 -> modbusRTU transaction result: E4
08:44:18.787 -> received a TCP request from 192.168.3.111-> Fn: 03, len: 5
08:44:23.888 -> sent request to RTU: 1 3 0 0 0 A C5 CD 
08:44:23.955 -> received response from RTU: 1 20 11 67 E6 69 D0 6C 59 D0 E3 3F D1 D4 62 E6 B4 6 3D 
08:44:28.766 -> received a TCP request from 192.168.3.111-> Fn: 03, len: 5
08:44:28.854 -> modbusRTU transaction result: E4
08:44:28.922 -> received a TCP request from 192.168.3.111-> Fn: 03, len: 5
08:44:33.725 -> sent request to RTU: 1 3 0 0 0 A C5 CD 
08:44:33.764 -> received response from RTU: 1 20 91 F4 A9 EE 22 EC C6 A9 A8 86 C A2 2D 65 9B 95 FF 
08:44:38.708 -> received a TCP request from 192.168.3.111-> Fn: 03, len: 5
08:44:38.741 -> modbusRTU transaction result: E4
08:44:38.787 -> received a TCP request from 192.168.3.111-> Fn: 03, len: 5
08:44:43.786 -> sent request to RTU: 1 3 0 0 0 A C5 CD 
08:44:43.818 -> received response from RTU: 1 20 51 EA 35 E2 58 36 91 B3 22 7B 54 26 D4 15 39 48 93 DB 
08:44:48.734 -> received a TCP request from 192.168.3.111-> Fn: 03, len: 5
08:44:48.802 -> modbusRTU transaction result: E4
08:44:48.802 -> received a TCP request from 192.168.3.111-> Fn: 03, len: 5
08:44:53.796 -> sent request to RTU: 1 3 0 0 0 A C5 CD 
08:44:53.830 -> received response from RTU: 1 20 D1 61 AC 94 50 9A 2B D8 1B 3A 41 81 EF 31 A2 AD 
08:44:58.768 -> received a TCP request from 192.168.3.111-> Fn: 03, len: 5
08:44:58.836 -> modbusRTU transaction result: E4
08:44:58.836 -> received a TCP request from 192.168.3.111-> Fn: 03, len: 5
08:45:03.853 -> sent request to RTU: 1 3 0 0 0 A C5 CD 
08:45:03.885 -> received response from RTU: 1 20 51 62 BE B3 C0 2D A3 40 5C E6 1F D6 E 45 5B B0 CD FC 
08:45:08.723 -> received a TCP request from 192.168.3.111-> Fn: 03, len: 5
08:45:08.770 -> modbusRTU transaction result: E4

[Eduardo-bat]

An external monitor (a Uno with the Rx of a SoftwareSerial connected to the NodeMCU hardware Rx pin) shows that the correct data reaches the ESP:

rtu monitor:

[RTU]>Rx > 18:21:37:626 - 01 03 00 00 00 0A C5 CD 
[RTU]>Tx > 18:21:37:626 - 01 03 14 9D AC D8 0D 61 1A 29 7B 0E 7D 19 15 62 01 C2 F1 9E CF 41 C6 3C D4 
[RTU]>Rx > 18:21:47:674 - 01 03 00 00 00 0A C5 CD 
[RTU]>Tx > 18:21:47:675 - 01 03 14 A7 EE 7E F2 5D 43 66 D7 4B 73 3A 0A D2 B6 23 BB F0 E4 AB D0 CD 9E 
[RTU]>Rx > 18:21:57:590 - 01 03 00 00 00 0A C5 CD 
[RTU]>Tx > 18:21:57:590 - 01 03 14 D0 31 DC 14 E7 A2 84 49 C6 3A 1D 13 BD 7E DD DF E1 C7 02 89 F0 80 
[RTU]>Rx > 18:22:07:638 - 01 03 00 00 00 0A C5 CD 
[RTU]>Tx > 18:22:07:639 - 01 03 14 71 26 FE 5B 12 23 A7 F4 39 0A 55 12 F9 E4 63 27 90 0C 18 11 00 51 
[RTU]>Rx > 18:22:17:682 - 01 03 00 00 00 0A C5 CD 
[RTU]>Tx > 18:22:17:683 - 01 03 14 1C 9D A1 68 11 71 A4 96 1D BF D4 C3 86 B1 B2 42 68 C4 72 BD C6 A3 
[RTU]>Rx > 18:22:27:722 - 01 03 00 00 00 0A C5 CD 
[RTU]>Tx > 18:22:27:724 - 01 03 14 93 6B 28 A4 F2 DD 3D E1 C3 29 61 82 EF CC E3 37 99 AA 32 04 3A 56 

external monitor:

response: 1 3 14 9D AC D8 D 61 1A 29 7B E 7D 19 15 62 1 C2 F1 9E CF 41 C6 3C D4
response: 1 3 14 A7 EE 7E F2 5D 43 66 D7 4B 73 3A A D2 B6 23 BB F0 E4 AB D0 CD 9E
response: 1 3 14 D0 31 DC 14 E7 A2 84 49 C6 3A 1D 13 BD 7E DD DF E1 C7 2 89 F0 80
response: 1 3 14 71 26 FE 5B 12 23 A7 F4 39 A 55 12 F9 E4 63 27 90 C 18 11 0 51
response: 1 3 14 1C 9D A1 68 11 71 A4 96 1D BF D4 C3 86 B1 B2 42 68 C4 72 BD C6 A3
response: 1 3 14 93 6B 28 A4 F2 DD 3D E1 C3 29 61 82 EF CC E3 37 99 AA 32 4 3A 56

bridge monitor:

received a TCP request from 192.168.1.12-> Fn: 03, len: 5
sent request to RTU: 1 3 0 0 0 A C5 CD 
received response from RTU: 1 20 51 C6 C3 D 58 A3 69 39 7D 46 91 5 C2 7C F6 41 1C A2 
received a TCP request from 192.168.1.12-> Fn: 03, len: 5
modbusRTU transaction result: E4

received a TCP request from 192.168.1.12-> Fn: 03, len: 5
sent request to RTU: 1 3 0 0 0 A C5 CD 
received response from RTU: 1 20 D1 73 7E BE 35 99 D7 A9 E9 A 3A DB DA F0 DE D D7 9E 

received a TCP request from 192.168.1.12-> Fn: 03, len: 5
modbusRTU transaction result: E4

received a TCP request from 192.168.1.12-> Fn: 03, len: 5
sent request to RTU: 1 3 0 0 0 A C5 CD 
received response from RTU: 1 20 11 17 E2 14 9E 23 49 9C EA 13 6F 75 DF 78 9C 89 80 
received a TCP request from 192.168.1.12-> Fn: 03, len: 5
modbusRTU transaction result: E4

received a TCP request from 192.168.1.12-> Fn: 03, len: 5
sent request to RTU: 1 3 0 0 0 A C5 CD 
received response from RTU: 1 20 51 99 FE 2B 34 3A F4 4E A1 95 94 E4 AC 12 C6 18 44 51 
received a TCP request from 192.168.1.12-> Fn: 03, len: 5
modbusRTU transaction result: E4

received a TCP request from 192.168.1.12-> Fn: 03, len: 5
sent request to RTU: 1 3 0 0 0 A C5 CD 
received response from RTU: 1 20 11 D4 A1 2B 14 91 96 47 A3 C3 58 93 42 8B 72 6F DC FF 
received a TCP request from 192.168.1.12-> Fn: 03, len: 5
modbusRTU transaction result: E4

received a TCP request from 192.168.1.12-> Fn: 03, len: 5
sent request to RTU: 1 3 0 0 0 A C5 CD 
received response from RTU: 1 20 D1 B6 A1 A4 BE D7 A C3 4A 9 EF 6E 37 66 35 22 3A F5 
received a TCP request from 192.168.1.12-> Fn: 03, len: 5
modbusRTU transaction result: E4