FHEM auf Fritzbox 7490 langsam nach write

Invers · 26 Dezember 2013, 10:15:22

Ich habe seit neuestem das Problem, dass FHEM Minuten zum Aufruf einer Seite braucht, nachdem ich save config gemacht habe.
Vorher läuft immer alles perfekt und schnell. Ändere ich die Config, muss ich sie natürlich speichern und aus ist es.
Es scheint ein Problem zu sein, was in der Fritzbox liegt.
Wenn ich die Box komplett neu starte, dann läuft alles, wie bisher. Alles ist wieder flüssig und schnell, bis ich wieder speichere. Danach wieder langsam und bleibt auch so, egal, was aufgerufen wird.

Ich habe schon die Firmware der Box und auch FHEM mehrfach neu installiert und versucht, den Fehler einzugrenzen. Es ist mir jedoch nicht gelungen. Hat jemand eine Idee, wie und wo ich noch suchen könnte?

rudolfkoenig · 26 Dezember 2013, 10:38:58

Da hilft nur "attr global verbose 5" einstellen, und uns den Log posten.
Es sei denn, es steht jetzt schon was sinnvolles drin.

Invers · 26 Dezember 2013, 11:14:07

Danke. So, hab ich mal gemacht. Plappern auf 5 üner die Kommandozeile gesetzt, dann auf Savo Config geklickt.
Das Speichern durch den Button hat keine Verzögerung bewirkt. Ich habe also dann die Config.cfg geöffnet, eine Leerzeile eingefügt und auf save geklickt. Schon gibt es wieder Streik auf der ganzen Linie.

Hier mal ein Ausschnitt aus der Logdatei von 11:05 bis Ende. In der Zeit habe ich nur die config.cfg und die Logdatei aufgerufen. Mehr nicht:

Code Auswählen

