Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Strange Modbus errors with multiple devices on the bus #16049

Closed
1 task done
premultiply opened this issue Sep 11, 2024 · 11 comments · Fixed by evcc-io/modbus#9
Closed
1 task done

Strange Modbus errors with multiple devices on the bus #16049

premultiply opened this issue Sep 11, 2024 · 11 comments · Fixed by evcc-io/modbus#9
Labels
bug Something isn't working

Comments

@premultiply
Copy link
Member

Describe the bug

Ich möchte 3 Zähler an einem RS485-Bus betreiben. 1x SDM72DMv2 und 2x SDM120-Modbus.
Alle Zähler haben eigene, eindeutige Modbus-ID (1,2,3) und ansonsten selbstverständlich identliche Kommunikationsparameter 9600 8N1. Der Bus ist Spezifikationskonform aufgebaut und korrekt terminiert und funktioniert eigentlich auch einwandfrei - nur nicht mit evcc. Hier gibt es sehr häufig Datenfehler und Timeouts, speziell bei den beiden SDM120, die in der Konfig unterhalb des SDM72 aufgeführt sind. Insbesondere schlägt meist das Lesen des ersten Datensatzes (Power) fehl, während der zweite Datensatz deutlich weniger oft betroffen ist.

Steps to reproduce

Jeder Zähler einzeln kann problemlos und dauerhaft z.B. mit evcc meter wp1 -r ohne jegliche Fehler angesprochen werden.
Lediglich die Verwendung im normalen Prozess oder wenn alle Meter zusammen abgefragt werden (evcc meter) macht sehr häufig (aber nicht immer!) Probleme.

Configuration details

meters:
- name: charger
  type: template
  template: eastron
  usage: charge
  modbus: rs485serial
  id: 3
  device: /dev/ttyUSB0
  baudrate: 9600
  comset: "8N1"
- name: wp1
  type: template
  template: eastron-sdm120
  usage: charge
  modbus: rs485serial
  id: 1
  device: /dev/ttyUSB0
  baudrate: 9600
  comset: "8N1"
- name: wp2
  type: template
  template: eastron-sdm120
  usage: charge
  modbus: rs485serial
  id: 2
  device: /dev/ttyUSB0
  baudrate: 9600
  comset: "8N1"

Log details

pi@autosmatix:~ $ evcc meter wp1 --log trace,db:error
[main  ] INFO 2024/09/11 23:15:43 evcc 0.130.9
[main  ] INFO 2024/09/11 23:15:43 using config file: /etc/evcc.yaml
[mqtt  ] INFO 2024/09/11 23:15:44 connecting evcc-1032005439 at tcp://localhost:1883
[mqtt  ] DEBUG 2024/09/11 23:15:44 tcp://localhost:1883 connected
[modbus] TRACE 2024/09/11 23:15:44 modbus: send 01 04 00 0c 00 02 b1 c8
[modbus] TRACE 2024/09/11 23:15:44 modbus: recv 01 04 04 44 30 00 00 ef 7b
[modbus] TRACE 2024/09/11 23:15:44 modbus: send 01 04 00 48 00 02 f1 dd
[modbus] TRACE 2024/09/11 23:15:44 modbus: recv 01 04 04 41 91 2b 02 21 64
Power:  704W
Energy: 18.1kWh
pi@autosmatix:~ $ evcc meter wp2 --log trace,db:error
[main  ] INFO 2024/09/11 23:15:50 evcc 0.130.9
[main  ] INFO 2024/09/11 23:15:50 using config file: /etc/evcc.yaml
[mqtt  ] INFO 2024/09/11 23:15:51 connecting evcc-557266435 at tcp://localhost:1883
[mqtt  ] DEBUG 2024/09/11 23:15:51 tcp://localhost:1883 connected
[modbus] TRACE 2024/09/11 23:15:51 modbus: send 02 04 00 0c 00 02 b1 fb
[modbus] TRACE 2024/09/11 23:15:51 modbus: recv 02 04 04 00 00 00 00 c8 84
[modbus] TRACE 2024/09/11 23:15:51 modbus: send 02 04 00 48 00 02 f1 ee
[modbus] TRACE 2024/09/11 23:15:51 modbus: recv 02 04 04 00 00 00 00 c8 84
Power:  0W
Energy: 0.0kWh
pi@autosmatix:~ $ evcc meter --log trace,db:error
[main  ] INFO 2024/09/11 23:16:00 evcc 0.130.9
[main  ] INFO 2024/09/11 23:16:00 using config file: /etc/evcc.yaml
[mqtt  ] INFO 2024/09/11 23:16:01 connecting evcc-1814173540 at tcp://localhost:1883
[mqtt  ] DEBUG 2024/09/11 23:16:01 tcp://localhost:1883 connected
wp2
---
[modbus] TRACE 2024/09/11 23:16:01 modbus: send 02 04 00 0c 00 02 b1 fb
[modbus] TRACE 2024/09/11 23:16:01 modbus: recv 02 04 04 00 00 00 00 c8 84
[modbus] TRACE 2024/09/11 23:16:01 modbus: send 02 04 00 48 00 02 f1 ee
[modbus] TRACE 2024/09/11 23:16:01 modbus: recv 02 04 04 00 00 00 00 c8 84
Power:  0W
Energy: 0.0kWh

