Modbus Serial port timeout for discontinued address poll

[binueda]

Relevant telegraf.conf:

#   ## Connection Configuration
#   ##
#   ## The plugin supports connections to PLCs via MODBUS/TCP or
#   ## via serial line communication in binary (RTU) or readable (ASCII) encoding
#   ##
#   ## Device name
trace_connection = true
close_connection = false
name = "BM"
slave_id = 10
timeout = "3s"
busy_retries =2
busy_retries_wait = "2s"

#   ## Serial (RS485; RS232)
   controller = "file:///dev/ttyAMA0"
   baud_rate = 9600
   data_bits = 8
   parity = "E"
   stop_bits = 1
   transmission_mode = "RTU"

holding_registers = [
        { name = "Watts Total-CH1",     byte_order = "CDAB",   data_type = "FLOAT32-IEEE", scale=1.0,address = [4100,4101]},
        { name = "Watts Total-CH2",     byte_order = "CDAB",   data_type = "FLOAT32-IEEE", scale=1.0,address = [4202,4203]},

   ]

System info:

Ubuntu, linux , arm64

Steps to reproduce:

1. Telegraf modbus module configured to read a serial device /dev/tty*
2. Create holding register address value is not continuous

{ name = "Watts Total-CH1",     byte_order = "CDAB",   data_type = "FLOAT32-IEEE", scale=1.0,address = [4100,4101]},
{ name = "Watts Total-CH2",     byte_order = "CDAB",   data_type = "FLOAT32-IEEE", scale=1.0,address = [4202,4203]},

3. Run the telegraf in debug mode
   --debug log
2021-05-10T19:35:45Z D! [agent] Starting service inputs
2021-05-10T19:35:50Z D! [inputs.modbus] modbus: send 0a 03 10 04 00 02 80 71 <-- First command at 9:35:50
   2021-05-10T19:35:50Z D! [inputs.modbus] modbus: recv 0a 03 04 00 00 00 00 40 f3
2021-05-10T19:35:50Z D! [inputs.modbus] got holding@4100[2]: [0 0 0 0]
2021-05-10T19:35:50Z D! [inputs.modbus] ~CH1 offset 0 with len 4: [0 0 0 0] --> 0 <-- First data received at 9:35:50
   2021-05-10T19:35:50Z D! [inputs.modbus] modbus: send 0a 03 10 6a 00 02 e1 ac <-- Next Command send at 9:35:50
   2021-05-10T19:35:54Z D! [inputs.modbus] modbus: recv
2021-05-10T19:35:54Z E! [inputs.modbus] Error in plugin: serial: timeout <-- timeout received after 3 sec

Expected behavior:

Serial port subsequent command will need a delay from the time data is read.

2021-05-10T19:35:45Z D! [agent] Starting service inputs
2021-05-10T19:35:50Z D! [inputs.modbus] modbus: send 0a 03 10 04 00 02 80 71 <-- First command at 9:35:50
2021-05-10T19:35:50Z D! [inputs.modbus] modbus: recv 0a 03 04 00 00 00 00 40 f3
2021-05-10T19:35:50Z D! [inputs.modbus] got holding@4100[2]: [0 0 0 0]
2021-05-10T19:35:50Z D! [inputs.modbus] ~CH1 offset 0 with len 4: [0 0 0 0] --> 0 <-- First data received at 9:35:50
2021-05-10T19:35:51Z D! [inputs.modbus] modbus: send 0a 03 10 6a 00 02 e1 ac <-- Next Command send at 9:35:51
2021-05-10T19:35:54Z D! [inputs.modbus] modbus: recv 0a 03 04 00 00 00 00 40 f3
2021-05-10T19:35:54Z E! [inputs.modbus] ~CH2 offset 0 with len 4: [0 0 0 0] --> 0 <-- second data received at 9:35:54

Additional info:

Serial poll rate should be greater than 100ms , found in mbpoll
-l # Poll rate in ms, ( > 100, 1000 is default)

Using mbpoll verified command send immediately after the poll completion, generated connection timeout subsequent command respond with data. device may not be ready to receive the next command

root@ubuntu:/etc/telegraf# mbpoll -b 9600 -p even -m rtu -a 10 -r 4201,4203,4205  -t 4:float /dev/ttyAMA0 -1 -v
debug enabled
Set device=/dev/ttyAMA0
mbpoll 1.4-25 - FieldTalk(tm) Modbus(R) Master Simulator
Copyright © 2015-2019 Pascal JEAN, https://github.com/epsilonrt/mbpoll
This program comes with ABSOLUTELY NO WARRANTY.
This is free software, and you are welcome to redistribute it
under certain conditions; type 'mbpoll -w' for details.

Opening /dev/ttyAMA0 at 9600 bauds (E, 8, 1)
Set response timeout to 1 sec, 0 us
Protocol configuration: Modbus RTU
Slave configuration...: address = [10]
                        start reference = [4201,4203,4205]
Communication.........: /dev/ttyAMA0,       9600-8E1
                        t/o 1.00 s, poll rate 1000 ms
Data type.............: 32-bit float (little endian), output (holding) register table

-- Polling slave 10...
[0A][03][10][68][00][02][40][6C]
Waiting for a confirmation...
<0A><03><04><00><00><00><00><40><F3>
[4201]:         0
[0A][03][10][6A][00][02][E1][AC]
Waiting for a confirmation...
ERROR Connection timed out: select
Read output (holding) register failed: Connection timed out
[0A][03][10][6C][00][02][01][AD]
Waiting for a confirmation...
<0A><03><04><00><00><00><00><40><F3>
[4205]:         0

