search

pymodbus-dev / pymodbus

A full modbus protocol written in python
Other
2.16k stars 889 forks source link

`ModbusSerialClient` does not handle `termios.error` on `connect` #2124

Closed farzadpanahi closed 3 months ago

farzadpanahi commented 3 months ago

Versions

Pymodbus Specific

Description

I am trying to open a serial port using ModbusSerialClient, using invalid connection settings (provided by the user) for instance bytesize=6. In this case, connect method in serial.py fails because the following exception is raised from pyserial:

  File "/home/pi/repos/test/venv/lib/python3.9/site-packages/pymodbus/client/serial.py", line 219, in connect
    self.socket.inter_byte_timeout = self.inter_byte_timeout
  File "/home/pi/repos/test/venv/lib/python3.9/site-packages/serial/serialutil.py", line 412, in inter_byte_timeout
    self._reconfigure_port()
  File "/home/pi/repos/test/venv/lib/python3.9/site-packages/serial/serialposix.py", line 517, in _reconfigure_port
    termios.tcsetattr(
termios.error: (22, 'Invalid argument')

The problem is that unlike serial.SerialException, termios.error is not handled in the connect method. 

    def connect(self):
        """Connect to the modbus serial server."""
        if self.socket:
            return True
        try:
            self.socket = serial.serial_for_url(
                self.comm_params.host,
                timeout=self.comm_params.timeout_connect,
                bytesize=self.comm_params.bytesize,
                stopbits=self.comm_params.stopbits,
                baudrate=self.comm_params.baudrate,
                parity=self.comm_params.parity,
                exclusive=True,
            )
            if self.strict:
                self.socket.inter_byte_timeout = self.inter_byte_timeout
            self.last_frame_end = None
        except serial.SerialException as msg:
            Log.error("{}", msg)
            self.close()
        return self.socket is not None

Because of this, the connection will not be closed properly and when I try to open the serial port again (with correct connection settings), I will get the following error:

ERROR:pymodbus.logging:[Errno 11] Could not exclusively lock port /dev/ttyS0: [Errno 11] Resource temporarily unavailable

Expected Behavior

I think ModbusSerialClient should also handle termios.error on connect and close the connection properly.

Code

The following code does the following:

  1. Attempt 1: Tries to open serial connection with wrong connection settings and fails. But it wraps ModbusSerialClient in try-catch and will explicitly close the connection when termios.error is caught
  2. Attempt 2: Tries to open serial connection with correct connection settings after the previous connection had failed, and succeeds because serial port has been closed properly in the previous attempt.
  3. Attempt 3: Tries to open serial connection with wrong connection settings and fails, but does not close the connection (just uses with without explicit try-catch).
  4. Attempt 4: Tries to open serial connection with correct connection settings after the previous connection had failed, and fails because serial port has not been closed properly in the previous attempt.

Notes:

  1. I could not reproduce the exact same behavior on x86. The error can be reproduced consistently on Raspberry Pi 4.
  2. There is no Modbus device connected to the serial port. That's why we see Modbus Error: [Input/Output] Modbus Error: [Invalid Message] No response received, expected at least 4 bytes (0 received). The intention is to just test the serial port not to actually read from a device.
import logging
import termios

import pymodbus
from pymodbus.client import ModbusSerialClient

logging.basicConfig(level=logging.INFO)
pymodbus.pymodbus_apply_logging_config("DEBUG")

port = '/dev/ttyS0'
baudrate = 9600
parity = 'N'
stopbits = 1
method = 'rtu'
bytesize = None
attempt = 0

def connect_using_with(attempt, method, port, baudrate, parity, stopbits, bytesize):
    logging.info('---------------------------------------------------------')
    logging.info(f'connection attempt {attempt} ...')
    try:
        logging.info(f'connection settings: method={method}, port={port}, baudrate={baudrate}, parity={parity}, stopbits={stopbits}, bytesize={bytesize}')
        with ModbusSerialClient(method=method, port=port, baudrate=baudrate, parity=parity, stopbits=stopbits, bytesize=bytesize) as client:
            logging.info(client)
            rr = client.read_coils(1, 1, slave=1)
            logging.info(f'results for atttempt {attempt}={rr}')
            logging.info(f'connection attempt {attempt} susccessful :)')
    except termios.error as e:
        logging.error(f'connection attempt {attempt} failed :(')
        logging.exception(f'termios error: {e}')

def connect_using_try_catch_close(attempt, method, port, baudrate, parity, stopbits, bytesize):
    logging.info('---------------------------------------------------------')
    logging.info(f'connection attempt {attempt} ...')
    try:
        logging.info(f'connection settings: method={method}, port={port}, baudrate={baudrate}, parity={parity}, stopbits={stopbits}, bytesize={bytesize}')
        client = ModbusSerialClient(method=method, port=port, baudrate=baudrate, parity=parity, stopbits=stopbits, bytesize=bytesize)
        client.connect()
        logging.info(client)
        rr = client.read_coils(1, 1, slave=1)
        logging.info(f'results for atttempt {attempt}={rr}')
        logging.info(f'connection attempt {attempt} susccessful :)')
    except termios.error as e:
        logging.error(f'connection attempt {attempt} failed :(')
        logging.exception(f'termios error: {e}')
        client.close()  # <-- explictly closing on failure
        logging.info(f'connection closed')

# attempt 1 should fail because bytesize 6 is invalid
attempt +=1 
bytesize = 6
connect_using_try_catch_close(attempt=attempt, method=method, port=port, baudrate=baudrate, parity=parity, stopbits=stopbits, bytesize=bytesize)

# attempt 2 should succeed because bytesize 8 is valid and previous connection is properly closed
attempt +=1 
bytesize = 8
connect_using_with(attempt=attempt, method=method, port=port, baudrate=baudrate, parity=parity, stopbits=stopbits, bytesize=bytesize)

# attempt 3 should fail because bytesize 6 is invalid 
attempt +=1 
bytesize = 6
connect_using_with(attempt=attempt, method=method, port=port, baudrate=baudrate, parity=parity, stopbits=stopbits, bytesize=bytesize)

# attempt 4 should fail because even bytesize 8 is valid previous connection is not properly closed
attempt +=1 
bytesize = 8
connect_using_with(attempt=attempt, method=method, port=port, baudrate=baudrate, parity=parity, stopbits=stopbits, bytesize=bytesize)

Logs

INFO:root:---------------------------------------------------------
INFO:root:connection attempt 1 ...
INFO:root:connection settings: method=rtu, port=/dev/ttyS0, baudrate=9600, parity=N, stopbits=1, bytesize=6
ERROR:root:connection attempt 1 failed :(
ERROR:root:termios error: (22, 'Invalid argument')
Traceback (most recent call last):
  File "/home/pi/repos/test/pymod.py", line 40, in connect_using_try_catch_close
    client.connect()
  File "/home/pi/repos/test/venv/lib/python3.9/site-packages/pymodbus/client/serial.py", line 209, in connect
    self.socket = serial.serial_for_url(
  File "/home/pi/repos/test/venv/lib/python3.9/site-packages/serial/__init__.py", line 90, in serial_for_url
    instance.open()
  File "/home/pi/repos/test/venv/lib/python3.9/site-packages/serial/serialposix.py", line 332, in open
    self._reconfigure_port(force_update=True)
  File "/home/pi/repos/test/venv/lib/python3.9/site-packages/serial/serialposix.py", line 517, in _reconfigure_port
    termios.tcsetattr(
termios.error: (22, 'Invalid argument')
INFO:root:connection closed
INFO:root:---------------------------------------------------------
INFO:root:connection attempt 2 ...
INFO:root:connection settings: method=rtu, port=/dev/ttyS0, baudrate=9600, parity=N, stopbits=1, bytesize=8
INFO:root:ModbusSerialClient /dev/ttyS0:0
2024-03-27 20:33:00,533 DEBUG logging:103 Current transaction state - IDLE
DEBUG:pymodbus.logging:Current transaction state - IDLE
2024-03-27 20:33:00,534 DEBUG logging:103 Running transaction 1
DEBUG:pymodbus.logging:Running transaction 1
2024-03-27 20:33:00,534 DEBUG logging:103 SEND: 0x1 0x1 0x0 0x1 0x0 0x1 0xac 0xa
DEBUG:pymodbus.logging:SEND: 0x1 0x1 0x0 0x1 0x0 0x1 0xac 0xa
2024-03-27 20:33:00,534 DEBUG logging:103 Resetting frame - Current Frame in buffer - 
DEBUG:pymodbus.logging:Resetting frame - Current Frame in buffer - 
2024-03-27 20:33:00,535 DEBUG logging:103 New Transaction state "SENDING"
DEBUG:pymodbus.logging:New Transaction state "SENDING"
2024-03-27 20:33:00,535 DEBUG logging:103 Changing transaction state from "SENDING" to "WAITING FOR REPLY"
DEBUG:pymodbus.logging:Changing transaction state from "SENDING" to "WAITING FOR REPLY"
2024-03-27 20:33:06,539 DEBUG logging:103 Transaction failed. (Modbus Error: [Invalid Message] No response received, expected at least 4 bytes (0 received)) 
DEBUG:pymodbus.logging:Transaction failed. (Modbus Error: [Invalid Message] No response received, expected at least 4 bytes (0 received)) 
2024-03-27 20:33:06,540 DEBUG logging:103 Processing: 
DEBUG:pymodbus.logging:Processing: 
2024-03-27 20:33:06,540 DEBUG logging:103 Getting transaction 1
DEBUG:pymodbus.logging:Getting transaction 1
2024-03-27 20:33:06,541 DEBUG logging:103 Changing transaction state from "PROCESSING REPLY" to "TRANSACTION_COMPLETE"
DEBUG:pymodbus.logging:Changing transaction state from "PROCESSING REPLY" to "TRANSACTION_COMPLETE"
INFO:root:results for atttempt 2=Modbus Error: [Input/Output] Modbus Error: [Invalid Message] No response received, expected at least 4 bytes (0 received)
INFO:root:connection attempt 2 susccessful :)
INFO:root:---------------------------------------------------------
INFO:root:connection attempt 3 ...
INFO:root:connection settings: method=rtu, port=/dev/ttyS0, baudrate=9600, parity=N, stopbits=1, bytesize=6
ERROR:root:connection attempt 3 failed :(
ERROR:root:termios error: (22, 'Invalid argument')
Traceback (most recent call last):
  File "/home/pi/repos/test/pymod.py", line 23, in connect_using_with
    with ModbusSerialClient(method=method, port=port, baudrate=baudrate, parity=parity, stopbits=stopbits, bytesize=bytesize) as client:
  File "/home/pi/repos/test/venv/lib/python3.9/site-packages/pymodbus/client/base.py", line 438, in __enter__
    self.connect()
  File "/home/pi/repos/test/venv/lib/python3.9/site-packages/pymodbus/client/serial.py", line 219, in connect
    self.socket.inter_byte_timeout = self.inter_byte_timeout
  File "/home/pi/repos/test/venv/lib/python3.9/site-packages/serial/serialutil.py", line 412, in inter_byte_timeout
    self._reconfigure_port()
  File "/home/pi/repos/test/venv/lib/python3.9/site-packages/serial/serialposix.py", line 517, in _reconfigure_port
    termios.tcsetattr(
termios.error: (22, 'Invalid argument')
INFO:root:---------------------------------------------------------
INFO:root:connection attempt 4 ...
INFO:root:connection settings: method=rtu, port=/dev/ttyS0, baudrate=9600, parity=N, stopbits=1, bytesize=8
2024-03-27 20:33:06,549 ERROR logging:115 [Errno 11] Could not exclusively lock port /dev/ttyS0: [Errno 11] Resource temporarily unavailable
ERROR:pymodbus.logging:[Errno 11] Could not exclusively lock port /dev/ttyS0: [Errno 11] Resource temporarily unavailable
INFO:root:ModbusSerialClient /dev/ttyS0:0
2024-03-27 20:33:06,549 ERROR logging:115 [Errno 11] Could not exclusively lock port /dev/ttyS0: [Errno 11] Resource temporarily unavailable
ERROR:pymodbus.logging:[Errno 11] Could not exclusively lock port /dev/ttyS0: [Errno 11] Resource temporarily unavailable
Traceback (most recent call last):
  File "/home/pi/repos/test/pymod.py", line 69, in <module>
    connect_using_with(attempt=attempt, method=method, port=port, baudrate=baudrate, parity=parity, stopbits=stopbits, bytesize=bytesize)
  File "/home/pi/repos/test/pymod.py", line 25, in connect_using_with
    rr = client.read_coils(1, 1, slave=1)
  File "/home/pi/repos/test/venv/lib/python3.9/site-packages/pymodbus/client/mixin.py", line 77, in read_coils
    return self.execute(
  File "/home/pi/repos/test/venv/lib/python3.9/site-packages/pymodbus/client/base.py", line 391, in execute
    raise ConnectionException(f"Failed to connect[{self!s}]")
pymodbus.exceptions.ConnectionException: Modbus Error: [Connection] Failed to connect[ModbusSerialClient /dev/ttyS0:0]
janiversen commented 3 months ago

Pyserial is sadly enough no longer maintained and the termios exception is not documented.

I will take a look and see if we easily can add a try/expect.

janiversen commented 3 months ago

2125 solves the problem, it is merged on dev.

Just as a sidetone, bytesize=6 is legal for serial communication (not for modbus though), so it might be you have a hardware problem on top of this problem.