charger
-------
[modbus] TRACE 2024/09/11 23:16:01 modbus: send 03 04 00 34 00 02 31 e7
[modbus] TRACE 2024/09/11 23:16:01 modbus: recv 03 04 04 3f e5 78 94 e6 08
[modbus] TRACE 2024/09/11 23:16:01 modbus: send 03 04 00 48 00 02 f0 3f
[modbus] TRACE 2024/09/11 23:16:01 modbus: recv 03 04 04 45 93 b4 39 8a 77
[modbus] TRACE 2024/09/11 23:16:01 modbus: send 03 04 00 06 00 02 90 28
[modbus] TRACE 2024/09/11 23:16:01 modbus: recv 03 04 04 3d 04 70 cf f1 bd
[modbus] TRACE 2024/09/11 23:16:01 modbus: send 03 04 00 08 00 02 f1 eb
[modbus] TRACE 2024/09/11 23:16:01 modbus: recv 03 04 04 00 00 00 00 d8 44
[modbus] TRACE 2024/09/11 23:16:01 modbus: send 03 04 00 0a 00 02 50 2b
[modbus] TRACE 2024/09/11 23:16:01 modbus: recv 03 04 04 00 00 00 00 d8 44
[modbus] TRACE 2024/09/11 23:16:01 modbus: send 03 04 00 00 00 02 70 29
[modbus] TRACE 2024/09/11 23:16:01 modbus: recv 03 04 04 43 6b a2 80 c4 dc
[modbus] TRACE 2024/09/11 23:16:01 modbus: send 03 04 00 02 00 02 d1 e9
[modbus] TRACE 2024/09/11 23:16:01 modbus: recv 03 04 04 41 dd 9d a4 35 69
[modbus] TRACE 2024/09/11 23:16:01 modbus: send 03 04 00 04 00 02 31 e8
[modbus] TRACE 2024/09/11 23:16:02 modbus: recv 03 04 04 00 00 00 00 d8 44
Power:          2W
Energy:         4726.5kWh
Current L1..L3: 0.0323A 0A 0A
Voltage L1..L3: 236V 27.7V 0V

wp1
---
[modbus] TRACE 2024/09/11 23:16:02 modbus: send 01 04 00 0c 00 02 b1 c8
[modbus] TRACE 2024/09/11 23:16:02 modbus: recv 01 04 04 44 30 39 9a 7d 40
[modbus] TRACE 2024/09/11 23:16:02 modbus: send 01 04 00 48 00 02 f1 dd
[modbus] TRACE 2024/09/11 23:16:02 modbus: recv 01 04 04 41 91 31 27 eb df
Power:  705W
Energy: 18.1kWh

