node-red query error

[MaGeHome]

Hello,

I am currently using the ioBroker with the node-red adapter to query my Huawei photovoltaic system. The Modbus TCP query is running stably without errors.
I would like to change the query via the multiplexer.

Unfortunately, I receive the following message in the log.

time="2024-11-17T22:19:49+01:00" level=info msg="#1: 172.18.0.1:33904 <-> 172.18.0.2:502"
time="2024-11-17T22:19:49+01:00" level=info msg="Connected clients: 1"
time="2024-11-17T22:19:51+01:00" level=info msg="creating target connection"
time="2024-11-17T22:19:51+01:00" level=info msg="new target connection: 172.18.0.2:34376 <-> 192.168.0.18:502"
time="2024-11-17T22:20:00+01:00" level=info msg="#2: 172.18.0.1:40410 <-> 172.18.0.2:502"
time="2024-11-17T22:20:12+01:00" level=info msg="#3: 172.18.0.1:56430 <-> 172.18.0.2:502"
time="2024-11-17T22:20:24+01:00" level=info msg="#4: 172.18.0.1:52962 <-> 172.18.0.2:502"
time="2024-11-17T22:20:36+01:00" level=info msg="#5: 172.18.0.1:47416 <-> 172.18.0.2:502"
time="2024-11-17T22:20:48+01:00" level=info msg="#6: 172.18.0.1:55528 <-> 172.18.0.2:502"
**time="2024-11-17T22:20:51+01:00" level=error msg="target connection: read tcp 172.18.0.2:34376->192.168.0.18:502: i/o timeout"
time="2024-11-17T22:20:51+01:00" level=error msg="failed to forward message, read tcp 172.18.0.2:34376->192.168.0.18:502: i/o timeout"**
time="2024-11-17T22:20:51+01:00" level=info msg="Connected clients: 2"
time="2024-11-17T22:20:51+01:00" level=info msg="creating target connection"
time="2024-11-17T22:20:52+01:00" level=info msg="new target connection: 172.18.0.2:38648 <-> 192.168.0.18:502"
time="2024-11-17T22:21:00+01:00" level=info msg="#7: 172.18.0.1:57906 <-> 172.18.0.2:502"
time="2024-11-17T22:21:12+01:00" level=info msg="#8: 172.18.0.1:54888 <-> 172.18.0.2:502"
time="2024-11-17T22:21:24+01:00" level=info msg="#9: 172.18.0.1:56190 <-> 172.18.0.2:502"
time="2024-11-17T22:21:36+01:00" level=info msg="#10: 172.18.0.1:36884 <-> 172.18.0.2:502"
time="2024-11-17T22:21:48+01:00" level=info msg="#11: 172.18.0.1:45178 <-> 172.18.0.2:502"
**time="2024-11-17T22:21:52+01:00" level=error msg="target connection: read tcp 172.18.0.2:38648->192.168.0.18:502: i/o timeout"
time="2024-11-17T22:21:52+01:00" level=error msg="failed to forward message, read tcp 172.18.0.2:38648->192.168.0.18:502: i/o timeout"**

In ioBroker I get the following message in the log.

[error] [modbus-client:ModBus-TCP] Error: connect ENETUNREACH 172.18.0.2:502 at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1607:16)

The multiplexer runs in a container on the same host.

services:
  modbus-proxy:
    platform: linux/arm64
    image: ghcr.io/ingmarstein/tcp-multiplexer
    container_name: Modbus-Multiplexer
    ports:
      - "502:502"
    command: [ "server", "-t", "192.168.0.18:502", "-l", "502", "-p", "modbus", "-v" ]
    restart: always
    environment:
      TZ: Europe/Berlin
    hostname: Modbus_Container
    dns: 192.168.0.1

I am not sure what the problem could be and would be happy for help

Regards

[IngmarStein]

There are two things to try out:

• listen on a non-privileged port (e.g. 1502) inside the container
• check network connectivity to the inverter using a different container, for example docker run --rm alpine ping 192.168.0.18

[MaGeHome]

Thanks for your help.