2013.12.26 11:05:28 5: FBAHA/RAW: /001400000000000c0000001200040000000000110703001c00000003001400000000000c0000001500040000000000ca0703001c00000003001400000000000c0000001600040000000000000703001c00000003001400000000000c0000000f00040000000000000703001c00000003001000000000000c000000140004000000003ce10703001c00000003001000000000000c00000013000400000003a41d0703001c00000003001000000000000c0000001200040000000020330703001c00000003001000000000000c00000015000400000008542b0703001c00000003001000000000000c0000001600040000000000000703001c0000000300100000
2013.12.26 11:05:28 1: FBAHA: resetting buffer as we are out of sync (0)
2013.12.26 11:05:48 4: Connection closed for FHEMWEB:192.168.178.34:54350
2013.12.26 11:05:48 4: Connection accepted from FHEMWEB:192.168.178.34:54493
2013.12.26 11:05:48 5: FBAHA/RAW: /0000000c0000000f0004000000000001
2013.12.26 11:05:48 5: fbaha dispatch 0000000c0000000f00040000
2013.12.26 11:05:48 1: FBDECT: unknown message type 00
2013.12.26 11:06:08 4: HTTP FHEMWEB:192.168.178.34:54493 GET /fhem/icons/favicon
2013.12.26 11:06:08 4: Connection accepted from FHEMWEB:192.168.178.34:54494
2013.12.26 11:06:28 4: Connection accepted from FHEMWEB:192.168.178.34:54495
2013.12.26 11:06:28 5: FBAHA/RAW: /0703001c00000003001300000000000c0000001400040000000000000703001c00000003001300000000000c00000013000400000003a1370703001c00000003001300000000000c0000001200040000000000110703001c00000003001300000000000c000000150004000000000f340703001c00000003001300000000000c0000001600040000000000000703001c00000003001300000000000c0000000f0004000000000000
2013.12.26 11:06:28 5: fbaha dispatch 0703001c00000003001300000000000c000000140004000000000000
2013.12.26 11:06:28 5: Triggering Stehlampe (1 changes)
2013.12.26 11:06:28 5: Notify loop for Stehlampe power: 0.00 W
2013.12.26 11:06:28 5: fbaha dispatch 0703001c00000003001300000000000c00000013000400000003a137
2013.12.26 11:06:28 5: Triggering Stehlampe (1 changes)
2013.12.26 11:06:28 5: Notify loop for Stehlampe voltage: 237.879 V
2013.12.26 11:06:28 5: fbaha dispatch 0703001c00000003001300000000000c000000120004000000000011
2013.12.26 11:06:28 5: Triggering Stehlampe (1 changes)
2013.12.26 11:06:28 5: Notify loop for Stehlampe current: 0.0017 A
2013.12.26 11:06:28 5: fbaha dispatch 0703001c00000003001300000000000c000000150004000000000f34
2013.12.26 11:06:28 5: Triggering Stehlampe (1 changes)
2013.12.26 11:06:28 5: Notify loop for Stehlampe energy: 3892 Wh
2013.12.26 11:06:28 5: fbaha dispatch 0703001c00000003001300000000000c000000160004000000000000
2013.12.26 11:06:28 5: Triggering Stehlampe (1 changes)
2013.12.26 11:06:28 5: Notify loop for Stehlampe powerFactor: 0.000
2013.12.26 11:06:28 5: fbaha dispatch 0703001c00000003001300000000000c0000000f0004000000000000
2013.12.26 11:06:28 5: Triggering Stehlampe (1 changes)
2013.12.26 11:06:28 5: Notify loop for Stehlampe off
2013.12.26 11:06:28 4: HTTP FHEMWEB:192.168.178.34:54494 GET /fhem?room=all&XHR=1&inform=1×tamp=1388052323296
2013.12.26 11:06:48 4: Connection closed for FHEMWEB:192.168.178.34:54495
2013.12.26 11:06:48 4: Connection accepted from FHEMWEB:192.168.178.34:54496
2013.12.26 11:06:48 5: FBAHA/RAW: /0703001c00000003001200000000000c0000001400040000000000000703001c00000003001200000000000c00000013000400000003a42b0703001c00000003001200000000000c0000001200040000000000000703001c00000003001200000000000c0000001500040000000010530703001c00000003001200000000000c0000001600040000000000000703001c00000003001200000000000c0000000f00040000000000000703001c00000003001100000000000c0000001400040000000000000703001c00000003001100000000000c00000013000400000003a3090703001c00000003001100000000000c0000001200040000000000000703001c
2013.12.26 11:06:48 5: fbaha dispatch 0703001c00000003001200000000000c000000140004000000000000
2013.12.26 11:06:48 5: Triggering TVLICHT_hinten (1 changes)
2013.12.26 11:06:48 5: Notify loop for TVLICHT_hinten power: 0.00 W
2013.12.26 11:06:48 5: fbaha dispatch 0703001c00000003001200000000000c00000013000400000003a42b
2013.12.26 11:06:48 5: Triggering TVLICHT_hinten (1 changes)
2013.12.26 11:06:48 5: Notify loop for TVLICHT_hinten voltage: 238.635 V
2013.12.26 11:06:48 5: fbaha dispatch 0703001c00000003001200000000000c000000120004000000000000
2013.12.26 11:06:48 5: Triggering TVLICHT_hinten (1 changes)
2013.12.26 11:06:48 5: Notify loop for TVLICHT_hinten current: 0.0000 A
2013.12.26 11:06:48 5: fbaha dispatch 0703001c00000003001200000000000c000000150004000000001053
2013.12.26 11:06:48 5: Triggering TVLICHT_hinten (1 changes)
2013.12.26 11:06:48 5: Notify loop for TVLICHT_hinten energy: 4179 Wh
2013.12.26 11:06:48 5: fbaha dispatch 0703001c00000003001200000000000c000000160004000000000000
2013.12.26 11:06:48 5: Triggering TVLICHT_hinten (1 changes)
2013.12.26 11:06:48 5: Notify loop for TVLICHT_hinten powerFactor: 0.000
2013.12.26 11:06:48 5: fbaha dispatch 0703001c00000003001200000000000c0000000f0004000000000000
2013.12.26 11:06:48 5: Triggering TVLICHT_hinten (1 changes)
2013.12.26 11:06:48 5: Notify loop for TVLICHT_hinten off
2013.12.26 11:06:48 5: fbaha dispatch 0703001c00000003001100000000000c000000140004000000000000
2013.12.26 11:06:48 5: Triggering TVLICHT_vorne (1 changes)
2013.12.26 11:06:48 5: Notify loop for TVLICHT_vorne power: 0.00 W
2013.12.26 11:06:48 5: fbaha dispatch 0703001c00000003001100000000000c00000013000400000003a309
2013.12.26 11:06:48 5: Triggering TVLICHT_vorne (1 changes)
2013.12.26 11:06:48 5: Notify loop for TVLICHT_vorne voltage: 238.345 V
2013.12.26 11:06:48 5: fbaha dispatch 0703001c00000003001100000000000c000000120004000000000000
2013.12.26 11:06:48 5: Triggering TVLICHT_vorne (1 changes)
2013.12.26 11:06:48 5: Notify loop for TVLICHT_vorne current: 0.0000 A
2013.12.26 11:06:48 4: Connection closed for FHEMWEB:192.168.178.34:54494
2013.12.26 11:07:08 4: Closing connection FHEMWEB:192.168.178.34:54493
2013.12.26 11:07:08 4: Connection accepted from FHEMWEB:192.168.178.34:54499
2013.12.26 11:07:08 4: Connection closed for FHEMWEB:192.168.178.34:54496
2013.12.26 11:07:08 5: FBAHA/RAW: /00000003001100000000000c000000150004000000001c980703001c00000003001100000000000c0000001600040000000000000703001c00000003001100000000000c0000000f00040000000000000703001c00000003001400000000000c0000001400040000000000000703001c00000003001400000000000c00000013000400000003a6020703001c00000003001400000000000c0000001200040000000000120703001c00000003001400000000000c0000001500040000000000ca0703001c00000003001400000000000c0000001600040000000000000703001c00000003001400000000000c0000000f00040000000000000703001c00000003
2013.12.26 11:07:08 1: FBAHA: resetting buffer as we are out of sync (6)
2013.12.26 11:07:28 4: HTTP FHEMWEB:192.168.178.34:54499 GET /fhem?cmd=style%20edit%20fhem.cfg
2013.12.26 11:07:28 4: Ignoring CUL_TX_21
2013.12.26 11:07:28 4: Ignoring FBDECT_900
2013.12.26 11:07:28 4: Ignoring CUL_TX_73
2013.12.26 11:07:28 4: Ignoring CUL_TX_21
2013.12.26 11:07:28 4: Ignoring CUL_TX_73
2013.12.26 11:07:28 4: Ignoring FBDECT_900
2013.12.26 11:07:29 4: /fhem?cmd=style%20edit%20fhem.cfg / RL:19210 / text/html; charset=UTF-8 / Content-Encoding: gzip
 / 
