FHEM (Perl) läuft mit 100% CPU Last bei Neuinstallation?

[MarioR]

Also instabile PIs gibt es bei mir nicht. Ist mir noch nie abgeschmiert.

@Werniemann Da hast Du voll Recht und DHCP gleich mit!

Gesundes neues Jahr
Otto

Lag wohl am Wlan. Der PI war nicht mehr erreichbar, und ich dachte er wär abgeschmirt. Seit er am LAN hängt ist er stabil.

[ext23]

Hallo,

ich möchte kein neues Thema öffnen aber ich habe auf meinem Server auch zwischen 90 und 100% last des perl Prozesses. Apptime verrät mir aber nichts womit ich was anfangen könnte. Hat noch jemand eine Idee wie ich raus bekomme woran das liegt? Die Maschine sollte eigentlich so performant sein, dass das nicht passiert. Also ich nutze ein RPi oder sowas...

/Daniel

[rudolfkoenig]

"attr global verbose 5" setzen, und log beobachten.

[ext23]

OK, habe ich auch schon geschaut, es kommt eine ganze Menge (Jeelink und SPSPM und so) aber ehrlich gesagt nicht in der Menge, dass ich sagen würde es sollte auch nur annähernd 1% CPU Last verursachen.

Ich werde es weiter beobachten, bzw. nach und nach mal die interface deaktivieren...

/Daniel

[ext23]

Also ich finde nichts, ich bin echt überfragt.

Werden bei Apptime nur Module gezeigt in denen bestimmte Bedingungen erfüllt sind oder alle, also auch die unsauber programmieren? Ich meine es sind keine 100% auf Anschlag, aber nahe dran, also irgend etwas scheint da tierisch zu ackern. Bei einem Intel(R) Core(TM) i3-4130 CPU @ 3.40GHz finde ich das ein wenig viel für FHEM.

Oder würdest du hier was auffälliges sehen:

Code Auswählen Erweitern

                                name             function    max  count    total  average maxDly
                            PanStick      panStamp_Define   4567      1     4567  4567.00      0 HASH(PanStick); PanStick panStamp /dev/PanStamp@38400
                                KODI           XBMC_Ready   3000 13889258    59988     0.00      0 HASH(KODI)
                           RFXTRX433           TRX_Define   2857      1     2857  2857.00      0 HASH(RFXTRX433); RFXTRX433 TRX /dev/RFXTRX433@38400
                             MP00202       OWX_ASYNC_Read   2422  12741   102441     8.04      0 HASH(MP00202)
            Notify_Schluessel_Daniel          notify_Exec   2245      2     2267  1133.50      0 HASH(Notify_Schluessel_Daniel); HASH(fl_iButton_blau)
                          az_OW_LCD1            OWLCD_Get   2213      1     2213  2213.00      0 HASH(az_OW_LCD1); az_OW_LCD1; gpio
                           wifiled01     WifiLight_Define   1008      1     1008  1008.00      0 HASH(wifiled01); wifiled01 WifiLight RGBW LD382A:192.168.0.91
                             JeeLink       JeeLink_Define   1006      1     1006  1006.00      0 HASH(JeeLink); JeeLink JeeLink /dev/JeeLink@57600
                             JeeNode       JeeLink_Define   1006      1     1006  1006.00      0 HASH(JeeNode); JeeNode JeeLink /dev/JeeNode@57600
                    Steckdose_Server         SISPM_Define    901      1      901   901.00      0 HASH(Steckdose_Server); Steckdose_Server SISPM /usr/local/bin/sispmctl
                         tmr-at_Exec      HASH(0x5a697a0)    810      4     3240   810.00      4 HASH(Timer_1Wire_ba_Temp_Steuereinheit)
               ba_Temp_Steuereinheit       ECMDDevice_Set    807     13     3228   248.31      0 HASH(ba_Temp_Steuereinheit); ba_Temp_Steuereinheit; messen
                             MP00202     OWX_ASYNC_Notify    717     17      717    42.18      0 HASH(MP00202); HASH(global)
                          PushNotify  PushNotifier_Define    520      1      520   520.00      0 HASH(PushNotify); PushNotify PushNotifier EV468E7DBV468E7DV75BBV46BV466C3VEFTBFTFBFB net.homeip.itse ext23 gen6iNWG9bY .*
        WEBtablet_192.168.0.15_41103              FW_Read    323      1      323   323.00      0 HASH(WEBtablet_192.168.0.15_41103)
                            Twilight      Twilight_Define    295      1      295   295.00      0 HASH(Twilight); Twilight Twilight 52.539094 13.603869 3 638242
                         Callmonitor FB_CALLMONITOR_Notify    244   1722      244     0.14      0 HASH(Callmonitor); HASH(global)
                        DMXUniverse1    DMX4ALLUSB_Define    206      1      206   206.00      0 HASH(DMXUniverse1); DMXUniverse1 DMX4ALLUSB /dev/DMX@38400
                                 WEB              FW_Read    184     17      766    45.06      0 HASH(WEB)
              tmr-OWX_ASYNC_RunTasks     HASH(0x10f2fd70)    174   1581    42613    26.95   3225 HASH(MP00202)
                                CUL1           CUL_Define    143      1      143   143.00      0 HASH(CUL1); CUL1 CUL /dev/ttyACM0 1234

Das avg ist recht hoch mhhh, aber bei allen. Oder spinnt hier eventuell mein USB Bus.

