search

tiagocoutinho / modbus-proxy

Connect multiple clients to modbus devices
Other
71 stars 13 forks source link

Modbus Proxy with Huawei SUN2000 #4

Closed javierin closed 2 years ago

javierin commented 2 years ago

Description

I am trying to proxy modbus TCP connections to a Huawei SUN2000 L1 inverter. I usually poll the device using solar-logger using a reduced version of scanner_2.py in that repository.

Unfortunately, I receive the following output from modbus proxy

root@zabbix:~# modbus-proxy -b tcp://0:5020 --modbus tcp://192.168.1.30:502
2021-09-20 09:10:03,578     INFO modbus-proxy: Starting...
2021-09-20 09:10:03,582     INFO modbus-proxy.ModBus(192.168.1.30:502): Ready to accept requests on 0:5020
2021-09-20 09:10:04,583     INFO modbus-proxy.Client(127.0.0.1:37407): new client connection
2021-09-20 09:10:04,584     INFO modbus-proxy.ModBus(192.168.1.30:502): connecting to modbus...
2021-09-20 09:10:04,590     INFO modbus-proxy.ModBus(192.168.1.30:502): connected!
2021-09-20 09:10:14,594    ERROR modbus-proxy.ModBus(192.168.1.30:502): write_read error: TimeoutError()
2021-09-20 09:10:14,594     INFO modbus-proxy.ModBus(192.168.1.30:502): closing connection...
2021-09-20 09:10:14,594     INFO modbus-proxy.ModBus(192.168.1.30:502): connection closed
2021-09-20 09:10:14,594     INFO modbus-proxy.ModBus(192.168.1.30:502): connecting to modbus...
2021-09-20 09:10:14,601     INFO modbus-proxy.ModBus(192.168.1.30:502): connected!
2021-09-20 09:10:24,603    ERROR modbus-proxy.ModBus(192.168.1.30:502): write_read error: TimeoutError()
2021-09-20 09:10:24,603     INFO modbus-proxy.ModBus(192.168.1.30:502): closing connection...
2021-09-20 09:10:24,603     INFO modbus-proxy.ModBus(192.168.1.30:502): connection closed
2021-09-20 09:10:24,603     INFO modbus-proxy.Client(127.0.0.1:37407): closing connection...
2021-09-20 09:10:24,604     INFO modbus-proxy.Client(127.0.0.1:37407): connection closed
2021-09-20 09:10:29,122     INFO modbus-proxy.Client(127.0.0.1:40587): new client connection
2021-09-20 09:10:29,123     INFO modbus-proxy.ModBus(192.168.1.30:502): connecting to modbus...
2021-09-20 09:10:29,127     INFO modbus-proxy.ModBus(192.168.1.30:502): connected!

The poller doesn't receive any data.

root@zabbix:~# /root/solar-logger/leer_solar.py
Conectando a Inversor
^CTraceback (most recent call last):
  File "/root/solar-logger/leer_solar.py", line 310, in <module>
    j = result.registers[0]
AttributeError: 'ModbusIOException' object has no attribute 'registers'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/root/solar-logger/leer_solar.py", line 42, in read_holding
    j = result.registers[nb - 1]
AttributeError: 'ModbusIOException' object has no attribute 'registers'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/root/solar-logger/leer_solar.py", line 317, in <module>
    result = read_holding(client, UnitID, Registro, 2)
  File "/root/solar-logger/leer_solar.py", line 47, in read_holding
    time.sleep(0.1)
KeyboardInterrupt

TBH I have no clue about why this is happening, I'm mostly sure it is related to the way the poller requests the information, more than modbus proxy itself, but if you have any hint, It would be much appreciated.

Thanks.

tiagocoutinho commented 2 years ago

Could you try launching modbus-proxy with debug log level?

For that you will need a config file with the following contents:

[formatters]
keys=standard

[handlers]
keys=console

[loggers]
keys=root

[formatter_standard]
format=%(asctime)s %(levelname)8s %(name)s: %(message)s

[handler_console]
class=StreamHandler
formatter=standard

[logger_root]
level=DEBUG
handlers=console

... and launch modbus-proxy with the following command line:

$ modbus-proxy -b tcp://0:5020 --modbus tcp://192.168.1.30:502 --log-config-file=./log.conf

This will give a more verbose output. Please send the output.

Also could you attach the script you adapted?

Thanks in adavance

javierin commented 2 years ago

Thanks for your quick response!

This is the output of modbus-proxy when using your debug config:

root@zabbix:~/modbus-proxy# python3 modbus_proxy.py -b tcp://0:5020 --modbus tcp://192.168.1.30:502 --log-config-file=./log.conf