2013.12.26 11:07:29 5: FBAHA/RAW: /001000000000000c0000001400040000000038770703001c00000003001000000000000c00000013000400000003a5080703001c00000003001000000000000c000000120004000000001ce10703001c00000003001000000000000c0000001500040000000854300703001c00000003001000000000000c0000001600040000000000000703001c00000003001000000000000c0000000f0004000000000001
2013.12.26 11:07:29 1: FBAHA: resetting buffer as we are out of sync (0)
2013.12.26 11:07:49 4: Connection accepted from FHEMWEB:192.168.178.34:54511
2013.12.26 11:07:49 4: HTTP FHEMWEB:192.168.178.34:54499 GET /fhem/pgm2/style.css
2013.12.26 11:08:09 4: Connection accepted from FHEMWEB:192.168.178.34:54512
2013.12.26 11:08:09 4: HTTP FHEMWEB:192.168.178.34:54511 GET /fhem/pgm2/jquery.min.js
2013.12.26 11:08:09 4: HTTP FHEMWEB:192.168.178.34:54499 GET /fhem/pgm2/svg.js
2013.12.26 11:08:29 5: Triggering myTwilight (5 changes)
2013.12.26 11:08:29 5: Notify loop for myTwilight azimuth: 165.88
2013.12.26 11:08:29 4: HTTP FHEMWEB:192.168.178.34:54512 GET /fhem/pgm2/jquery-ui.min.js
2013.12.26 11:08:29 4: Connection accepted from FHEMWEB:192.168.178.34:54513
2013.12.26 11:08:29 4: HTTP FHEMWEB:192.168.178.34:54511 GET /fhem/pgm2/fhemweb.js
2013.12.26 11:08:29 4: HTTP FHEMWEB:192.168.178.34:54499 GET /fhem/pgm2/fhemweb_colorpicker.js
2013.12.26 11:08:29 5: FBAHA/RAW: /0703001c00000003001300000000000c0000001400040000000000000703001c00000003001300000000000c00000013000400000003a0c00703001c00000003001300000000000c0000001200040000000000100703001c00000003001300000000000c000000150004000000000f340703001c00000003001300000000000c0000001600040000000000000703001c00000003001300000000000c0000000f00040000000000000703001c00000003001200000000000c0000001400040000000000000703001c00000003001200000000000c00000013000400000003a31d0703001c00000003001200000000000c0000001200040000000000000703001c
2013.12.26 11:08:29 5: fbaha dispatch 0703001c00000003001300000000000c000000140004000000000000
2013.12.26 11:08:29 5: Triggering Stehlampe (1 changes)
2013.12.26 11:08:29 5: Notify loop for Stehlampe power: 0.00 W
2013.12.26 11:08:29 5: fbaha dispatch 0703001c00000003001300000000000c00000013000400000003a0c0
2013.12.26 11:08:29 5: Triggering Stehlampe (1 changes)
2013.12.26 11:08:29 5: Notify loop for Stehlampe voltage: 237.760 V
2013.12.26 11:08:29 5: fbaha dispatch 0703001c00000003001300000000000c000000120004000000000010
2013.12.26 11:08:29 5: Triggering Stehlampe (1 changes)
2013.12.26 11:08:29 5: Notify loop for Stehlampe current: 0.0016 A
2013.12.26 11:08:29 5: fbaha dispatch 0703001c00000003001300000000000c000000150004000000000f34
2013.12.26 11:08:29 5: Triggering Stehlampe (1 changes)
2013.12.26 11:08:29 5: Notify loop for Stehlampe energy: 3892 Wh
2013.12.26 11:08:29 5: fbaha dispatch 0703001c00000003001300000000000c000000160004000000000000
2013.12.26 11:08:29 5: Triggering Stehlampe (1 changes)
2013.12.26 11:08:29 5: Notify loop for Stehlampe powerFactor: 0.000
2013.12.26 11:08:29 5: fbaha dispatch 0703001c00000003001300000000000c0000000f0004000000000000
2013.12.26 11:08:29 5: Triggering Stehlampe (1 changes)
2013.12.26 11:08:29 5: Notify loop for Stehlampe off
2013.12.26 11:08:29 5: fbaha dispatch 0703001c00000003001200000000000c000000140004000000000000
2013.12.26 11:08:29 5: fbaha dispatch 0703001c00000003001200000000000c00000013000400000003a31d
2013.12.26 11:08:29 5: Triggering TVLICHT_hinten (1 changes)
2013.12.26 11:08:29 5: Notify loop for TVLICHT_hinten voltage: 238.365 V
2013.12.26 11:08:29 5: fbaha dispatch 0703001c00000003001200000000000c000000120004000000000000
2013.12.26 11:08:29 5: Triggering TVLICHT_hinten (1 changes)
2013.12.26 11:08:29 5: Notify loop for TVLICHT_hinten current: 0.0000 A
2013.12.26 11:08:49 4: HTTP FHEMWEB:192.168.178.34:54512 GET /fhem/pgm2/fhemweb_svg.js
2013.12.26 11:08:49 4: HTTP FHEMWEB:192.168.178.34:54511 GET /fhem/pgm2/fhemweb_slider.js
2013.12.26 11:08:49 4: HTTP FHEMWEB:192.168.178.34:54499 GET /fhem/pgm2/fhemweb_noArg.js
2013.12.26 11:08:49 5: FBAHA/RAW: /00000003001200000000000c0000001500040000000010530703001c00000003001200000000000c0000001600040000000000000703001c00000003001200000000000c0000000f00040000000000000703001c00000003001100000000000c0000001400040000000000000703001c00000003001100000000000c00000013000400000003a2a80703001c00000003001100000000000c0000001200040000000000000703001c00000003001100000000000c000000150004000000001c980703001c00000003001100000000000c0000001600040000000000000703001c00000003001100000000000c0000000f00040000000000000703001c00000003
2013.12.26 11:08:49 1: FBAHA: resetting buffer as we are out of sync (6)
2013.12.26 11:08:49 4: HTTP FHEMWEB:192.168.178.34:54513 GET /fhem/pgm2/dashboard.js
2013.12.26 11:09:09 4: HTTP FHEMWEB:192.168.178.34:54512 GET /fhem/pgm2/dashboard_darkstyle.css
2013.12.26 11:09:09 4: HTTP FHEMWEB:192.168.178.34:54511 GET /fhem/pgm2/fhemweb_time.js
2013.12.26 11:09:09 4: HTTP FHEMWEB:192.168.178.34:54499 GET /fhem/pgm2/fhemweb_textField.js
2013.12.26 11:09:09 5: FBAHA/RAW: /001400000000000c0000001400040000000000000703001c00000003001400000000000c00000013000400000003a59b0703001c00000003001400000000000c00000012000400000000000e0703001c00000003001400000000000c0000001500040000000000ca0703001c00000003001400000000000c0000001600040000000000000703001c00000003001400000000000c0000000f00040000000000000703001c00000003001000000000000c000000140004000000003ad00703001c00000003001000000000000c00000013000400000003a6be0703001c00000003001000000000000c000000120004000000001eda0703001c0000000300100000
2013.12.26 11:09:09 1: FBAHA: resetting buffer as we are out of sync (0)
2013.12.26 11:09:09 4: HTTP FHEMWEB:192.168.178.34:54513 GET /fhem/icons/favicon
2013.12.26 11:09:29 4: HTTP FHEMWEB:192.168.178.34:54499 GET /fhem/images/default/fhemicon_dark.png
2013.12.26 11:09:29 5: FBAHA/RAW: /0000000c0000001500040000000854360703001c00000003001000000000000c0000001600040000000000000703001c00000003001000000000000c0000000f0004000000000001
2013.12.26 11:09:29 5: fbaha dispatch 0000000c0000001500040000
2013.12.26 11:09:29 1: FBDECT: unknown message type 00
2013.12.26 11:09:29 1: FBAHA: resetting buffer as we are out of sync (43116)
2013.12.26 11:09:49 4: HTTP FHEMWEB:192.168.178.34:54512 GET /fhem/FileLog_logWrapper?dev=Logfile&type=text&file=fhem-2013-12.log
2013.12.26 11:09:49 4: Ignoring CUL_TX_21
2013.12.26 11:09:49 4: Ignoring FBDECT_900
2013.12.26 11:09:49 4: Ignoring CUL_TX_73
2013.12.26 11:09:49 4: Ignoring CUL_TX_21
2013.12.26 11:09:49 4: Ignoring CUL_TX_73
2013.12.26 11:09:49 4: Ignoring FBDECT_900

