Hallo Zusammen,
ich habe bei Aufruf von Seiten im Webfrontend (und Floorplan) massive Probleme mit Delays (Konfiguration in Signatur). Ich habe mir das mit perfmon angeschaut. Leider sagen mit die entsprechenden Log-Ausgaben, die vor den Delays auftauchen, nicht viel:
2014.03.26 09:37:39.991 4: HTTP FHEMWEB:192.168.2.110:53898 GET /fhem/floorplan/EG_1?XHR=1&inform=type=status;filter=room=all×tamp=1395823059966
2014.03.26 09:37:40.598 5: SET: Unknown argument ?, choose one of burstXmit clear:readings,register,rssi,msgEvents fwUpdate getConfig getRegRaw inhibit:on,off pair raw regB
ulk regSet reset sysTime unpair
Unknown argument ?, choose one of burstXmit clear:readings,register,rssi,msgEvents fwUpdate getConfig getRegRaw inhibit:on,off pair raw regBulk regSet reset sysTime unpair
Unknown argument ?, choose one of burstXmit clear:readings,register,rssi,msgEvents fwUpdate getConfig getRegRaw inhibit:on,off pair raw regBulk regSet reset sysTime unpair
Unknown argument ?, choose one of burstXmit clear:readings,register,rssi,msgEvents fwUpdate getConfig getRegRaw inhibit:on,off pair raw regBulk regSet reset sysTime unpair
2014.03.26 09:37:44.852 5: SET: Unknown argument ?, choose one of burstXmit clear:readings,register,rssi,msgEvents controlManu:on,off,5.0,5.5,6.0,6.5,7.0,7.5,8.0,8.5,9.0,9.
5,10.0,10.5,11.0,11.5,12.0,12.5,13.0,13.5,14.0,14.5,15.0,15.5,16.0,16.5,17.0,17.5,18.0,18.5,19.0,19.5,20.0,20.5,21.0,21.5,22.0,22.5,23.0,23.5,24.0,24.5,25.0,25.5,26.0,26.5,
27.0,27.5,28.0,28.5,29.0,29.5,30.0 controlMode:auto,manu,boost,day,night controlParty desired-temp:on,off,5.0,5.5,6.0,6.5,7.0,7.5,8.0,8.5,9.0,9.5,10.0,10.5,11.0,11.5,12.0,1
2.5,13.0,13.5,14.0,14.5,15.0,15.5,16.0,16.5,17.0,17.5,18.0,18.5,19.0,19.5,20.0,20.5,21.0,21.5,22.0,22.5,23.0,23.5,24.0,24.5,25.0,25.5,26.0,26.5,27.0,27.5,28.0,28.5,29.0,29.
5,30.0 getConfig getRegRaw inhibit:on,off peerBulk regBulk regSet sign:on,off sysTime tempListFri tempListMon tempListSat tempListSun tempListThu tempListTue tempListWed
Unknown argument ?, choose one of burstXmit clear:readings,register,rssi,msgEvents controlManu:on,off,5.0,5.5,6.0,6.5,7.0,7.5,8.0,8.5,9.0,9.5,10.0,10.5,11.0,11.5,12.0,12.5,
13.0,13.5,14.0,14.5,15.0,15.5,16.0,16.5,17.0,17.5,18.0,18.5,19.0,19.5,20.0,20.5,21.0,21.5,22.0,22.5,23.0,23.5,24.0,24.5,25.0,25.5,26.0,26.5,27.0,27.5,28.0,28.5,29.0,29.5,30
.0 controlMode:auto,manu,boost,day,night controlParty desired-temp:on,off,5.0,5.5,6.0,6.5,7.0,7.5,8.0,8.5,9.0,9.5,10.0,10.5,11.0,11.5,12.0,12.5,13.0,13.5,14.0,14.5,15.0,15.
5,16.0,16.5,17.0,17.5,18.0,18.5,19.0,19.5,20.0,20.5,21.0,21.5,22.0,22.5,23.0,23.5,24.0,24.5,25.0,25.5,26.0,26.5,27.0,27.5,28.0,28.5,29.0,29.5,30.0 getConfig getRegRaw inhib
it:on,off peerBulk regBulk regSet sign:on,off sysTime tempListFri tempListMon tempListSat tempListSun tempListThu tempListTue tempListWed
Unknown argument ?, choose one of burstXmit clear:readings,register,rssi,msgEvents controlManu:on,off,5.0,5.5,6.0,6.5,7.0,7.5,8.0,8.5,9.0,9.5,10.0,10.5,11.0,11.5,12.0,12.5,
13.0,13.5,14.0,14.5,15.0,15.5,16.0,16.5,17.0,17.5,18.0,18.5,19.0,19.5,20.0,20.5,21.0,21.5,22.0,22.5,23.0,23.5,24.0,24.5,25.0,25.5,26.0,26.5,27.0,27.5,28.0,28.5,29.0,29.5,30
.0 controlMode:auto,manu,boost,day,night controlParty desired-temp:on,off,5.0,5.5,6.0,6.5,7.0,7.5,8.0,8.5,9.0,9.5,10.0,10.5,11.0,11.5,12.0,12.5,13.0,13.5,14.0,14.5,15.0,15.
5,16.0,16.5,17.0,17.5,18.0,18.5,19.0,19.5,20.0,20.5,21.0,21.5,22.0,22.5,23.0,23.5,24.0,24.5,25.0,25.5,26.0,26.5,27.0,27.5,28.0,28.5,29.0,29.5,30.0 getConfig getRegRaw inhib
it:on,off peerBulk regBulk regSet sign:on,off sysTime tempListFri tempListMon tempListSat tempListSun tempListThu tempListTue tempListWed
Unknown argument ?, choose one of burstXmit clear:readings,register,rssi,msgEvents controlManu:on,off,5.0,5.5,6.0,6.5,7.0,7.5,8.0,8.5,9.0,9.5,10.0,10.5,11.0,11.5,12.0,12.5,
13.0,13.5,14.0,14.5,15.0,15.5,16.0,16.5,17.0,17.5,18.0,18.5,19.0,19.5,20.0,20.5,21.0,21.5,22.0,22.5,23.0,23.5,24.0,24.5,25.0,25.5,26.0,26.5,27.0,27.5,28.0,28.5,29.0,29.5,30
.0 controlMode:auto,manu,boost,day,night controlParty desired-temp:on,off,5.0,5.5,6.0,6.5,7.0,7.5,8.0,8.5,9.0,9.5,10.0,10.5,11.0,11.5,12.0,12.5,13.0,13.5,14.0,14.5,15.0,15.
5,16.0,16.5,17.0,17.5,18.0,18.5,19.0,19.5,20.0,20.5,21.0,21.5,22.0,22.5,23.0,23.5,24.0,24.5,25.0,25.5,26.0,26.5,27.0,27.5,28.0,28.5,29.0,29.5,30.0 getConfig getRegRaw inhib
it:on,off peerBulk regBulk regSet sign:on,off sysTime tempListFri tempListMon tempListSat tempListSun tempListThu tempListTue tempListWed
Unknown argument ?, choose one of burstXmit clear:readings,register,rssi,msgEvents controlManu:on,off,5.0,5.5,6.0,6.5,7.0,7.5,8.0,8.5,9.0,9.5,10.0,10.5,11.0,11.5,12.0,12.5,
13.0,13.5,14.0,14.5,15.0,15.5,16.0,16.5,17.0,17.5,18.0,18.5,19.0,19.5,20.0,20.5,21.0,21.5,22.0,22.5,23.0,23.5,24.0,24.5,25.0,25.5,26.0,26.5,27.0,27.5,28.0,28.5,29.0,29.5,30
.0 controlMode:auto,manu,boost,day,night controlParty desired-temp:on,off,5.0,5.5,6.0,6.5,7.0,7.5,8.0,8.5,9.0,9.5,10.0,10.5,11.0,11.5,12.0,12.5,13.0,13.5,14.0,14.5,15.0,15.
5,16.0,16.5,17.0,17.5,18.0,18.5,19.0,19.5,20.0,20.5,21.0,21.5,22.0,22.5,23.0,23.5,24.0,24.5,25.0,25.5,26.0,26.5,27.0,27.5,28.0,28.5,29.0,29.5,30.0 getConfig getRegRaw inhib
it:on,off peerBulk regBulk regSet sign:on,off sysTime tempListFri tempListMon tempListSat tempListSun tempListThu tempListTue tempListWed
^* matches null string many times in regex; marked by <-- HERE in m/^* <-- HERE .open$/ at ./FHEM/01_FHEMWEB.pm line 1966.
^* matches null string many times in regex; marked by <-- HERE in m/^* <-- HERE .closed$/ at ./FHEM/01_FHEMWEB.pm line 1966.
2014.03.26 09:37:46.184 1: Perfmon: possible freeze starting at 09:37:40, delay is 6.183
2014.03.26 09:37:46.190 0: HMLAN_Send: HMLAN1 I:K
2014.03.26 09:37:46.209 4: HTTP FHEMWEB:192.168.2.110:53901 GET /fhem/floorplan/B29_1?room=all
Kann damit jemand etwas anfangen? Der in diesem Log-Auszug angegebene Delay von 6,183 s ist eher ein kurzer Delay. Das kann auch bis zu 30 s hochgehen.
Wäre super, wenn da jemand einen Tip für mich hätte.
Danke und Gruß
Christoph
Hallo,
ich habe ebenfalls lange Hänger (bis zu 30 Sekunden), sowohl beim Aufbau der FHEMWEB-Seiten als auch in RSS.
Ich konnte diese bereits auf Hänger beim Abruf des Google-Kalenders und/oder der Yahoo-Wettervorhersage zurückführen: hereinkommender Datenverkehr vom entfernten Webserver stockt entsprechend lange und blockiert FHEM.
Tip: strace [-e trace=read,write] -r -p PIDvonfhem.p> 2>&1 | tee /tmp/strace.log
Wenn ich dazu komme, werde ich sowohl das Weather- als auch das Calendar-Modul auf asynchrone Kommunikation (nonblocking) umstellen und sehen, ob das was bringt.
Ich würde aber noch lieber wissen wollen, ob da ein Problem in meinem lokalen Netz vorliegt oder was die Ursache der Hänger auf der Socket-Verbindung ist. Das Lightning-Addin von Thunderbird, das ebenfalls meinen Google-Kalender abruft, läßt nämlich Thunderbird genau so hängen.
Grüße
Boris
Hallo Boris, da ich ebenfalls mit Yahoo Wetter und vielen RSS und Kalendern arbeite, kann ich zuverlässig sagen, dass ich die beschriebenen Verzögerungen hier noch nicht hatte.
Als ich noch den Yahoo Wetterdienst eingesetzt habe, hatte ich auch Verzögerungen von bis zu 10-11 Sekunden. Nachdem ich das raus genommen hatte, waren die Verzögerungen weg. Bis zu 30 Sekunden waren es nie.
Calendar (google) verzögert hin und wieder mal mit etwas über 1 Sekunde.
hallo christoph,
die fehlermeldungen
2014.03.26 09:37:40.598 5: SET: Unknown argument ?...
deuten darauf hin, dass ein set befehl abgesetzt werden soll, der befehl aber nicht ausgeführt werden kann, da er nicht gültig ist. entweder ein set befehl auf ein device, dass diesen nicht unterstützt, ein syntax fehler oder ein wert ausserhalb des erlaubten range. die fehlermeldung zeigt dir dann die erlaubten befehle an.
diese fehlermeldungen erhält man auch im webif. wenn du in der detailansicht eines devices bist, kannst du im set-pulldown-menü die erlaubten befehle zu diesem device erkennen.
da dies aber wohl im zusammenhang mit floorplan passiert, könnte es auch mit deiner floorplan definition zusammenhängen.
die fehlermeldungen, die ...,boost,... enthalten werden sich wohl auf einen hm-rt beziehen.
@all
ich hatte bis vor kurzem mit der funktion GetHttpFile verzögerungen im lokalen netz beim zugriff auf einen arduino mit ethernet. nach der umstellung (ersetzen) mit HttpUtils_NonblockingGet sind die verzögerungen verschwunden.
gruss frank
Die Fehlermeldungen haben vermutlich nichts mit den Delays zu tun, sondern kommen daher, dass 10_CUL_HM.pm keine korrekte Behandlung der Anfrage "set <device> ?" implementiert hat, die z.B. beim fhem-Start automatisch an jedes device geschickt wird.
Danke für die bisherigen Hinweise.
Weder Yahoo-Wetter noch google-Kalender werden von mir benutzt. Das scheidet also als Ursache aus.
Zitat von: Dr. Boris Neubert am 26 März 2014, 11:25:06
(..)
Ich würde aber noch lieber wissen wollen, ob da ein Problem in meinem lokalen Netz vorliegt oder was die Ursache der Hänger auf der Socket-Verbindung ist.
(...)
Ich habe auch den "Verdacht", dass es am lokalen Netz hängt. Weiß aber nicht so recht, wie ich diese Vermutung validieren kann bzw. das Problem fixen kann.
Zitat von: betateilchen am 26 März 2014, 12:44:36
Die Fehlermeldungen haben vermutlich nichts mit den Delays zu tun, sondern kommen daher, dass 10_CUL_HM.pm keine korrekte Behandlung der Anfrage "set <device> ?" implementiert hat, die z.B. beim fhem-Start automatisch an jedes device geschickt wird.
Diese Fehlermeldungen kommen aber nicht beim fhem-Start sondern beim Laden von Floorplan-Seiten. Und da sich meine Floorplans noch in der Entwicklung befinden sind die, bis auf Links und Dummy-Anzeigen abgesehen, noch leer.
Hallo,
ich habe zumindest jetzt das bei mir auftretende Problem verstanden: ich nutze RSS, welches jeweils alle Nase lang große Bilddateien per WLAN auf den Bilderrahmen sendet. Bei dem write auf den Socket kommt es zu Verbindungsabbrüchen und dann hängt write (und damit FHEM) bis zu 180 Sekunden, bevor es zum Abbruch der Verbindungsversuche kommt.
Ich habe nun den Bilderrahmen auf einen günstiger gelegenen Access Point verbunden habe. So richtig funktioniert das aber immer noch nicht.
Output von strace:
11.125163 write(95, "HTTP/1.1 200 OK\r\nContent-Length:"..., 8192) = 8192 <0.001822>
0.003297 write(95, "\0\353\324Q^\5\261\267\v&\331\342\231\2449\37w;1\374\217\345W_Q\205\374\240$X\204a"..., 8192) = 8192 <0.003374>
0.005275 write(95, "7\376>z6\24\36@=\375kIJ\376\254|\317q-\213#\264r.U\27s\373\1P\313\10"..., 8192) = 8192 <0.001366>
0.003844 write(95, "\215O\314L\303\357{d\377\0J\322Xjml7N/Vy\v\306\221]42e\6\365%N"..., 8192) = 8192 <0.000731>
0.003528 write(95, "\310\36\376\347\372\325\244\272\235\31\35\343f|\340\371}W\353\353Y\362\377\0\244\207\271\230\17\335\266\323"..., 8192) = 8192 <0.000739>
0.004095 write(95, "\226\313o\353\3603\213\327R\327\212&\220\\_Z\302\24\333\302\376q\30\301M\300\2?2\177:\344"..., 8192) = 8192 <0.239217>
0.242107 write(95, "\326\217d8\\,'\313\10\304`t9\375k\237vK\fy{\0366;U\207\361s\234\n\331{"..., 8192) = 8192 <0.019159>
0.022338 write(95, "\22G\34\36\335)\227R\313\4\204!b\212\252v\343\240\2536\220\315\35\274r\335L\250\347\34\0A"..., 8192) = 8192 <0.000188>
0.003807 write(95, "\264\267\35\354\254u\332v\204\267\242+\373\370Sk>\310{a\t\340\267\267\\U\215B\331\376\301\33"..., 8192) = 8192 <1.361662>
1.364537 write(95, "o\263fVwR\256v\20\276\371\254\334\224\265\356=75\204\360\215\"\332(\263\204\334[=Ei"..., 8192) = 8192 <0.000520>
0.003813 write(95, "\f\254\260\257\357\21@>fX\223\301\355\214U\302\355\353\320q\276\306ds%\265\2713\r\335Tl"..., 8192) = 8192 <1.851190>
1.853550 write(95, "M(\317\235\244\326\237\251\255\223WC\265'f\263vM\312\312\16\0\372\365\374\277\225c-\273\1\34"..., 8192) = 8192 <24.795349>
24.796562 write(95, "\360GG\36\242\275\233-\215\326\207\204\370\376\307T\262\326<\231\246\16\322.\360\352B\206\376\351\254\250"..., 8192) = 8192 <58.246348>
58.247603 write(95, "\7$\347\212\273{\243^h\367\263[\337DD\247\30\364\347\374\232\364[]\16\327F\376\317\266\201\v"..., 8192) = 5680 <139.485711>
139.486881 write(95, "\304\26\306\25\3730V\4\315(\16\301\370'\35\270\305@n>\314\220\307\246\227\331\v4\210\304\0K"..., 2512) = -1 EPIPE (Broken pipe) <0.001061>
Da auch Firefox ab und zu beim Surfen eine Gedenkminute einlegt, tippe ich immer noch auf ein Problem in der Netzwerkinfrastruktur (Switches).
Viele Grüße
Boris
Man kann das Schreiben mit addToWritebuffer($hash, $text) ueber das globale select laufen lassen, allerdings duerfen die Daten im "alten" Puffer 100k nicht ueberschreiten (Vorkehrung fuer longpoll auf Notebook in Standby) .
Zitat von: rudolfkoenig am 31 März 2014, 09:57:33
Man kann das Schreiben mit addToWritebuffer($hash, $text) ueber das globale select laufen lassen, allerdings duerfen die Daten im "alten" Puffer 100k nicht ueberschreiten (Vorkehrung fuer longpoll auf Notebook in Standby) .
Ähm, mir fehlen die Grundkenntnisse, diesen Hinweis zu verstehen. Ich habe mir die Zeilen ab 539 in FHEMWEB.pm angesehen (RSS liefert als Extension von FHEMWEB aus) und noch nicht einmal so recht verstanden, wo das Ergebnis $FW_RET in den Socket geschrieben wird (vermutlich ab Zeile 365).
Allerdings werden da 1,44 MB rübergeschubst. Wie ich Dich verstehe, wird der Puffer also nicht reichen?
Grüße
Boris
Wenn RSS per FWEXT realisiert ist, dann hast du wohl recht. Die 100kb gilt nur fuer die im Puffer bereits befindlichen Daten, falls es zutirfft, werden keine neuen Daten mehr angenommen