Hohe Latenz im Serial Port des Raspberry Pi

[Prof. Dr. Peter Henning]

Hallo Liste,

dieser Post richtet sich an erfahrene RPi-Anwender und hat nur indirekt mit FHEM zu tun.

Ich bin gerade dabei, die Ankopplung von FHEM an Heizungsanlagen mit EBus-Schnittstelle durchzuführen. Dabei wird die Software ebusd von Roland Jax auf einem separaten Raspberry Pi eingesetzt, sie greift im Moment direkt über den Serial Port des Raspberry auf diesen EBus zu. Die Datenrate ist dabei minimal: 2400 Baud. Und es wird nur gelesen, eine Einwirkung des RPi auf die Heizungsanlage findet derzeit nicht statt.

Wir haben nun ein Problem gefunden, das uns gemeinsam etwas irre macht: startet man dieses ebusd = EBUS Dämon, kommen die über den EBus einlaufenden Bytes immer später bei der Software an. Diese Verzögerung steigert sich bis zu mehreren Stunden.

Hier mal ein Auszug meiner Diskussion mit Roland Jax:

ebusd (neueste Version von github) läuft als

/usr/local/bin/ebusd -l All --device /dev/ttyAMA0

Angeschlossen ist eine Vaillant-Heizung neuester Bauart, mit DCF77
Funkuhr. Über den ebus geht alle 30 Sekunden auch die aktuelle Zeit als
broadcast (Adresse fe). Kommando dafür in meiner command.csv

c broad date_time_temp

ebusd erkennt den zugehörigen Binärstring problemlos.

Allerdings werden die Werte nur mit zunehmender Versögerung in den Puffer
übernommen, den man mit 

ebusctl cyc broad date_time_temp

ausliest. Direkt nach dem Neustart von ebusd (eben um 15:40) stimmt die
Zeit mit der realen Zeit überein. Aber beispielsweise bekomme ich jetzt
(15:45) durch dieses Kommando den return

Sat 01.11.2014 15:42:36 15.375

das heißt, der Wert ist etwa 3 Minuten alt.

Um 15:49 abgefragt erhalte  ich

Sat 01.11.2014 15:44:17 15.375

Die Verzögerung ist jetzt schon auf 5 Minuten angewachsen.

Diese Verzögerung betrifft auch alle anderen zyklisch über den Bus
gehenden Werte - und sie wächst an bis zu mehreren Stunden. Das kann man
sehr schön im Plot sehen, denn ich messe z.B. die Vorlauftemperatur der
Heizung separat - und kann sehen, wie die vom ebus geholten Werte immer
stärker zurückhängen.

Ich habe deshalb derzeit einen cronjob laufen, der den ebusd alle 10
Minuten neu startet.

Echt irre - es wirkt auf mich so, als ob der ebusd immer länger
benötigt, um die aktuell empfangenen Werte in diesen Puffer zu
übernehmen.

Das gleiche gilt, wenn ich den ebusd im foreground laufen lasse.

Derzeit habe ich testweise den Neustart alle 10 Minuten blockiert, der
ebusd läuft jetzt etwa 15 Minuten. Ortszeit (frisch gesetzt mit
ntpdate), und auch DCF77-Zeit, frisch kontrolliert auf der Vaillant-
Heizung ist 16:15.

Sat 01.11.2014 16:07:58 15.375

Lassen wir die Kiste also mal laufen ... Abfrage um 16:19 ergibt

Sat 01.11.2014 16:10:45 15.375

und um 16:20 wechselt der Wert auf

Sat 01.11.2014 16:11:20 15.125

und um 16:22 wechselt der Wert auf

Sat 01.11.2014 16:11:51 15.125

und um 16:23 wechselt der Wert auf

Sat 01.11.2014 16:12:56 15.125

Wohlgemerkt laufen diese Daten bei dem ebusd wirklich verspätet ein, der interne Bus-Tracer vermerkt z.B. um 17:33 den Eingang der Daten von 16:51. Nun könnte man annehmen, dass der ebusd den Eingangspuffer der seriellen Schnittstelle nicht richtig leert und dieser darum anwächst. Stoppt man aber den Datenstrom von außen, holt der ebusd nicht etwa weiter Daten aus dem möglicherwiese noch vollen Puffer.

Hat jemand so etwas schon einmal erlebt ? Irgendeine konkrete Idee, woran das liegen könnte ?

LG

pah

[Rince]

Nein.
Aber hast du mal versucht das ganze mit einem seriell/USB Wandler am Raspberry zu betreiben?
Damit würde die GPIO Geschichte quasi rausfallen.
Irgendwo muss man ja anfangen mit Fehler eingrenzen

(Der Speicherverbrauch dürfte auch spannend sein; vielleicht läuft da irgend ein Puffer voll)

[Prof. Dr. Peter Henning]

Der externe Wandler ist schon in der Post, das war auch mein erster Schritt. Die Fa. eservice war aber wohl im Urlaub...

An der Pufferfrage bin ich schon dran.

LG

pah

[PeMue]

Hallo pah,

bei mir läuft am Raspberry Pi ein CSM im rfmode MAX an der seriellen Schnittstelle. Momentan habe ich nicht beobachtet, dass es hier zu einer nennenswerten Zeitverzögerung kommt. Aber ich werde das mal beobachten.
Wie holt ihr denn die Daten an der seriellen Schnittstelle ab? Per Interrupt in einen Puffer? Oder per Polling?
Die Idee mit dem USB-seriell Wandler ist gut, da kann man sehen, ob es ein Hardware oder eher ein Softwareproblem ist.

Gruß PeMue

[Prof. Dr. Peter Henning]

Mein Verdacht war richtig.

Der "serielle Port" eines Raspberry Pi hat offenbar keinen dezidierten UART, sondern dieser wird an einem GPIO-Pin emuliert. Die Prozessorleistung reicht nicht aus, um die (dank fortlaufender Synchronisationsimpulse existierende) Dauerlast bei 2400 Bit/s auf dem angeschlossenen EBus in dieser Emulation zu verarbeiten. Das mag durchaus mit der Zugriffsmethode zusammenhängen - aber den Spaß, das auch noch zu erforschen, wollte ich mir nicht geben.

Als Folge davon füllt sich der Eingangspuffer - so weit, dass die Daten schließlich mit einer Verzögerung von bis zu 90 Minuten (!) weitergereicht werden. Setzt man einen UART/USB-Konverter für 4,95 € dazwischen und geht über den USB-Port in den Raspberry hinein, ist das Problem weg.

Ich finde das zwar leicht irre, denn bei richtiger Benutzung kann dieser serielle Port mit bis zu 115 kBit/s kommunizieren. Aber, wie gesagt: Da investiere ich lieber die 4,95 € als mehrere Stunden Arbeitszeit.

LG

pah