Cmd: >xmllist< = Perfmon: possible freeze

[Ralf W.]

Hallo,

ich brauche mal einen kleinen Anstubser, wie ich weiter einen Fehler einkreisen kann.

Ich habe in schöner Regelmäßgkeit freeze-Einträge:

Code Auswählen Erweitern

2016.01.03 12:01:12 1: Perfmon: possible freeze starting at 12:01:09, delay is 3.335
2016.01.03 12:10:15 1: Perfmon: possible freeze starting at 12:10:12, delay is 3.491
2016.01.03 12:21:12 1: Perfmon: possible freeze starting at 12:21:09, delay is 3.716
2016.01.03 12:32:14 1: Perfmon: possible freeze starting at 12:32:11, delay is 3.306
2016.01.03 12:39:53 1: Perfmon: possible freeze starting at 12:39:50, delay is 3.555
2016.01.03 12:50:14 1: Perfmon: possible freeze starting at 12:50:11, delay is 3.694
2016.01.03 13:00:47 1: Perfmon: possible freeze starting at 13:00:44, delay is 3.979
2016.01.03 13:09:53 1: Perfmon: possible freeze starting at 13:09:50, delay is 3.022
2016.01.03 13:20:14 1: Perfmon: possible freeze starting at 13:20:11, delay is 3.902
2016.01.03 13:30:44 1: Perfmon: possible freeze starting at 13:30:41, delay is 3.923
2016.01.03 13:39:53 1: Perfmon: possible freeze starting at 13:39:50, delay is 3.663
2016.01.03 13:50:19 1: Perfmon: possible freeze starting at 13:50:15, delay is 4.723
2016.01.03 14:00:51 1: Perfmon: possible freeze starting at 14:00:46, delay is 5.228
2016.01.03 14:10:15 1: Perfmon: possible freeze starting at 14:10:12, delay is 3.23
2016.01.03 14:20:50 1: Perfmon: possible freeze starting at 14:20:47, delay is 3.979
2016.01.03 14:31:12 1: Perfmon: possible freeze starting at 14:31:09, delay is 3.219
2016.01.03 14:40:14 1: Perfmon: possible freeze starting at 14:40:12, delay is 2.784
2016.01.03 14:51:12 1: Perfmon: possible freeze starting at 14:51:09, delay is 3.37
2016.01.03 15:02:41 1: Perfmon: possible freeze starting at 15:02:37, delay is 4.179
2016.01.03 15:10:22 1: Perfmon: possible freeze starting at 15:10:19, delay is 3.828
2016.01.03 15:21:46 1: Perfmon: possible freeze starting at 15:21:43, delay is 3.445
2016.01.03 15:32:15 1: Perfmon: possible freeze starting at 15:32:12, delay is 3.288
2016.01.03 15:39:41 1: Perfmon: possible freeze starting at 15:39:39, delay is 2.743
2016.01.03 15:50:17 1: Perfmon: possible freeze starting at 15:50:11, delay is 6.293


Ich konnte das jetzt auf folgende immer wiederkehrende Meldung eingekreisen:

Code Auswählen Erweitern

2016.01.03 18:21:12.346 5: Cmd: >xmllist<
2016.01.03 18:21:16.353 1: Perfmon: possible freeze starting at 18:21:13, delay is 3.353
In den Zeilen vorher stehen immer unterschiedlich Einträge.

Apptime hilft auch nicht so recht weiter:

Code Auswählen Erweitern

                                name             function    max  count    total  average maxDly
          telnet:192.168.1.120:50438          telnet_Read    527     14      780    55.71      0 HASH(telnet:192.168.1.120:50438)
                           SE_Jabber        Jabber_Define    479      1      479   479.00      0 HASH(SE_Jabber); SE_Jabber Jabber jabber.de 5222 urgelsiele brummkopp 1 0
               tmr-allergy_GetUpdate      HASH(0x43bffe0)    120      1      120   120.00      0 HASH(Pollenflug_Daten)
                              HMLAN1           HMLAN_Read    114    995     8031     8.07      0 HASH(HMLAN1)
                           FB_Anrufe  FB_CALLMONITOR_Read     93      8      630    78.75      0 HASH(FB_Anrufe)
                   rg_AG_BATT_STATUS readingsGroup_Notify     93    844     1846     2.19      0 HASH(rg_AG_BATT_STATUS); HASH(WETTER_Wuppertal)
                             nanoCUL             CUL_Read     92    432     1608     3.72      0 HASH(nanoCUL)
               tmr-HTTPMOD_GetUpdate      update:TDatteln     76      9      185    20.56      2 update:TDatteln
                     rg_AG_humStatus readingsGroup_Notify     71    844     1732     2.05      0 HASH(rg_AG_humStatus); HASH(WETTER_Wuppertal)
                         tmr-at_Exec      HASH(0x3fd7c98)     70      3      192    64.00      3 HASH(SE_FHEM_save)
             tmr-Jabber_PollMessages      HASH(0x5e6dbd8)     69   2577    27259    10.58   4760 HASH(SE_Jabber)
         FHEMWEB:192.168.1.120:53354              FW_Read     65      3       79    26.33      0 HASH(FHEMWEB:192.168.1.120:53354)
                       FB_Anrufliste   FB_CALLLIST_Notify     61      8      414    51.75      0 HASH(FB_Anrufliste); HASH(FB_Anrufe)
               tmr-HTTPMOD_GetUpdate update:AG_FZ_Wuppertal     53      3      140    46.67     58 update:AG_FZ_Wuppertal
                               HMUSB           HMLAN_Read     44   1102     2291     2.08      0 HASH(HMUSB)
               tmr-HTTPMOD_GetUpdate          update:Avia     38      9      111    12.33   1342 update:Avia
                    JeeLink_LaCrosse         JeeLink_Read     37  20174    14020     0.69      0 HASH(JeeLink_LaCrosse)
               tmr-HTTPMOD_GetUpdate update:AG_FZ_Datteln     37      2       69    34.50      0 update:AG_FZ_Datteln
                 tmr-CUL_HM_ActCheck       ActionDetector     31      9      149    16.56      4 ActionDetector
                        OrviboBridge     BauhnBridge_Read     26    181     1959    10.82      0 HASH(OrviboBridge)
                 tmr-Twilight_sunpos      HASH(0x6ec8438)     26      1       26    26.00      2 HASH(Daemmerung_sunpos)


Auf dem Rechner läuft nur FHEM aktueller Stand. Keine besonderen Einträge in syslog.

Im Moment bin ich etwas ratlos, wie ich weiter suchen soll. Vielleicht kann mir einer von Euch einen Tipp geben.

MfG

[viegener]

Wenn xmllist die ursache ist, wäre es interessant herauszufinden was hier das Kommando xmllist aufruft.
Ich nehme an, dass die Info mit xmllist aus einem globalen verbose 5 stammt?

Zuerstmal kannst Du aber natürlich selbstmal xmllist direkt aufrufen und schauen, ob das zu der freeze-Meldung führt.
Wenn das der Fall ist sind vermutlich externe Verbindungen (also auch Systeme die von aussen auf FHEM zugreifen Kandidaten um xmllist zu verwenden), vielleicht können die deakt

[Ralf W.]

Hallo,

ja, das stammt aus einem globalen verbose 5.

xmllist direkt aufgerufen. Kein freeze. Mmmhhh ...

Von aussen greift nur ein System auf FHEM zu. Das hatte ich schon abgestellt. freeze bleibt.

Ich schalte dann mal nachher alles ab, was von FHEM irgendwo in der Welt Daten anfordert. Mal sehen, ob ich den Verursacher finde.

MfG

[rudolfkoenig]

XmlList geht die internen Strukturen durch und schreibt inrgendwohin (==Netzwerk) eine potentiell grosse Datenmenge.
Wenn die Verbindung ueber FHEMWEB laeuft, dann wird das mW nichtblockierend durchgefuehrt, bei telnet kann sich das Schreiben blockieren, da hier noch "einfach" geschrieben wird.