I checked the network connectivity.
The connection is good.

$ docker run --rm alpine ping 192.168.0.18
PING 192.168.0.18 (192.168.0.18): 56 data bytes
64 bytes from 192.168.0.18: seq=0 ttl=254 time=0.699 ms
64 bytes from 192.168.0.18: seq=1 ttl=254 time=0.308 ms
64 bytes from 192.168.0.18: seq=2 ttl=254 time=0.418 ms
64 bytes from 192.168.0.18: seq=3 ttl=254 time=0.300 ms
--- 192.168.0.18 ping statistics ---
4 packets transmitted, 4 packets received, 0% packet loss
round-trip min/avg/max = 0.300/0.431/0.699 ms

$ docker run --rm alpine ping 192.168.0.18:502
PING 192.168.0.18:502 (192.168.0.18): 56 data bytes
64 bytes from 192.168.0.18: seq=0 ttl=254 time=0.595 ms
64 bytes from 192.168.0.18: seq=1 ttl=254 time=0.301 ms
64 bytes from 192.168.0.18: seq=2 ttl=254 time=0.289 ms
64 bytes from 192.168.0.18: seq=3 ttl=254 time=0.311 ms
--- 192.168.0.18:502 ping statistics ---
4 packets transmitted, 4 packets received, 0% packet loss
round-trip min/avg/max = 0.289/0.374/0.595 ms

I changed the Port inside the container to 1502.
Unfortunately this does not bring any change.

services:
  modbus-proxy:
    platform: linux/arm64
    image: ghcr.io/ingmarstein/tcp-multiplexer
    container_name: Modbus-Multiplexer
    ports:
      - "1502:502"
    command: [ "server", "-t", "192.168.0.18:502", "-l", "502", "-p", "modbus", "-v" ]
    restart: always
    environment:
      TZ: Europe/Berlin
    hostname: Modbus_Container
    dns: 192.168.0.1

The host runs on 192.168.0.29, node-red on port 1880 and the ioBroker on port 8081. Is it possible that additional port shares are required for forwarding the message in the container?

Regards

[IngmarStein]

The modified Compose file changed the exposed port, not the listening port. Try this:

services:
  modbus-proxy:
    platform: linux/arm64
    image: ghcr.io/ingmarstein/tcp-multiplexer
    container_name: Modbus-Multiplexer
    ports:
      - "502:1502"
    command: [ "server", "-t", "192.168.0.18:502", "-l", "1502", "-p", "modbus", "-v" ]
    restart: always
    environment:
      TZ: Europe/Berlin
    hostname: Modbus_Container
    dns: 192.168.0.1

[MaGeHome]

I'm sorry, I misunderstood about the port.
Changing the exposed port does not change anything.

I don't know if it helps. This is my node-red flow.
Modbus.json

[IngmarStein]

Looking a bit more into the log, it looks like network connectivity isn't the problem. Both the connections from the client to the multiplexer and from the multiplexer to the inverter work. Five messages are exchanged successfully, but the sixth message causes the multiplexer to wait for a response from the inverter which isn't fully read within 60 seconds.

It could be an issue with the modbus implementation or quirk for this inverter model. Can you add -d to the command line and try again?

[MaGeHome]

I added -d to the command line.

command: [ "server", "-t", "192.168.0.18:502", "-l", "1502", "-p", "modbus", "-v", "-d" ]

I have also changed the query interval from 10s to 60s in node-red.
Unfortunately, this has no effect.

With the multiplexer only shows me connected in node-red. (see far right under iob write value boxes)

In the query without multiplexer, the values are displayed directly after a second.
So I think that the queries are sent. But the answers do not come back

Thanks for your help.

[IngmarStein]

Oh yeah, -d just enables debug mode. I'd be interested in the log output.

I don't use node-red and the flow charts and the config files are not needed to debug the issue.

[MaGeHome]

Even if I'm embarrassing myself now. :-) Where does the container store the debug log?
In Portainer I only see this LogPath.

