FHEM Forum

FHEM - Hausautomations-Systeme => Sonstige Systeme => Thema gestartet von: fhemputty am 11 Oktober 2015, 13:54:17

Titel: SuperJeeLink + LaGrosse --> hoher CPU Verbrauch durch viel USB Verkehr
Beitrag von: fhemputty am 11 Oktober 2015, 13:54:17
Update 11.10.2015 / 20:20:
- Es scheint als ob FHEM sowie das 36_JeeLink.pm nichts für den Traffic können.
- es sieht danach aus, als ob der SuperJeeLink mit konstant 2000 Messages / s den PC anbrüllt.

Es stellt sich die Frage: warum ?

Fhem ist aktuell. SuperJeeLink auf aktuellen Stand geflashed. Problem ist auf verschiedenen Rechnern reproduzierbar.




Hallo zusammen,
ich hatte fhem in einer virtuellen Maschine unter QEMU betrieben. In Kombination mit dem SuperJeeLink und habe ich einen deutlichen CPU Verbrauchsanstieg festgestellt. Stoppt man FHEM oder detached man den USB Stick von der VM ist wieder Ruhe. Per USBMON sieht man sehr viel Traffic zwischen fhem und dem USB Subsystem.

QEMU (also den VM Betrieber) kann ich zwischenzeitlich ausschließen, da das gleiche Phänomen auch auf nativer Hardware auftritt.

Der SuperJeeLink wird per ftdi_sio angesprochen.

Der USBMON liefert folgende Meldungen:
ffff8800d71bd480 2162926556 S Bi:1:008:1 -115 512 <
ffff8800d71bd0c0 2162927557 C Bi:1:008:1 0 2 = 016a
ffff8800d71bd0c0 2162927559 S Bi:1:008:1 -115 512 <
ffff8800d71bd480 2162928555 C Bi:1:008:1 0 2 = 016a
ffff8800d71bd480 2162928557 S Bi:1:008:1 -115 512 <
ffff8800d71bd0c0 2162929582 C Bi:1:008:1 0 2 = 016a
ffff8800d71bd0c0 2162929584 S Bi:1:008:1 -115 512 <
ffff8800d71bd480 2162930557 C Bi:1:008:1 0 2 = 016a
ffff8800d71bd480 2162930560 S Bi:1:008:1 -115 512 <
ffff8800d71bd0c0 2162931555 C Bi:1:008:1 0 2 = 016a
ffff8800d71bd0c0 2162931558 S Bi:1:008:1 -115 512 <
ffff8800d71bd480 2162932558 C Bi:1:008:1 0 2 = 016a
ffff8800d71bd480 2162932560 S Bi:1:008:1 -115 512 <
ffff8800d71bd0c0 2162933558 C Bi:1:008:1 0 2 = 016a
ffff8800d71bd0c0 2162933561 S Bi:1:008:1 -115 512 <
ffff8800d71bd480 2162934570 C Bi:1:008:1 0 2 = 016a
ffff8800d71bd480 2162934571 S Bi:1:008:1 -115 512 <
ffff8800d71bd0c0 2162935557 C Bi:1:008:1 0 2 = 016a
ffff8800d71bd0c0 2162935559 S Bi:1:008:1 -115 512 <
ffff8800d71bd480 2162936557 C Bi:1:008:1 0 2 = 016a
ffff8800d71bd480 2162936559 S Bi:1:008:1 -115 512 <
ffff8800d71bd0c0 2162937556 C Bi:1:008:1 0 2 = 016a
ffff8800d71bd0c0 2162937558 S Bi:1:008:1 -115 512 <
ffff8800d71bd480 2162938554 C Bi:1:008:1 0 2 = 016a
ffff8800d71bd480 2162938556 S Bi:1:008:1 -115 512 <
ffff8800d71bd0c0 2162939557 C Bi:1:008:1 0 2 = 016a
ffff8800d71bd0c0 2162939559 S Bi:1:008:1 -115 512 <
ffff8800d71bd480 2162940555 C Bi:1:008:1 0 2 = 016a
ffff8800d71bd480 2162940557 S Bi:1:008:1 -115 512 <
ffff8800d71bd0c0 2162941556 C Bi:1:008:1 0 2 = 016a
ffff8800d71bd0c0 2162941558 S Bi:1:008:1 -115 512 <
ffff8800d71bd480 2162942557 C Bi:1:008:1 0 2 = 016a


