cgi-bin/r? liefert leere Response

[Chris M.]

Mit der neuen CometVisuClient.js verhält sich die Visu deutlich besser, jedoch scheint das Problem noch nicht gelöst (Browser cache wurde geleert!). Wenn keine Antwort auf t=0 kommt, folgt gleich die nächste Anfrage und die Werte werden schneller nachgeladen (davor immer 1 Minute Wartezeit). In der Console konnte ich jedoch häufiger beobachten, dass die erste Anfrage unbeantwortet bleibt. Angefügt ein Screenshot als Extremfall (wieder eine Häufung von leeren Antworten). Ich musste die Visu jedoch häufiger neuladen, um diese Situation zu erhalten.

Sagt dir der Fehler "preseerror! Read undefined" etwas?

Ja das sagt mir was, genau da habe ich bei der Datei nämlich angesetzt und was Du hier siehst ist die Instruementierung um zu sehen, ob auch dass passiert was ich vermute

Bei mir kann ich das Verhalten nur so provozieren, dass ich eine Config verwende, die nur eine GA hat, die sicher nicht im Cache des eibd/knxd liegt. Dann antwortet der eibd mit einer leeren Antwort.
Dies führt nun dazu, dass der AJAX-Read-Request an den Error-Handler übergeben wird (den es im übrigen beidem Code-Pfad für enableQueue gar nicht gab...). Da der Error-Handler aber eine gültige HTTP-Antwort bekommt - schließlich liegt hier ja ein parseerror vor - hat der bestehende Code diesen Fehler ignoriert und die Kommunikation kam zum erliegen. Nach ca. 60 Sekunden sieht der Watchdog, dass es ja gar keine Kommunikation mehr gibt und fängt wieder von vorne an.
Sollte es nun wieder nur eine leere Antwort geben, heißt es nochmal 60 Sekunden warten. Etc. pp...

Die oben angehängte Version handled nun den parseerror in dem sofort einfach nochmal gefragt wird. (Um hier einen z.B. aktuell überlasteten Server nicht noch mehr in die Bredouille zu bringen wird dafür gesorgt, dass mindestens 1 Sekunde zwischen den Requests liegt)

Was natürlich nicht gelöst ist, ist das Thema, dass das Backend eine leere Antwort schickt. Der Code hier geht nur damit (hoffentlich) besser um.

Aber was ich nicht verstehe, ist warum es in der 0.9.2 funktioniert.

Ja, das ist eine spannende Frage. Hier habe ich noch nicht nachgeforscht. Bevor der Fix offiziell wird, werde ich mir das Thema aber nochmal ansehen, nicht das wir uns eine Regression einfangen.

Der Code ist an der Stelle der selbe im CometVisu-Client. Dann kann es eigentlich nur an der aktualisierten jQuery Version liegen (0.9.2 => 1.8.3 und 0.10.0 => 2.2.3). Das würde auch erklären warum das in 0.11.0 nicht auftritt, weil dort kein jQuery mehr benutzt wird.

Das ist ein interessanter Ansatz!

Und was auch ganz interessant zu wissen wäre, ist warum das Backend überhaupt leere Antworten schickt, denn das aus meiner Sicht ist der eigentliche Fehler.

Wenn der Cache leer ist, dann kann ich das irgendwie nachvollziehen (der Logik nach, ich müsste aber mal in den Code schauen um das genau zu verstehen).
Aber wenn die Config auch nur eine GA enthält, die sicher im Cache liegt - z.B. weil die regelmäßig gesendet wird - kann ich mir so ein Verhalten auch nicht erklären.

[Robert_Mini]

Auch bei mir => sehr gut, nur in Ausnahmefällen dauert es 6-7s (was immer noch schneller als 0.9.2 ist), meist viel flotter.
Soll ich noch mit wireshark aufzeichnen, oder hilft das im Moment nicht?

Danke für euren Einsatz zu diesem Thema!!
Robert

[Chris M.]

Um meine Theorie final zu bestätigen kannst Du mal einen dieser 6-7 Sekunden-Fälle in WireShark aufzeichnen, dazu das Konsolen-Log und ggf. die Netzwerk-Sicht vom Browser.

Falls nicht, werde ich trotzdem die obige Datei noch bereinigen und zum Testen bereitstellen

[Robert_Mini]

Mach ich heute Abend.
Robert

[Robert_Mini]

Wireshark ist online mit 2017-03-23_xxxx:
https://www.dropbox.com/sh/lldzqubmu...8BOy0zcLa?dl=0

Robert

[Chris M.]

OK, danke. Sieht passend aus

Hier noch die Datei, für die ich den Pull-Request stellen werde, wenn ein Test von Euch i.O. sagt.

(Änderung: Debugging-Instrumentierung ist wieder draußen und die Request-URL ist umgebaut um auch bei abgeschnittenen Text leichter zu sehen was wichtig ist)

[Robert_Mini]

Funktioniert soweit wie es sein soll.
Man merkt eigentlich nur, dass manchmal die Stati zuerst laden => perfekt und manchmal zuerst die rsslog und dann die Stati => hier schlägt das erneut lesen zu. Ist aber immer noch besser als die 0.9.2 und damit produktiv voll nutzbar.

Danke für deinen Einsatz!!!
lg Robert

[mivola]

Hier noch die Datei, für die ich den Pull-Request stellen werde, wenn ein Test von Euch i.O. sagt.

Ich werde versuchen heute abend nochmal zu testen...

[mivola]

Ich werde versuchen heute abend nochmal zu testen...

Also bei mir sieht es damit auch sehr gut aus!
Danke!!

[Chris M.]

Auch wenn das Thema erst mal gelöst ist, in dem Kontext war ja eine Frage, ob das rsslog hier evtl. durch eine zu hohe Load mit reinspuckt.

XueSheng und Robert_Mini könnt ihr mal nachsehen wie viele Einträge im rsslog liegen?
-> http://wiregate/cometvisu/plugins/rs...sslog.php?dump -> Die Zahl in der letzten Zeile hinter dem sum

Bei mir hatte gerade die rssdemo mal wieder sehr gebremst - die hat aber auch viele Requests parallel offen. Und nach dem ich von fast 10k Einträgen die alten gelöscht habe und nun bei 250 Einträgen bin flutscht es wieder...

[Robert_Mini]

Ich kann gerne nachsehen, aber 10k sind es bestimmt.
Hatte aber auch eine config ohne rsslog getestet, da gab es das gleiche Verhalten.

Robert

[Chris M.]

Bei meiner Frage ging's nicht um das Verhalten - das haben wir ja inzwischen gelöst.
Ich wollte nur mal schauen, ob das ggf. als Ursache (ggf. auch nur als ein Teil davon) in Frage kommt. Da wäre es dann ausreichend, wenn auch nur ein Gerät parallel eine Visu offen hätte wo RSSLog verwendet wird.

In https://github.com/OpenAutomationPro...CleanRSSLog.pl habe ich übrigens gerade mal ein Plugin veröffentlicht, dass die alten Daten weglöscht.

[XueSheng]

XueSheng und Robert_Mini könnt ihr mal nachsehen wie viele Einträge im rsslog liegen?
-> http://wiregate/cometvisu/plugins/rs...sslog.php?dump -> Die Zahl in der letzten Zeile hinter dem sum

Es sind auf jeden Fall jede Menge Einträge. Zeitüberschreitung bei Aufruf:

Fatal error: Maximum execution time of 30 seconds exceeded in /var/www/CometVisu_release_0.10.1/plugins/rsslog/rsslog.php on line 89

In https://github.com/OpenAutomationPro...CleanRSSLog.pl habe ich übrigens gerade mal ein Plugin veröffentlicht, dass die alten Daten weglöscht.

Alte Daten löschen? Muss das?
Wäre es nicht eine Option die alten Daten zu archivieren (z.B. in einer separaten Datenbank)?

[Chris M.]

Es sind auf jeden Fall jede Menge Einträge. Zeitüberschreitung bei Aufruf:

Ui, dann wundert es mich nicht, dass es bei einem Aufruf der Visu zu Problemen kommen kann, wenn da auch noch ein RSSLog mit im Spiel ist.

Der Dump macht intern eigentlich genau das gleiche wie ein Laden des RSSLog. Weitere Optimierungen sind im PHP Code eigentlich nicht möglich, evtl. lässt sich aber noch etwas an der Datenbank drehen.

Alte Daten löschen? Muss das?
Wäre es nicht eine Option die alten Daten zu archivieren (z.B. in einer separaten Datenbank)?

Nö, keiner muss löschen. Du musst halt nur überlegen wie Du damit umgehen möchtest. Für die meisten dürfte Löschen am einfachsten und dennoch ausreichend sein (im Plugin ist einstellbar wie lang die Daten behalten werden sollen. Unverändert wären es 31 Tage).

Da es eine normale, simple sqlite Datenbank ist kannst Du damit natürlich machen was Du für sinnvoll erachtest. Alles was die Anzahl im Dump auf eine Menge reduziert die auch schnell zurück geliefert werden kann (sagen wir mal kleiner 1 Sekunde, optimal z.B. 1/4 Sekunde) sollte hilfreich sein.

[XueSheng]

Da es eine normale, simple sqlite Datenbank ist kannst Du damit natürlich machen was Du für sinnvoll erachtest. Alles was die Anzahl im Dump auf eine Menge reduziert die auch schnell zurück geliefert werden kann (sagen wir mal kleiner 1 Sekunde, optimal z.B. 1/4 Sekunde) sollte hilfreich sein.

Das Laden des rsslog dauert bei Start der CV rund 800ms (Datenbankabfrage in der Konsole <100ms). Das scheint für mich ok. Dass der komplette dump in ein timeout läuft sollte doch irrelevant sein.

Ich hatte seiner Zeit mal den Suchindex von "id" auf "t" geändert, wodurch die Abfrage bei der veralteten sqlite Version des wiregate stark beschleunigt wurde (gibt hier auch irgendwo einen Thread dazu).