[Ralf W.]

Hallo,

ich bin jetzt damit angefangen alles ausser HomeMatic herauszunehmen. Ich warte dann immer zwei bis drei Stunden, um zu sehen, ob und wie noch freeze-Einträge erscheinen.

Mir ist noch eins aufgefallen. Nach einem Systemstart erscheint nach einigen Minuten folgendes:

Code Auswählen Erweitern

2016.01.04 14:39:28.471 5: Cmd: >xmllist<
2016.01.04 14:39:28.474 5: Loading ./FHEM/98_XmlList.pm
2016.01.04 14:39:28.626 1: PERL WARNING: Use of uninitialized value $d in hash element at fhem.pl line 3767.
2016.01.04 14:39:28.626 1: PERL WARNING: Use of uninitialized value $cmd in hash element at FHEM/SetExtensions.pm line 49.
2016.01.04 14:39:28.627 1: PERL WARNING: Use of uninitialized value $cmd in concatenation (.) or string at FHEM/SetExtensions.pm line 52.
2016.01.04 14:39:28.872 5: SET: Unknown argument ?, choose one of statusRequest
Unknown argument ?, choose one of statusRequest
Unknown argument ?, choose one of statusRequest
2016.01.04 14:39:28.874 5: SET: Unknown argument ?, choose one of assignHmKey clear:readings,trigger,register,oldRegs,rssi,msgEvents,attack,all deviceRename getConfig getRegRaw peerBulk peerChan raw regBulk regSet reset sign:on,off unpair
Unknown argument ?, choose one of assignHmKey clear:readings,trigger,register,oldRegs,rssi,msgEvents,attack,all deviceRename getConfig getRegRaw peerBulk peerChan raw regBulk regSet reset sign:on,off unpair
2016.01.04 14:39:28.876 5: SET: Unknown argument ?, choose one of assignHmKey clear:readings,trigger,register,oldRegs,rssi,msgEvents,attack,all deviceRename getConfig getRegRaw peerBulk peerChan raw regBulk regSet reset sign:on,off unpair
Unknown argument ?, choose one of assignHmKey clear:readings,trigger,register,oldRegs,rssi,msgEvents,attack,all deviceRename getConfig getRegRaw peerBulk peerChan raw regBulk regSet reset sign:on,off unpair
2016.01.04 14:39:31.052 1: Perfmon: possible freeze starting at 14:39:29, delay is 2.051

Laut einigen Forumbeiträgen ist das unkritisch. Sehe ich das richtig und kann das jemand bestätigen?

MfG

[rudolfkoenig]

Die "Unknown argument ?" Zeilen sind normal auf verbose 5. Die "PERL WARNING"s sind Programmierfehler, wovon die Erste vmtl. Benutzerfehler ist (Value() ohne Argument aufgerufen), die beiden Anderen vermutlich Modulfehler. Details sieht man, wenn man "attr global stacktrace" setzt.

[Ralf W.]

Hallo Rudolf,

dank Deiner Hilfe habe ich die Verursacher der WARNINGs gefunden. 30_BauhnBridge und 31_BauhnDevice (http://forum.fhem.de/index.php?topic=25406.0). Habe ich entfernt. Jetzt sind die Warnungen verschwunden.

MfG

[Ralf W.]

Hallo,

kurzer Zwischenstand. Alles bis auf HomeMatic ist rausgeflogen. Freeze trotzdem noch vorhanden.

fhem.cfg.demo habe ich zwischenzeitlich auch laufen lassen. Kein Freeze.

Ich habe mich entschlossen, FHEM komplett neu aufzusetzten. Das FHEM ist vom RasPi über Cubietruck zur jetzigen Plattform gewechselt. Früher gab es keine Trennung PROD und TEST. Den Neuaufbau werde ich schrittweise durchführen und dabei das Log beobachten. Die wichtigen HomeMatic-Devices laufen ja ohne FHEM autark.

MfG