LogPath /var/lib/docker/containers/afb9e191f6da38e10f97c7dbc7cb4d2154907c366bd860fa7911ce83edfe1cf2/afb9e191f6da38e10f97c7dbc7cb4d2154907c366bd860fa7911ce83edfe1cf2-json.log

And there is only the same content that I have already shown.

$ docker logs Modbus-Multiplexer
time="2024-11-18T20:48:25+01:00" level=info msg="#1: 172.18.0.1:55468 <-> 172.18.0.2:1502"
time="2024-11-18T20:48:25+01:00" level=info msg="Connected clients: 1"
time="2024-11-18T20:48:27+01:00" level=info msg="creating target connection"
time="2024-11-18T20:48:27+01:00" level=info msg="new target connection: 172.18.0.2:42416 <-> 192.168.0.18:502"
time="2024-11-18T20:48:36+01:00" level=info msg="#2: 172.18.0.1:55822 <-> 172.18.0.2:1502"
time="2024-11-18T20:49:27+01:00" level=error msg="target connection: read tcp 172.18.0.2:42416->192.168.0.18:502: i/o timeout"
time="2024-11-18T20:49:27+01:00" level=info msg="Connected clients: 2"
time="2024-11-18T20:49:27+01:00" level=error msg="failed to forward message, read tcp 172.18.0.2:42416->192.168.0.18:502: i/o timeout"
time="2024-11-18T20:49:27+01:00" level=info msg="Connected clients: 1"
time="2024-11-18T20:49:27+01:00" level=info msg="creating target connection"
time="2024-11-18T20:49:27+01:00" level=info msg="new target connection: 172.18.0.2:35354 <-> 192.168.0.18:502"
time="2024-11-18T20:49:36+01:00" level=info msg="#3: 172.18.0.1:48900 <-> 172.18.0.2:1502"
time="2024-11-18T20:50:27+01:00" level=error msg="target connection: read tcp 172.18.0.2:35354->192.168.0.18:502: i/o timeout"
time="2024-11-18T20:50:27+01:00" level=error msg="failed to forward message, read tcp 172.18.0.2:35354->192.168.0.18:502: i/o timeout"
time="2024-11-18T20:50:27+01:00" level=info msg="Connected clients: 2"
time="2024-11-18T20:50:27+01:00" level=info msg="creating target connection"
time="2024-11-18T20:50:28+01:00" level=info msg="new target connection: 172.18.0.2:53378 <-> 192.168.0.18:502"
time="2024-11-18T20:50:36+01:00" level=info msg="#4: 172.18.0.1:42578 <-> 172.18.0.2:1502"
time="2024-11-18T20:51:28+01:00" level=error msg="target connection: read tcp 172.18.0.2:53378->192.168.0.18:502: i/o timeout"
time="2024-11-18T20:51:28+01:00" level=info msg="Connected clients: 1"
time="2024-11-18T20:51:28+01:00" level=info msg="Connected clients: 2"
time="2024-11-18T20:51:28+01:00" level=info msg="creating target connection"
time="2024-11-18T20:51:28+01:00" level=error msg="failed to forward message, read tcp 172.18.0.2:53378->192.168.0.18:502: i/o timeout"
time="2024-11-18T20:51:29+01:00" level=info msg="new target connection: 172.18.0.2:54760 <-> 192.168.0.18:502"
time="2024-11-18T20:51:36+01:00" level=info msg="#5: 172.18.0.1:59402 <-> 172.18.0.2:1502"

[IngmarStein]

docker logs was the right command, but I forgot that the modbus implementation doesn't log raw messages (unlike the HTTP multiplexer). You could use wireshark to log traffic from and to the multiplexer, but before doing so: is there another client connected directly to the inverter? The messages seem to failing intermittently and that could happen when there are two clients competing for a single TCP connection (the problem that tcp-multiplexer solves).

[MaGeHome]

Correct, the Modbus of the inverter only allows one connection. I therefore disconnect the connection to node-red before connecting the multiplexer. Otherwise the multiplexer would return connection denied.

I have not used Wireshark yet. I'll have a look at it.

[capi]

Make sure that your server at 192.168.0.18 doesn't have any iptables (or other firewall) rules that prevent speaking to it from inside a docker container. I fell into this trap once that a port was accessible from my network 192.168.0.0/24 since I whitelisted the netmask, but I forgot that the container was a) not connecting via eth0 but the bridge interface and b) in a 172.28.0.0/24 subnet. (This should be relevant only if 192.168.0.18 is actually also your docker host.)

Try, if you can get it working by using network_mode: host which means that the container will run in the network stack of the Docker host. If this works, you really likely have firewalling and/or NAT issues somewhere.

Edit: If 192.168.0.18 is actually your docker-host, you might need to expose access to the host like the following:

extra_hosts:
      - "host.docker.internal:host-gateway"

And then you need to connect to host.docker.internal instead of 192.168.0.28

[MaGeHome]

Make sure that your server at 192.168.0.18 doesn't have any iptables (or other firewall) rules that prevent speaking to it from inside a docker container. I fell into this trap once that a port was accessible from my network 192.168.0.0/24 since I whitelisted the netmask, but I forgot that the container was a) not connecting via eth0 but the bridge interface and b) in a 172.28.0.0/24 subnet. (This should be relevant only if 192.168.0.18 is actually also your docker host.)

Try, if you can get it working by using network_mode: host which means that the container will run in the network stack of the Docker host. If this works, you really likely have firewalling and/or NAT issues somewhere.

Edit: If 192.168.0.18 is actually your docker-host, you might need to expose access to the host like the following:

extra_hosts:
      - "host.docker.internal:host-gateway"

And then you need to connect to host.docker.internal instead of 192.168.0.28

Thank you for your help and advice.
192.168.0.18 is not my Docker host. My Docker host is 192.168.0.29. My Docker host itself does not have its own firewall.

I have changed the container's network to host. Unfortunately, the result is unchanged.

[MaGeHome]

I have installed Wireshark on my host and added Edgeshark in a container. I have also added the cshargextcap package.
Here is the overview from Edgeshark.

Unfortunately, I have not yet managed to get a connection to the Multilpexer Conatiner to record the traffic.

[capi]

Looking at this part of your log-line:

**time="2024-11-17T22:21:52+01:00" level=error msg="target connection: read tcp 172.18.0.2:38648->192.168.0.18:502: i/o timeout"

And the fact, that you could ping your host:

docker run --rm alpine ping 192.168.0.18

You cannot, however, ping a port, so the line where you try to ping the port does not help. What you can try though if you can successfully connect to the port via nc (it's default installed in alpine):

docker run --rm alpine nc -v -w 5 192.168.0.18 502

If this runs into a timeout, the port is wrong or there is a firewall involved somewhere. In my case, the connection is immediately closed after a short timeout, but it indicates the port is open, whereas a wrong port times out (SolarEdge inverter in my case):

martin@host:~$ docker run --rm alpine nc -v -w 3 192.168.1.90 502
192.168.1.90 (192.168.1.90:502) open
martin@host:~$ docker run --rm alpine nc -v -w 3 192.168.1.90 503
nc: 192.168.1.90 (192.168.1.90:503): Operation timed out

[IngmarStein]

As you embark on this endeavor, did you double-check that tcp-multiplexer is the only thing talking to the inverter?

The log snippet

time="2024-11-17T22:20:24+01:00" level=info msg="#4: 172.18.0.1:52962 <-> 172.18.0.2:502"
time="2024-11-17T22:20:36+01:00" level=info msg="#5: 172.18.0.1:47416 <-> 172.18.0.2:502"
time="2024-11-17T22:20:48+01:00" level=info msg="#6: 172.18.0.1:55528 <-> 172.18.0.2:502"
**time="2024-11-17T22:20:51+01:00" level=error msg="target connection: read tcp 172.18.0.2:34376->192.168.0.18:502: i/o timeout"

could be interpreted as: a number of messages where exchanged successfully and then the inverter stopped responding (for example because something else opened a TCP connection). In such cases, the multiplexer returns an error and will attempt to open a new connection for the next packet.