2.Wort = Timestamp
3.Wort = (S)ubmission / (C)allback

Man sieht: Zwischen Submission und Callback geht etwas mehr Zeit drauf. Zwischen Callback und Submission so gut wie keine...deshalb schätze ich dass fhem nach jeder Submission sofort wieder nach dem aktuellen Status frägt. Es könnte natürlich auch das perl sein und fhem ist gar nicht der Verursacher ;_)

Als nächstes werde ich das 36_JeeLink.pm mit debug Meldung beglücken, vielleicht wird´s dann klarer...vielleicht kann man auch dem Perl mitteilen, dass es seine aktivitäten mit dem USB Stick protokollieren soll...

Soweit mein aktueller Debug-Status...hatte das schon mal einer von euch ?

Grüße
Thorsten
Titel: Antw:SuperJeeLink + LaGrosse --> hoher CPU Verbrauch durch viel USB Verkehr
Beitrag von: HCS am 12 Oktober 2015, 21:36:03
Irgendwo (aber wo?) habe ich gelesen, dass der 3.13.0.65 Kernel wohl Probleme mir der Seriellen hat.

Nur um auch den Sketch auszuschließen. Bist Du in der Lage, einen minimal-Sketch zu erstellen, der alle paar Sekunden mal was über die Schnittstelle schickt?
Falls nicht, dann mache ich Dir einen.
Titel: Antw:SuperJeeLink + LaGrosse --> hoher CPU Verbrauch durch viel USB Verkehr
Beitrag von: fhemputty am 12 Oktober 2015, 23:31:53
Auf dem System ist ein selbst gebackener 4.0.8 Kernel (gentoo 64Bit). Im Kernel sind CONFIG_USB_SERIAL und CONFIG_USB_SERIAL_FTDI_SIO eingeschaltet. Mit anderen Modulen wollte der FTDI nicht. Das Ganze läßt sich in einer VM mit 4.1.7 Kernel (der USB Source ist der gleiche) nachstellen. Und auf einem älterne OpenSuse ebenso.

Ich bin noch nicht in der Lage ein Sketch aus dem Ärmel zu schütteln.

Hier steht noch etwas wie man den USB Bus wach hält: http://www.ftdichip.com/Support/FAQs.htm#HwGen2.

An dem PC hängen noch andere USB Gerätchen die dieses Verhalten alle nicht zeigen. z.b. ein DS1490F.

Kannst du das Verhalten bei dir nachstellen ?  (modprobe usbmon und dann cat /sys/kernel/debug/usb/usbmon/0u; oder über wireshark, der kann auch USB).

Ich werd mal vesuchen das ftdi_sio.c zu verstehen...vielleicht erschließt sich mir dessen Verhalten anhand des Sourcecodes.

Grüße & Danke
Titel: Antw:SuperJeeLink + LaGrosse --> hoher CPU Verbrauch durch viel USB Verkehr
Beitrag von: HCS am 13 Oktober 2015, 21:47:44
Habe mich mal etwas mit beschäftigt.

Cubietruck mit  3.4.103-sun7i, JeeLink V3
Den traffic auf dem USB Port kann ich auch beobachten. Sobald der JeeLink drauf steckt ist er da.
Ob das gut, schlecht oder normal ist, vermag ich nicht zu beurteilen, in den Treiber-Abgründen kenne ich mich absolut nicht aus.
Aber ich kann keine Unterschied bezüglich der Last feststellen. Egal ob mit oder ohne JeeLink habe ich IDLE Werte zw. 90 und 99.