/Daniel

[justme1968]

ist es wirklich der haupt fhem prozess oder irgend ein child? beim mit spinnt manchmal der sonos prozess mit 100% cpu. 

du kannst dich mit strace -p <pid> an den prozess hängen und schauen was er gerade macht.

gruss
   andre

[ext23]

Hi,

naja ich denke es ist der Hauptprozess, also Perl. Der läuft aber auch nur jeweils auf einer der 4 Kerne die meine CPU hat.

strace liefert ein haufen Zeilen aller:
select(176, [5 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 29 30 54 55 71 72 73 95 146 153 155 171], NULL, NULL, {1, 353556}) = 1 (in [21], left {1, 353550})
select(176, [5 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 29 30 54 55 71 72 73 95 146 153 155 171], NULL, NULL, {1, 353451}) = 1 (in [21], left {1, 353444})
select(176, [5 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 29 30 54 55 71 72 73 95 146 153 155 171], NULL, NULL, {1, 353339}) = 1 (in [21], left {1, 353333})
select(176, [5 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 29 30 54 55 71 72 73 95 146 153 155 171], NULL, NULL, {1, 353231}) = 1 (in [21], left {1, 353225})


Das ist der Prozess:
fhem      9966 80.8 11.6 603656 456920 ?       S    10:34 474:05 perl fhem.pl fhem.cfg

top:
  PID BENUTZER  PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
9966 fhem      20   0  604008 457308   5344 R  82,5 11,7 474:47.50 perl

Ich kann da kein Unterprozess erkennen auch nicht im Baum.

Gruß
Daniel

[justme1968]

über /proc/<pid>/fd solltest du  sehen wozu der filedescriptor 21 gehört der das select aufwachen lässt.

gruss
  andre

[justme1968]

irgendwo gibt es einen thread bei dem es auch um zu viel last beim lesen von einem usb device ging. kann aber sein das das nur in einer vm war. da gibt es auch einen patch vorschlag der zumindest dort geholfen hat.

[ext23]

Mhh das ist mein DMX Adapter, und das Modul habe ich selber geschrieben Heißt ich habe da irgendwo Misst gebaut in meinem Modul.

/Daniel

[ext23]

Ich hab jetzt mal ein paar Debug logs in meine Module eingebaut. Auffällig ist nur, dass die read Funktion Device Modul ständig aufgerufen wird. Die ist aber leer bei mir, ich nutze das nicht da der DMX Controller von sich aus keine Infos sendet sondern nur auf Anfragen antwortet. Kann das mein Problem sein?

Es heißt ja "called from the global loop, when the select for hash->{FD} reports data" Jetzt ist nur die Frage warum da Daten reported werden... Sonst dürfte er die Funktion ja gar nicht aufrufen wenn ich das richtig verstanden habe.

/Daniel

[rudolfkoenig]

Jetzt ist nur die Frage warum da Daten reported werden

Vmtl. weil FD in selectlist eingetragen ist.
Hast du die Datei mit DevIO geoeffnet? Dann passiert das automatisch.

[ext23]

Vmtl. weil FD in selectlist eingetragen ist.
Hast du die Datei mit DevIO geoeffnet? Dann passiert das automatisch.

Ich nutze DevIO ja. Heißt also das ist normal und vermutlich nicht Ursache für mein Verhalten.

[rudolfkoenig]

Heißt also das ist normal und vermutlich nicht Ursache für mein Verhalten.

Aeh:
- Wenn man DevIO nutzt, ist normal, dass man nicht pollt, sondern ReadFn aufgerufen wird, wenn das zentrale select() feststellt, dass was zum Lesen gibt.
- Wenn das Geraet unaufgefordert Daten schickt, oder das Modul beim Pollen nicht alle Daten "weggelesen" hat, und ReadFn nichts tut, dann tritt genau das o.g. Verhalten auf: ReadFn wird in einer Endlosschleife aufgerufen.

Wenn du DevIO verwenden willst, und auf Pollen bestehst, dann solltest du

delete($selectlist{"$name.$dev");
  delete($readyfnlist{"$name.$dev");

nach DevIo_OpenDev aufrufen.

[ext23]

wenn das zentrale select() feststellt, dass was zum Lesen gibt.

Naja das macht es dann vermutlich, nur gibt es nichts zum Lesen weil, bzw. wenn dann die Antwort, aber die sollte ja eigentlich irgend wann mal "weggelesen" sein, ist nur 1 Byte was da als Antwort im UART Buffer liegt.

- Wenn das Geraet unaufgefordert Daten schickt, oder das Modul beim Pollen nicht alle Daten "weggelesen" hat, und ReadFn nichts tut, dann tritt genau das o.g. Verhalten auf: ReadFn wird in einer Endlosschleife aufgerufen.

Wenn du DevIO verwenden willst, und auf Pollen bestehst, dann solltest du nach DevIo_OpenDev aufrufen.

Naja Pollen möchte ich gerade nichts, also die Antwort vom DMX Controller interessiert mich garnicht um es mal krass zu sagen. Aber danke, ich schau mir das mal an was du schreibst. Ansonsten baue ich in die Lesefunktion noch was ein, das der Buffer leergelesen wird oder so. Aber jetzt habe ich zumindest verstanden was das Problem ist. Das ist mir nie aufgefallen das ich da misst drin habe. Schade das AppTime sowas nicht anzeigt. Ich versuche das zu ändern und werde berichten.

/Daniel