rudolfkoenig · 26 Dezember 2013, 17:29:31

ZitatIch habe also dann die Config.cfg geöffnet, eine Leerzeile eingefügt und auf save geklickt.

Das empfehle ich nicht, weil es ein rereadconfig bedeutet, was alle angeschlossenen Geraete neu initialisiert, und etliche interne temopraere Variablen loescht. Es sei denn man will Probleme haben. Apropos rereadcfg: das wurde nicht waehrend der protokollierten Zeit durchgefuehrt.

Was ich sehe sind Probleme bei der Netzwerk-Uebertragung: die exakt 20-Sekunden-Delays entstehen nur um den HTTP Requests herum (mal davor, mal danach), was kein Zufall sein kann, da es in den 5 Minuten 12-mal vorkommt. Und 12*20s = 5 Min.

Ich vermute(!) das Problem haengt nicht direkt mit FHEM zusammen.

Invers · 26 Dezember 2013, 20:08:16

Netzwerkprobleme allgemein sind auszuschliessen. Alles läuft eigentlich einwandfrei. Ich kann höchstens zum Test eine ältere Firmware in die Box einspielen. Support lehnt ja AVM in meinem Fall leider ab.

ZitatDas empfehle ich nicht, weil es ein rereadconfig bedeutet, was alle angeschlossenen Geraete neu initialisiert, und etliche interne temopraere Variablen loescht.