Zum weiteren test habe ich dann diesen Sketch geflasht (anstatt der LaCrosse firmware), der mit der Schnittstelle exakt nichts macht, nur die LED blinken lässt:
#include "Arduino.h"
#define LED_PIN 9
unsigned long lm = 0;

void loop(void) {
  digitalWrite(LED_PIN, 0);
  delay(50);
  digitalWrite(LED_PIN, 1);
  delay(1000);
}

void setup(void) {
  pinMode(LED_PIN, OUTPUT);
  digitalWrite(LED_PIN, 1);
}


Exakt das gleiche Verhalten.

Und jetzt wird es interessant:
wenn ich ein NodeMCU DevBoard dranstecke, das eine CP2102 UART bridge drauf hat, ist es nicht so. Da kommen ab und zu mal Daten vorbei, passend zur activity LED auf dem Board, die signalisiert, dass etwas empfangen wurde.
Ein JeeNode V5 mit einem FTDI-Kabel, das sich ebenfalls als CP210x UART Bridge meldet, das gleiche Verhalten.

Das hat meine Neugier erweckt, also mal einen Arduino nano dran, der hat einen FT232RL drauf. Ergebnis: Dauerfeuer.
Einen noname FTDI ohne irgendwas hinten dran gesteckt (ebenfalls mt FT232RL). Ergebnis: Dauerfeuer.

Und was hat ein JeeLink V3 drauf: klar, einen FT232RL.
Und Dein Clone? Must mal mit der Lupe nachlesen, aber es wird wohl ein FT232RL sein.

Ob das nun ein Problem ist? Keine Ahnung! Bei mir macht es keinen Unterschied, was die Last angeht.
Die ist mit allem, was ich eben dran hatte und mit nichts dran immer ungefähr gleich.
Titel: Antw:SuperJeeLink + LaGrosse --> hoher CPU Verbrauch durch viel USB Verkehr
Beitrag von: fhemputty am 13 Oktober 2015, 22:53:44
hallo,
der Clone hat auch einen FT232RL Chip drauf. Daraus folgt: das Dauerfeuer liegt am ftdi_sio Treiber in Kombination mit dem FT232RL.

Ich werde versuchen aus dem Treiber schlau zu werden.

Ob das Dauerfeuer stört: Hänge ich den USB Stick "direkt" an die VM geht deren Last merklich hoch (auch weil die Virtualisierung natürlich auch mitgestresst wird).
Hänge ich den Stick per ser2net an die VM ist nur etwas Traffic im Träger Linux zu sehen. gut, bei 1000 Meldungen in der Sekunde kommt die CPU halt nicht zu schlafen.

Ist es möglich auf so einen Clone einfach einen anderen (ftdi) RS232 nach USB Chip draufzulöten ?

Grüße & Danke
Titel: Antw:SuperJeeLink + LaGrosse --> hoher CPU Verbrauch durch viel USB Verkehr
Beitrag von: HCS am 13 Oktober 2015, 23:05:57
Zitat von: fhemputty am 13 Oktober 2015, 22:53:44
Ist es möglich auf so einen Clone einfach einen anderen (ftdi) RS232 nach USB Chip draufzulöten ?
Da tippe ich mal eher auf Nein.
Der CP2102 und der FT232RL habe ja schon mal völlig unterschiedliche Bauformen.
Und ein QFN package auflöten, hmmm...
Titel: Antw:SuperJeeLink + LaGrosse --> hoher CPU Verbrauch durch viel USB Verkehr
Beitrag von: fhemputty am 14 Oktober 2015, 22:26:34
Na da habe ich mich ja als Voll-Laie geoutet.

Ich habe etwas gelesen. Es sieht so aus, als ob das USB2 Protokoll als Mindestgranularität 1ms vorsieht sowie keine Interrupts kennt also immer pollen muß.
Es gibt lt. Wiki verschiedene Transfermodi: Isochroner (quasi Realtime), Interrupt (kein Wiederspruch, siehe unten) und Bulk.

Das Verhalten kommt wahrscheinlich so zustande:
- fhem, oder socat machen den ttyUSBx auf und lauschen
- da der FT232RL in seinem Endpoint Descriptor BULK stehen hat fragen die beteiligten KernelModule im Abstand von 1ms nach Daten
- der FS232RL antwortet auch immer brav mit den Daten aus seinem Buffer oder halt mit nix, wenn nix im Buffer steht.

Der Unterschied zur Tastatur oder zum OneWire-USB Adapter ist jedoch: diese stehen auf Interrupt-Transfertype. Dieser hat den entscheidenen Vorteil: man kann das Pollinginterval einstellen (wo wird noch geklärt)...so wird meine Tastatur z.B.: mit 10ms gepolled. So wie der OneWire Adapter auch. Wobei das noch nicht die ganze Wahrheit zu sein scheint....weil dann wäre mehr Traffic auf der Leitung.

Möchte man das aktuelle Verhalten ändern, müßte man...
- das Polling Interval vergrößern (nur wie und durch wen)
- oder das fhem / superjeelink-clone Protokoll dahingehend ändern, dass fhem nicht dauernd lauscht sondern nur periodisch alle bis dahin angefallenen Daten vom superjeelink abholt die der zwischenzeitlich intern gespeichert hat und zwar solange bis der jeelink wieder "leer" ist.

Grüße
Titel: SuperJeeLink + LaGrosse --> hoher CPU Verbrauch durch viel USB Verkehr
Beitrag von: fhemputty am 15 Oktober 2015, 19:31:09
Aktueller (abschließender) Status:
- der FT232RL kann nur USB Bulk. Punkt.
- den FT232RL auf Interrupt Transfermode umstellen geht nicht.
- Nur Bulk bedeutet, der Gerätetreiber frägt im 1ms Takt und bekommt eine leere oder eine gefüllte Antwort.

Also bleibt nur:
(1) den jeeLink nur hin und wieder in FHEM aktivieren
(2) oder Kommunikation zwischen Fhem und dem Sketch mit weniger Transfers realisieren

(2) --> bekomme ich jetzt so nicht aus dem Handgelenk geschüttelt
(1) --> über setstate xxx off hat es schonmal nicht geklappt. Gibts da was Schlaueres wie ich die Verbindung zum jeelink nur alle 5Minuten für 30Sekunden aufbauen kann ? Das würde mir von der Genauigkeit her reichen...selbst alle 10Minuten wäre ok....

Grüße
Titel: SuperJeeLink + LaGrosse --> hoher CPU Verbrauch durch viel USB Verkehr
Beitrag von: fhemputty am 27 Oktober 2015, 20:27:07
Noch ein abschließender Status:
- ich habe jetzt einen jeelink Clone mit CH340 drauf. (Linux Modul: ch341).
- Dieser meldet sich als "1a86:7523 QinHeng Electronics HL-340 USB-Serial adapter".
- Der spricht nicht dauernd mit dem jeelink sondern nur bei Bedarf.
- lsusb -v -d 1a86:7523   zeigt dazu die entscheidende Zeilen:

      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x81  EP 1 IN
        bmAttributes            3
          Transfer Type            Interrupt
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0008  1x 8 bytes
        bInterval               1


- den FT232RL konnte man nicht von seinem Bulk TransferType abbringen. Der Ch340 ist m.E. aufgrund seines Interrupt TransferTypes besser als Sensor->USB Wandler geeignet.

Es gibt allerdings einen klitzekleinen Wermutstropfen:
- die Menschen die diesen Chip entwickelt haben, sahen wohl keine Veranlassung eine eindeutige Seriennummer ins Silizium zu brennen. Das ist bei einem dieser Wandlerchips noch kein Problem. Aber spätestens mit dem 2.CH340 wünscht man sich doch eine Seriennummer um per udev Regel die verschiedenen Gerätchen unterscheiden zu können, insbesondere wenn man andere USB Ports verwenden will.

Grüße