2021-09-23 15:21:29,947     INFO modbus-proxy: Starting...
2021-09-23 15:21:29,947    DEBUG asyncio: Using selector: EpollSelector
2021-09-23 15:21:29,950     INFO modbus-proxy.ModBus(192.168.1.30:502): Ready to accept requests on 0:5020
2021-09-23 15:22:15,910     INFO modbus-proxy.Client(127.0.0.1:33237): new client connection
2021-09-23 15:22:17,912    DEBUG modbus-proxy.Client(127.0.0.1:33237): received b'\x00\x01\x00\x00\x00\x06\x00\x03uw\x00\x01'
2021-09-23 15:22:17,913     INFO modbus-proxy.ModBus(192.168.1.30:502): connecting to modbus...
2021-09-23 15:22:17,931     INFO modbus-proxy.ModBus(192.168.1.30:502): connected!
2021-09-23 15:22:17,932    DEBUG modbus-proxy.ModBus(192.168.1.30:502): sending b'\x00\x01\x00\x00\x00\x06\x00\x03uw\x00\x01'
2021-09-23 15:22:24,419     INFO modbus-proxy.Client(127.0.0.1:58063): new client connection
2021-09-23 15:22:24,420    DEBUG modbus-proxy.Client(127.0.0.1:58063): received b'\x00\x02\x00\x00\x00\x06\x00\x03uw\x00\x02'
2021-09-23 15:22:27,935    ERROR modbus-proxy.ModBus(192.168.1.30:502): write_read error: TimeoutError()
2021-09-23 15:22:27,936     INFO modbus-proxy.ModBus(192.168.1.30:502): closing connection...
2021-09-23 15:22:27,936     INFO modbus-proxy.ModBus(192.168.1.30:502): connection closed
2021-09-23 15:22:27,937     INFO modbus-proxy.ModBus(192.168.1.30:502): connecting to modbus...
2021-09-23 15:22:27,940     INFO modbus-proxy.ModBus(192.168.1.30:502): connected!
2021-09-23 15:22:27,940    DEBUG modbus-proxy.ModBus(192.168.1.30:502): sending b'\x00\x01\x00\x00\x00\x06\x00\x03uw\x00\x01'
2021-09-23 15:22:37,942    ERROR modbus-proxy.ModBus(192.168.1.30:502): write_read error: TimeoutError()
2021-09-23 15:22:37,942     INFO modbus-proxy.ModBus(192.168.1.30:502): closing connection...
2021-09-23 15:22:37,943     INFO modbus-proxy.ModBus(192.168.1.30:502): connection closed
2021-09-23 15:22:37,943     INFO modbus-proxy.Client(127.0.0.1:33237): closing connection...
2021-09-23 15:22:37,943     INFO modbus-proxy.ModBus(192.168.1.30:502): connecting to modbus...
2021-09-23 15:22:37,944     INFO modbus-proxy.Client(127.0.0.1:33237): connection closed
2021-09-23 15:22:37,949     INFO modbus-proxy.ModBus(192.168.1.30:502): connected!
2021-09-23 15:22:37,949    DEBUG modbus-proxy.ModBus(192.168.1.30:502): sending b'\x00\x02\x00\x00\x00\x06\x00\x03uw\x00\x02'
2021-09-23 15:22:47,951    ERROR modbus-proxy.ModBus(192.168.1.30:502): write_read error: TimeoutError()
2021-09-23 15:22:47,951     INFO modbus-proxy.ModBus(192.168.1.30:502): closing connection...
2021-09-23 15:22:47,951     INFO modbus-proxy.ModBus(192.168.1.30:502): connection closed
2021-09-23 15:22:47,952     INFO modbus-proxy.ModBus(192.168.1.30:502): connecting to modbus...
2021-09-23 15:22:47,956     INFO modbus-proxy.ModBus(192.168.1.30:502): connected!
2021-09-23 15:22:47,957    DEBUG modbus-proxy.ModBus(192.168.1.30:502): sending b'\x00\x02\x00\x00\x00\x06\x00\x03uw\x00\x02'
^C2021-09-23 15:22:53,105     INFO modbus-proxy.ModBus(192.168.1.30:502): closing connection...
2021-09-23 15:22:53,105     INFO modbus-proxy.Client(127.0.0.1:58063): closing connection...
2021-09-23 15:22:53,106     INFO modbus-proxy.ModBus(192.168.1.30:502): connection closed
2021-09-23 15:22:53,106     INFO modbus-proxy.Client(127.0.0.1:58063): connection closed
2021-09-23 15:22:53,107  WARNING modbus-proxy: Ctrl-C pressed. Bailing out!

This is the script I use for reading https://raw.githubusercontent.com/basking-in-the-sun2000/solar-logger/master/scanner_2.py

My modifications are just reducing the amount of registers I capture and redirecting the output to another monitoring API (my Zabbix server) instead of printing the output to console.

Again, thanks for your interest

tiagocoutinho commented 2 years ago

Everything looks normal in the log with the exception that your modbus device doesn't seem to answer to the request that is sent.

The only difference I see is that in your script, after you establish a connection, there is a 2s sleep before the first communication. It's hard to say what might be the cause. Some hardware devices don't implement the TCP stack properly so yours might need a stabilization time after a connection is made.

So, I created a new version (0.4.2) which adds a --modbus-connection-time parameter. The idea is to be able to configure a delay after connection.

Could you retry the new version with the command:

$ modbus-proxy -b tcp://0:5020 --modbus tcp://192.168.1.30:502 --log-config-file=./log.conf --modbus-connection-time=2

If you installed modbus-proxy with pip then just update with:

$ pip install -U modbus-proxy

Otherwise if you are using git, just pull from master.

javierin commented 2 years ago

Yay! Working like a charm!!!!

tiagocoutinho commented 2 years ago

Great! Thanks for reporting Good luck with your project

henfri commented 1 year ago

Hello,

despite using the latest version, I experience the same issue:

2023-06-01 23:12:24,068     INFO modbus-proxy: Starting...
2023-06-01 23:12:24,071     INFO modbus-proxy.ModBus(192.168.200.1:6607): Ready to accept requests on 0:502
2023-06-01 23:12:34,506     INFO modbus-proxy.Client(192.168.177.41:57620): new client connection
2023-06-01 23:12:36,567    DEBUG modbus-proxy.Client(192.168.177.41:57620): received b'\x00\r\x00\x00\x00\x06\x01\x03u0\x00\x0f'
2023-06-01 23:12:36,567     INFO modbus-proxy.ModBus(192.168.200.1:6607): connecting to modbus...
2023-06-01 23:12:36,571     INFO modbus-proxy.ModBus(192.168.200.1:6607): connected!
2023-06-01 23:12:36,572     INFO modbus-proxy.ModBus(192.168.200.1:6607): delay after connect: 2.0
2023-06-01 23:12:38,572    DEBUG modbus-proxy.ModBus(192.168.200.1:6607): sending b'\x00\r\x00\x00\x00\x06\x01\x03u0\x00\x0f'
2023-06-01 23:12:48,575    ERROR modbus-proxy.ModBus(192.168.200.1:6607): write_read error [1/2]: TimeoutError()
2023-06-01 23:12:48,575     INFO modbus-proxy.ModBus(192.168.200.1:6607): closing connection...
2023-06-01 23:12:48,576     INFO modbus-proxy.ModBus(192.168.200.1:6607): connection closed
2023-06-01 23:12:48,576     INFO modbus-proxy.ModBus(192.168.200.1:6607): connecting to modbus...
2023-06-01 23:12:48,581     INFO modbus-proxy.ModBus(192.168.200.1:6607): connected!
2023-06-01 23:12:48,582     INFO modbus-proxy.ModBus(192.168.200.1:6607): delay after connect: 2.0
2023-06-01 23:12:50,584    DEBUG modbus-proxy.ModBus(192.168.200.1:6607): sending b'\x00\r\x00\x00\x00\x06\x01\x03u0\x00\x0f'
2023-06-01 23:13:00,587    ERROR modbus-proxy.ModBus(192.168.200.1:6607): write_read error [2/2]: TimeoutError()
2023-06-01 23:13:00,587     INFO modbus-proxy.ModBus(192.168.200.1:6607): closing connection...
2023-06-01 23:13:00,588     INFO modbus-proxy.ModBus(192.168.200.1:6607): connection closed
2023-06-01 23:13:00,588     INFO modbus-proxy.Client(192.168.177.41:57620): closing connection...
2023-06-01 23:13:00,589     INFO modbus-proxy.Client(192.168.177.41:57620): connection closed

Do you have any Idea/Suggestion?

Best regards, Hendrik

tiagocoutinho commented 1 year ago

Could you post here the configuration file and command line you are using ?

henfri commented 1 year ago

Of course. Sorry. modbus-proxy -b tcp://0:502 --modbus tcp://192.168.200.1:6607 --log-config-file=./log.conf --modbus-connection-time=2

log.conf is the one from above.

Alternatively, I used this config:

huawei_modbux-proxy.yaml
devices:
- modbus:
    url: 192.168.200.1:6607     # device url (mandatory)
    timeout: 10                # communication timeout (s) (optional, default: 10)
    connection_time: 1       # delay after connection (s) (optional, default: 0)
  listen:
    bind: 0:502               # listening address (mandatory)r