pi@autosmatix:~ $ evcc meter --log trace,db:error
[main  ] INFO 2024/09/11 23:16:12 evcc 0.130.9
[main  ] INFO 2024/09/11 23:16:12 using config file: /etc/evcc.yaml
[mqtt  ] INFO 2024/09/11 23:16:13 connecting evcc-1177360853 at tcp://localhost:1883
[mqtt  ] DEBUG 2024/09/11 23:16:13 tcp://localhost:1883 connected
charger
-------
[modbus] TRACE 2024/09/11 23:16:13 modbus: send 03 04 00 34 00 02 31 e7
[modbus] TRACE 2024/09/11 23:16:13 modbus: recv 03 04 04 3f d7 1d 48 6d 0e
[modbus] TRACE 2024/09/11 23:16:13 modbus: send 03 04 00 48 00 02 f0 3f
[modbus] TRACE 2024/09/11 23:16:13 modbus: recv 03 04 04 45 93 b4 39 8a 77
[modbus] TRACE 2024/09/11 23:16:13 modbus: send 03 04 00 06 00 02 90 28
[modbus] TRACE 2024/09/11 23:16:13 modbus: recv 03 04 04 3d 04 f8 0d 16 2c
[modbus] TRACE 2024/09/11 23:16:13 modbus: send 03 04 00 08 00 02 f1 eb
[modbus] TRACE 2024/09/11 23:16:13 modbus: recv 03 04 04 00 00 00 00 d8 44
[modbus] TRACE 2024/09/11 23:16:13 modbus: send 03 04 00 0a 00 02 50 2b
[modbus] TRACE 2024/09/11 23:16:13 modbus: recv 03 04 04 00 00 00 00 d8 44
[modbus] TRACE 2024/09/11 23:16:13 modbus: send 03 04 00 00 00 02 70 29
[modbus] TRACE 2024/09/11 23:16:13 modbus: recv 03 04 04 43 6b a2 3b 84 af
[modbus] TRACE 2024/09/11 23:16:13 modbus: send 03 04 00 02 00 02 d1 e9
[modbus] TRACE 2024/09/11 23:16:13 modbus: recv 03 04 04 41 dd 9a 93 76 8f
[modbus] TRACE 2024/09/11 23:16:13 modbus: send 03 04 00 04 00 02 31 e8
[modbus] TRACE 2024/09/11 23:16:13 modbus: recv 03 04 04 00 00 00 00 d8 44
Power:          2W
Energy:         4726.5kWh
Current L1..L3: 0.0325A 0A 0A
Voltage L1..L3: 236V 27.7V 0V

wp2
---
[modbus] TRACE 2024/09/11 23:16:13 modbus: send 02 04 00 0c 00 02 b1 fb
[modbus] TRACE 2024/09/11 23:16:18 modbus: recv
[modbus] TRACE 2024/09/11 23:16:18 modbus: send 02 04 00 48 00 02 f1 ee
[modbus] TRACE 2024/09/11 23:16:18 modbus: recv 02 04 04 00 00 00 00 c8 84
Power:  read failed: serial: timeout
Energy: 0.0kWh

wp1
---
[modbus] TRACE 2024/09/11 23:16:18 modbus: send 01 04 00 0c 00 02 b1 c8
[modbus] TRACE 2024/09/11 23:16:23 modbus: recv
[modbus] TRACE 2024/09/11 23:16:23 modbus: send 01 04 00 48 00 02 f1 dd
[modbus] TRACE 2024/09/11 23:16:23 modbus: recv 01 04 04 41 91 3b 64 ac 8e
Power:  read failed: serial: timeout
Energy: 18.2kWh

What type of operating system are you running?

Linux

Nightly build

  • I have verified that the issue is reproducible with the latest nightly build

Version

evcc version 0.130.9

@andig andig added question Rather clarification than issue labels Sep 12, 2024
@andig
Copy link
Member

andig commented Sep 14, 2024

Probier mal bitte z.B. 100ms delay.

@andig
Copy link
Member

andig commented Sep 15, 2024

Also see #15196 and #15437

@github-actions github-actions bot added the stale Outdated and ready to close label Sep 22, 2024
@premultiply
Copy link
Member Author

premultiply commented Sep 23, 2024

Schon mit delay: 10ms funktioniert es bei mir dann problemlos als custom Meter.
Also muss da irgendwo noch der Hund begraben sein...

meters:
- name: charger
  type: template
  template: eastron
  usage: charge
  modbus: rs485serial
  id: 3
  device: /dev/ttyUSB0
  baudrate: 9600
  comset: "8N1"
- name: wp1
  type: custom
  power:
    source: modbus
    id: 1
    device: /dev/ttyUSB0
    baudrate: 9600
    comset: "8N1"
    delay: 10ms
    register:
      address: 0x0c # Active power
      type: input
      decode: float32
  energy:
    source: modbus
    id: 1
    device: /dev/ttyUSB0
    baudrate: 9600
    comset: "8N1"
    #delay: 10ms
    register:
      address: 0x48 # Import active energy
      type: input
      decode: float32