Ja, aber was soll ich machen? Ich musste ja den Fehler zum Test hervorrufen.
Wenn ich Änderungen an der Config vornehme, editiere ich diese doch eigentlich immer direkt. Dass dies falsch ist, wusste ich nicht. Welche Alternative sollte ich denn nutzen? Manche Dinge muss man doch per Hand eintragen.

rudolfkoenig · 27 Dezember 2013, 11:50:07

ZitatIch musste ja den Fehler zum Test hervorrufen.

Dazu ist dieser Vorgang vollkommen valide.

ZitatWelche Alternative sollte ich denn nutzen?

Geraete in der Komandozeile (oben) definieren oder loeschen, Attribute in der Detailansicht vergeben, modifizieren ebenso, und dann Save config nicht vergessen.

Invers · 27 Dezember 2013, 13:19:08

Nehme ich mir zu Herzen und werde künftig nach Möglichkeit so verfahren.

Der Hinweis auf die Netzwerkkommunikation war ein Treffer. Ich hatte das eigentlich auch vermutet, aber keinen Sinn darin gesehen.
Ich habe gestern dann noch meine Box genau unter die Lupe genommen und im Protokoll einige Merkwürdigkeiten gefunden.
Ich bin mit meinen Geräten (ausser PC) im 5GHz-Netz aktiv. Da habe ich nun den Hinweis im LOG gefunden, dass der Kanal nicht akzeptiert wird, weil er angeblich von einem Radar genutzt wird. Habe ich also nachgesehen und festgestellt, dass tatsächlich von der Box 5 Kanäle gesperrt wurden.
Abgesehen davon, dass es völliger Blödsinn ist, denn ich habe eine solche Störung noch nie gehabt, habe ich also meinen fest vergebenen Kanal 100 in 48 geändert.
Die 4 Kanäle um 100 herum blieben weiterhin als Radar reserviert. Ich habe zum Test noch meine beiden CULs entfernt und die Box neu gestartet. Keine Änderung.
Dann, aus welchen Gründen auch immer, verschwand die Radargeschichte. Auch nach dem Neustart der Box blieb alles im grünen Bereich.
Vielleicht sollte ich noch erwähnen, dass ich die Box zuletzt nicht per Interface neu gestartet habe, sondern vor dem Anstecken der CULs vom Stromnetz trennte.

Seit die Radargeschichte verschwunden ist und ich den Kanal gewechselt habe, funktioniert alles wieder einwandfrei.

Vielleicht können ja meine Erkenntnisse andern Fritzboxnutzern helfen.
Wie auch immer - merkwürdig bleibt das allemal.

P.S. Nochmals danke für die Hilfe.