[binueda]

Tested with pause_between_requests = "100ms" with non-consecutive registers and found working perfect 👍

Configuration

trace_connection = true
close_connection = false
name = "BM"
slave_id = 10
timeout = "4s"
pause_between_requests = "100ms"
#   ## Serial (RS485; RS232)
   controller = "file:///dev/ttyAMA0"
   baud_rate = 9600
   data_bits = 8
   parity = "E"
   stop_bits = 1
   transmission_mode = "RTU"
holding_registers = [
        { name = "Watts Total-CH1",     byte_order = "CDAB",   data_type = "FLOAT32-IEEE", scale=1.0,address = [4100,4101]},
        { name = "Total Current-2",       byte_order = "CDAB",   data_type = "FLOAT32-IEEE", scale=1.0,address = [4202,4203]},
   ]

Result

2021-05-11T11:31:49Z D! [agent] Starting service inputs
2021-05-11T11:31:50Z D! [inputs.modbus] modbus: send 0a 03 10 04 00 02 80 71
2021-05-11T11:31:50Z D! [inputs.modbus] modbus: recv 0a 03 04 00 00 00 00 40 f3
2021-05-11T11:31:50Z D! [inputs.modbus] got holding@4100[2]: [0 0 0 0]
2021-05-11T11:31:50Z D! [inputs.modbus]   field Watts Total-CH1 with offset 0 with len 4: [0 0 0 0] --> 0
2021-05-11T11:31:50Z D! [inputs.modbus] modbus: send 0a 03 10 6a 00 02 e1 ac
2021-05-11T11:31:50Z D! [inputs.modbus] modbus: recv 0a 03 04 00 00 00 00 40 f3
2021-05-11T11:31:50Z D! [inputs.modbus] got holding@4202[2]: [0 0 0 0]
2021-05-11T11:31:50Z D! [inputs.modbus]   field Total Current-2 with offset 0 with len 4: [0 0 0 0] --> 0
2021-05-11T11:31:55Z D! [inputs.modbus] modbus: send 0a 03 10 04 00 02 80 71
2021-05-11T11:31:55Z D! [inputs.modbus] modbus: recv 0a 03 04 00 00 00 00 40 f3
2021-05-11T11:31:55Z D! [inputs.modbus] got holding@4100[2]: [0 0 0 0]
2021-05-11T11:31:55Z D! [inputs.modbus]   field Watts Total-CH1 with offset 0 with len 4: [0 0 0 0] --> 0
2021-05-11T11:31:55Z D! [inputs.modbus] modbus: send 0a 03 10 6a 00 02 e1 ac
2021-05-11T11:31:55Z D! [inputs.modbus] modbus: recv 0a 03 04 00 00 00 00 40 f3
2021-05-11T11:31:55Z D! [inputs.modbus] got holding@4202[2]: [0 0 0 0]
2021-05-11T11:31:55Z D! [inputs.modbus]   field Total Current-2 with offset 0 with len 4: [0 0 0 0] --> 0
2021-05-11T11:31:59Z D! [outputs.file] Wrote batch of 2 metrics in 615.843µs
2021-05-11T11:31:59Z D! [outputs.file] Buffer fullness: 0 / 10000 metrics
2021-05-11T11:32:00Z D! [inputs.modbus] modbus: send 0a 03 10 04 00 02 80 71
2021-05-11T11:32:00Z D! [inputs.modbus] modbus: recv 0a 03 04 00 00 00 00 40 f3
2021-05-11T11:32:00Z D! [inputs.modbus] got holding@4100[2]: [0 0 0 0]
2021-05-11T11:32:00Z D! [inputs.modbus]   field Watts Total-CH1 with offset 0 with len 4: [0 0 0 0] --> 0
2021-05-11T11:32:00Z D! [inputs.modbus] modbus: send 0a 03 10 6a 00 02 e1 ac
2021-05-11T11:32:00Z D! [inputs.modbus] modbus: recv 0a 03 04 00 00 00 00 40 f3
2021-05-11T11:32:00Z D! [inputs.modbus] got holding@4202[2]: [0 0 0 0]
2021-05-11T11:32:00Z D! [inputs.modbus]   field Total Current-2 with offset 0 with len 4: [0 0 0 0] --> 0
2021-05-11T11:32:05Z D! [inputs.modbus] modbus: send 0a 03 10 04 00 02 80 71
2021-05-11T11:32:05Z D! [inputs.modbus] modbus: recv 0a 03 04 00 00 00 00 40 f3
2021-05-11T11:32:05Z D! [inputs.modbus] got holding@4100[2]: [0 0 0 0]
2021-05-11T11:32:05Z D! [inputs.modbus]   field Watts Total-CH1 with offset 0 with len 4: [0 0 0 0] --> 0
2021-05-11T11:32:05Z D! [inputs.modbus] modbus: send 0a 03 10 6a 00 02 e1 ac
2021-05-11T11:32:05Z D! [inputs.modbus] modbus: recv 0a 03 04 00 00 00 00 40 f3
2021-05-11T11:32:05Z D! [inputs.modbus] got holding@4202[2]: [0 0 0 0]
2021-05-11T11:32:05Z D! [inputs.modbus]   field Total Current-2 with offset 0 with len 4: [0 0 0 0] --> 0

[binueda]

This function is tested

[srebhan]

@binueda please only close this issue after the PR has been merged and you tested with the master branch. Otherwise it might look like the issue no longer exists and the pressure to merge the PR is reduced. ;-) Furthermore, other people experiencing the same issue will think it should work already. Will reopen. :-)

[binueda]

Got it, will keep it open