- name: wp2
  type: custom
  power:
    source: modbus
    id: 2
    device: /dev/ttyUSB0
    baudrate: 9600
    comset: "8N1"
    delay: 10ms
    register:
      address: 0x0c # Active power
      type: input
      decode: float32
  energy:
    source: modbus
    id: 2
    device: /dev/ttyUSB0
    baudrate: 9600
    comset: "8N1"
    #delay: 10ms
    register:
      address: 0x48 # Import active energy
      type: input
      decode: float32

@github-actions github-actions bot removed the stale Outdated and ready to close label Sep 23, 2024
@premultiply premultiply added bug Something isn't working and removed question Rather clarification than issue labels Sep 23, 2024
@premultiply
Copy link
Member Author

premultiply commented Sep 23, 2024

Ich kann auch diese Formel hier beim besten Willen nicht nachvollziehen: https://github.com/evcc-io/modbus/blob/980a0405c373b08e064517bc13ffa9eaa71391dd/rtuclient.go#L287-L300

Mal ganz davon abgesehen, dass man höchstens eine Mindestzeit berechnen kann bis der die Antwort sehr theoretisch vorliegen könnte, wird dabei völlig die unbekannte und vielleicht auch nicht konstante interne Verarbeitungszeit des Modbus-Geräts selbst ausser acht gelassen, die es braucht um die Antwort überhaupt lossenden zu können.

Die theoretische Dauer eines Bits auf der Leitung ist 1/Baudrate s.
Davon braucht man (Startbit+Datenbits+Paritätsbit+Stopbits)*n Bytes. Das jeweils für Anfragelänge + erwartete Antwortlänge (+ Verarbeitungszeit)

@andig
Copy link
Member

andig commented Sep 23, 2024

See MODBUS over Serial Line - Specification and Implementation Guide

Kann den Text auf dem Pad nicht raus kopieren.

@premultiply
Copy link
Member Author

See MODBUS over Serial Line - Specification and Implementation Guide

Schon klar und genau da steht etwas anderes als hier implementiert ist:

  1. Fehlt in der Formel die Übertragungszeit des Zeichens selbst (tChar + tChar*1.5 !)
  2. Fehlt das Delay tChar*3.5 VOR dem Senden auf dem Bus.

Insbesondere 2. dürfte hier zu den beobachteten Problemen führen, da hier derzeit direkt nach vollständigem Empfang der letzten Antwort sofort die nächste Anfrage auf den Bus getackert wird. Hier muss aber mindestens tChar*3.5 Ruhe sein.
Bei 9600 8N1 sind das alleine schon 3,64584 ms.

@RTTTC
Copy link
Contributor

RTTTC commented Sep 24, 2024

Huh!
Good catch!
I hope your fix will also eliminate the random timeout I have every few hours with my DIN charge controller :)

@andig
Copy link
Member

andig commented Sep 24, 2024

Das Characterdelay ist laut PDF zwischen den Characters. Warum fehlt da die Zeit des Zeichens selbst? Weil der Code es anders nutzt? Der PR sollte Upstream eröffnet werden. Wenn er dort nicht gemerged wird können wir das parallel auch tun.

@andig
Copy link
Member

andig commented Sep 24, 2024

Nvm. Wird anders verwendet.

@premultiply
Copy link
Member Author

Na weil das Zeichen selbst eben auch eine nicht vernachlässigbare Übertragungszeit hat.

Ich würde hier aber vermuten, dass dieses ganze Delay zwischen senden und empfangen ohnehin völlig egal ist, denn das Slave-Device antwortet ohnehin wann es will.
Solange das Timeout wesentlich größer als die Übertragungszeit ist spielt das somit eigentlich keine Rolle.

Ich würde daher vorschlagen noch das Zwischendelay entweder ganz zu entfernen oder zumindest auf die reine Char-Übertragungszeit + 2*t3.5 zu beschränken.
Die zusätzliche Addition eines maximal großen Inter-Char-Delay sorgt im Zweifelsfall nur für völlig unnötige Verzögerungen - die meisten Geräte dürften die Chars völlig lückenlos auf die Reise schicken.
Hier wäre mein Ansatz eher nur das minimale Delay zu berechnen und den verbleibenden Rest im Timeout auszugleichen.

Ferner würde ich das erstmal bei uns ausprobieren und dann ggf. erst Upstream mergen.

Ok?

@andig
Copy link
Member

andig commented Sep 24, 2024

Gerne lokal probieren. Dafür muss es nicht gemerged werden.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants