Gelöst: Bug? Content-Type z.T. falsch "plain/text" statt "text/html"

Begonnen von Aurel_B, 26 November 2023, 07:16:04

Vorheriges Thema - Nächstes Thema

Aurel_B

Hallo zusammen,

bei geschätzt jedem 5-10x wird die FHEM Seite nicht dargestellt sondern nur der Quelltext. Ein Neuladen im Browser liefert dann i.d.R. die richtige Darstellung. Ich verwende flex und dachte zuerst, es liegt daran (siehe Link). Was eigentlich nicht so Sinn macht denn es ist ja nur ein Style mit einer JS und 3 CSS Dateien. Und tatsächlich: eine Umstellung auf f18 zeigte das selbe Problem.

Anscheinend liegt es daran, dass z.T. fälschlicherweise als Content-Type" plain/text statt text/html zurückgeliefert wird:

korrekt
GET /fhem?room=Haushalt HTTP/1.1
Host: raspberry:8083
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:120.0) Gecko/20100101 Firefox/120.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
Accept-Language: en-GB,en;q=0.5
Accept-Encoding: gzip, deflate
Referer: http://raspberry:8083/fhem?room=Waermepumpe
DNT: 1
Sec-GPC: 1
Connection: keep-alive
Upgrade-Insecure-Requests: 1

HTTP/1.1 200 OK
Content-Length: 24172
Cache-Control: no-cache, no-store, must-revalidate
Content-Encoding: gzip
Access-Control-Allow-Methods: GET, POST, OPTIONS
Access-Control-Allow-Headers: Origin, Authorization, Accept
Access-Control-Allow-Credentials: true
Access-Control-Max-Age: 86400
Access-Control-Expose-Headers: X-FHEM-csrfToken
X-FHEM-csrfToken: csrf_656373881905459
Content-Type: text/html; charset=UTF-8

inkorrekt

GET /fhem?room=Haushalt HTTP/1.1
Host: raspberry:8083
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:120.0) Gecko/20100101 Firefox/120.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
Accept-Language: en-GB,en;q=0.5
Accept-Encoding: gzip, deflate
Referer: http://raspberry:8083/fhem?room=Waermepumpe
DNT: 1
Sec-GPC: 1
Connection: keep-alive
Upgrade-Insecure-Requests: 1

HTTP/1.1 200 OK
Content-Length: 83009
Cache-Control: no-cache, no-store, must-revalidate
Access-Control-Allow-Methods: GET, POST, OPTIONS
Access-Control-Allow-Headers: Origin, Authorization, Accept
Access-Control-Allow-Credentials: true
Access-Control-Max-Age: 86400
Access-Control-Expose-Headers: X-FHEM-csrfToken
X-FHEM-csrfToken: csrf_656373881905459
Content-Type: text/plain; charset=UTF-8

Bei der Forumssuche bin ich auf http://svn.fhem.de/trac/changeset/25685/trunk gestossen was irgendwie auch wieder mit flex zu tun haben scheint: https://forum.fhem.de/index.php?topic=126213.msg.

Vielleicht ist da immer noch nicht alles gefixt?

rudolfkoenig

Ich kann die "inkorrekt" Version nicht nachstellen, brauche ein Anleitung.
Ich gehe auch davon aus, dass es sich um eine seltene Kombination bei der FHEM Installation oder Zugriff handelt, sonst haetten wir hier mehr Meldungen.

Laut Code wird text/plain nur dann zurueckgeliefert, falls man beim Aufruf XHR=1 oder jsonp=1 gesetzt hat.
Das passiert zwar der dynamischen Abfrage von Attribut- oder Reading-Werten, das ist aber auch so gewollt.

Aurel_B

#2
Hallo Rudolf,

danke für deine Antwort. Ich konnte der Sache (gefühlt) etwas näher kommen: ich denke, es etwas mit der Antwortedauer des Servers zu tun, deshalb fällt es bei meiner Konstallation (Raspberry, komplexe FHEM Konfiguration, Flex Style) öfters oder erst überhaupt auf: jetzt habe ich gerade gemerkt, dass das Problem z.T. auch ist, dass als Content-Type "image/png" gesendet wird. Ich habe dir die entsprechnden Mitschnitte aus der Firefox Console samt Screenshots angehängt. Wenn du möchtest, so kann ich dir auch (privat) meine fhem.cfg zusenden.
Es scheint mir so, als ob FHEM (selten) fälschlicherweise den Content-Type aus einer "parallelen" Anfrage verwendet. Also aus einer XHR=1 resp. einer favicon Anfrage die unmittelbar/zeitgleich mit der Hauptseite angefordert wurde (siehe Screenshots).

Mit einer blanken FHEM Installation und dem f18 Style habe ich das Problem nicht. Auf einem schnelleren Intel Server mit Flex Style und meiner umfangreichen fhem.cfg habe ich das Problem gefühlt weniger oft (der braucht auch nur ca. 1/3 der Zeit für die Seitenauslieferung). Verwende ich nur Flex auf dem Intel Server und fhem.cfg.demo tritt das Problem überhaupt nicht auf.

Ich hoffe, ich konnte das Problem etwas schildern. Irgendwie scheint FHEM intern etwas durcheinanderzubringen wenn es lange braucht, um die Hauptseite auszuliefern (und parallel dessen vielleicht weitere Anfragen mit anderem Content-Type eintrudeln?).

Besten Gruss & vielen Dank für FHEM, eine absolut phantastische Sache!


text/html
Du darfst diesen Dateianhang nicht ansehen.
text/plain
Du darfst diesen Dateianhang nicht ansehen.
image/png
Du darfst diesen Dateianhang nicht ansehen.Du darfst diesen Dateianhang nicht ansehen. 
Du darfst diesen Dateianhang nicht ansehen.

rudolfkoenig

ZitatEs scheint mir so, als ob FHEM (selten) fälschlicherweise den Content-Type aus einer "parallelen" Anfrage verwendet.
FHEMWEB ist (bis auf wenige Ausnahmen) single threaded, im gezeigten Beispiel sollte Multi-Threading keine Rolle spielen.

Kannst Du bitte Folgendes noch testen:
attr TYPE=FHEMWEB plotEmbed 0
attr TYPE=FHEMWEB longpoll websocket
und wenn möglich, statt Firefox auch mit Chrome testen.

ZitatWenn du möchtest, so kann ich dir auch (privat) meine fhem.cfg zusenden.
Möchten ist übertrieben, ich kann aber anbieten, einen Versuch zu starten.
Bin nicht sicher, ob das mangels Hardware sinnvolle Ergebnisse produziert.

Aurel_B

plotEmbed war bereits 0, longpoll habe ich von "1" auf "websocket" umgestellt. Mit Chrome habe ich den Fehler auch (siehe Screenshots). Ich habe wirklich das Gefühl, das hier eine ungünstige Verkettung (langsame Hardware, komplexe fhem.cfg, aufwändiger Style -> Lange Ladezeit) zusammenkommen. Ich sende dir eine (zensierte) fhem.cfg zu, ich konnte mit dieser das Problem auch auf meinem viel schnelleren Intel Server nachstellen auch ohne korrekt funktionierende Hardware (diese ist immer noch am Pi angeschlossen und wird irgendwann umgestellt auf den Intel).

Du darfst diesen Dateianhang nicht ansehen.
Du darfst diesen Dateianhang nicht ansehen.

Aurel_B

@rudolfkoenig: leider kann ich dir keine privaten Nachrichten zusenden, deshalb hier eine (zensierte) fhem.cfg: https://drive.google.com/file/d/1ae07xBW2WtdNafmSl1hc69WvY6ecU7gE/view?usp=sharing.

Ich habe alle IPs, URLs, API Keys etc. entfernt.

rudolfkoenig

Zitat@rudolfkoenig: leider kann ich dir keine privaten Nachrichten zusenden, deshalb hier eine (zensierte) fhem.cfg
Danke, habs abgeholt, kann entfernt werden.
Ich bin ueber die im Impressum erwaehnte Email-Adresse erreichbar.


Wie befuerchtet hilft diese fhem.cfg nicht weiter: ich kann das Problem nicht reproduzieren.
Die Darstellung der Raeume klappt auf den ersten Blick fehlerfrei, mit wenig Verzoegerung, natuerlich ohne sinnvolle Daten oder Grafiken.
Und das trotz einer 100% Auslastung der CPU, was ich (noch) nicht erklaeren kann.
Womoeglich liegt die Auslastung an den vielen nicht angeschlossenen Geraeten, oder an den fehlenden Funktionen in meiner Version von 99_myUtils.pm. Das FHEM-Log besteht aus regelmaessig blockweise erzeugte Fehlermeldungen.

Aurel_B

#7
Hallo Rudolf, danke dir! Ich denke, die 100% kommen von den vielen ModbusAttr Devices, die werden alle recht oft abgefragt. Wie lange braucht es bei dir, bis die Seite angezeigt wird (z.B. "Heizung")? Bei meinem Raspberry geht das schon 4-5s, auf dem Intel 1.5s. Beim Raspberry habe ich den Fehler wesentlich öfter (gefühlt jeder 10 Aufruf). Beim Intel braucht es schon mehrere Anläufe. Ich lade die Seite jeweils so oft mit Ctrl-R neu, bis der Fehler angezeigt wird. Vielleicht kannst du es so reproduzieren?

Falls nicht könnte ich dir auch einen SSH Zugang auf meinen Raspberry geben, da ist genügend Vertrauen von mir da :-)

Ich schaue mal selber in 01_FHEMWEB.pm nach, ob ich etwas finde was uns auf die richtige Spur bringen könnte.

Beste Grüsse,

Aurel

Aurel_B

Ah ich habs! Drück mal während dem Reload wie wild auf die "Save" Taste -> da werden parallel dann ja ganz viele Requests an fhem?cmd=save mit XHR=1 abgesetzt. So bekomme ich den Fehler viel öfters. Im Log sieht das dann so aus (WEB mit verbose=4):

Korrekt
2023.11.30 15:19:45.687 4: Connection accepted from WEB_192.168.1.1_42581
2023.11.30 15:19:46.088 4: WEB_192.168.1.1_42581 GET /fhem?room=Haushalt; BUFLEN:0
2023.11.30 15:19:46.537 4: WEB:  / RL:24099 / text/html; charset=UTF-8 / Content-Encoding: gzip
 / Cache-Control: no-cache, no-store, must-revalidate
 2023.11.30 15:22:09.833 4: WEB_192.168.1.1_56381 GET /fhem?room=Haushalt; BUFLEN:0

Inkorrekt
2023.11.30 15:22:09.833 4: WEB_192.168.1.1_56381 GET /fhem?room=Haushalt; BUFLEN:0
2023.11.30 15:22:09.910 4: WEB_192.168.1.1_26450 POST /fhem?cmd=save&XHR=1&fwcsrf=csrf_278738545367956&fw_id=1701354111.77246; BUFLEN:0
2023.11.30 15:22:10.020 4: WEB: /fhem?cmd=save&XHR=1&fwcsrf=csrf_278738545367956&fw_id=1701354111.77246 / RL:52 / text/plain; charset=UTF-8 / Content-Encoding: gzip
 / Cache-Control: no-cache, no-store, must-revalidate

2023.11.30 15:22:10.021 4: WEB_192.168.1.1_41700 POST /fhem?cmd=save&XHR=1&fwcsrf=csrf_278738545367956&fw_id=1701354111.77246; BUFLEN:0
2023.11.30 15:22:10.103 4: WEB: /fhem?cmd=save&XHR=1&fwcsrf=csrf_278738545367956&fw_id=1701354111.77246 / RL:52 / text/plain; charset=UTF-8 / Content-Encoding: gzip
 / Cache-Control: no-cache, no-store, must-revalidate

2023.11.30 15:22:10.104 4: WEB_192.168.1.1_54306 POST /fhem?cmd=save&XHR=1&fwcsrf=csrf_278738545367956&fw_id=1701354111.77246; BUFLEN:0
2023.11.30 15:22:10.186 4: WEB: /fhem?cmd=save&XHR=1&fwcsrf=csrf_278738545367956&fw_id=1701354111.77246 / RL:52 / text/plain; charset=UTF-8 / Content-Encoding: gzip
 / Cache-Control: no-cache, no-store, must-revalidate

2023.11.30 15:22:10.187 4: WEB_192.168.1.1_65293 POST /fhem?cmd=save&XHR=1&fwcsrf=csrf_278738545367956&fw_id=1701354111.77246; BUFLEN:0
2023.11.30 15:22:10.268 4: WEB: /fhem?cmd=save&XHR=1&fwcsrf=csrf_278738545367956&fw_id=1701354111.77246 / RL:52 / text/plain; charset=UTF-8 / Content-Encoding: gzip
 / Cache-Control: no-cache, no-store, must-revalidate

2023.11.30 15:22:10.277 4: Connection closed for WEB_192.168.1.1_53177: EOF
2023.11.30 15:22:11.159 4: WEB_192.168.1.1_34460 POST /fhem?cmd=save&XHR=1&fwcsrf=csrf_278738545367956&fw_id=1701354111.77246; BUFLEN:0
2023.11.30 15:22:11.241 4: WEB: /fhem?cmd=save&XHR=1&fwcsrf=csrf_278738545367956&fw_id=1701354111.77246 / RL:52 / text/plain; charset=UTF-8 / Content-Encoding: gzip
 / Cache-Control: no-cache, no-store, must-revalidate

2023.11.30 15:22:11.629 4: WEB:  / RL:24097 / text/plain; charset=UTF-8 / Content-Encoding: gzip
 / Cache-Control: no-cache, no-store, must-revalidate

Irgendwo müssen ja weitere Anfragen in einer Art Queue landen wenn fhem hauptsächlich single-threaded ist und noch die erste Anfrage am abarbeiten ist. Wird da eventuell etwas durcheinandergebracht?

rudolfkoenig

Ich konnte das Problem mit haeufigen refresh reproduzieren.

Ursache des Problems ist die Einstellung "plotembed 0, plotfork 1", damit sind Probleme bei genau solchen Umgebungen bekannt.
Das war mein erster Versuch ohne <embed> Tags die Plot-Berechnung zu parallelisieren. <embed> macht Probleme beim Verschieben der Elemente in f18.
Mein Zweiter Versuch war "plotEmbed 2", damit gibt es in f18 keine Probleme, und ist die Voreinstellung auf Mehrprozessorrechner.

Soweit ich sehe, funktioniert "plotEmbed 2" aber nicht mit flex, weiss nicht wieso.

Ich sehe mit flex keine Probleme mit
- "plotEmbed 0, plotfork 0" (SVG Berechnung ist damit sequentiell)
- "plotEmbed 1, plotfork 0" (mit <embed>, immer noch sequentiell)
- "plotEmbed 1, plotfork 1" (mit <embed>, parallelisiert)

Aurel_B

Alles klar, danke dir vielmals! Ich habe jetzt "plotEmbed 0, plotfork 0" verwendet da so die Darstellung unverändert ist und die Ladezeiten sich nicht (spürbar) verlängert haben.
Der Fehler scheint wirklich verschwunden zu sein, trotz "draufhämmern" auf den Save Button bei Neuladen läuft alles korrekt und der Fehler tritt nicht mehr auf, super!
Ich schreib das noch in den Flex Thread damit die Flex-Benutzer Bescheid wissen.