FHEM Log Cannot fork: Cannot allocate memory

Begonnen von michael.winkler, 23 Juni 2017, 07:43:04

Vorheriges Thema - Nächstes Thema

michael.winkler

Zitat von: Wernieman am 29 Juni 2017, 11:25:29
Ich kann Dir nur wieder raten, wenn Du schon mit VM arbeitest, dann richtig, d.h. eine VM = ein Dienst.
4 S root      2420  2326  0  80   0 - 192202 -     Jun23 ?        00:01:49 homeb
0 S root      2059     1  0  80   0 - 187813 -     Jun23 ?        00:02:17 alexa

Pache die einfach mal in eigene VMs ....

Danke für den Hinweis.

Allerdings glaube ich nicht dass es durch das verschieben der zwei Dienste besser wird. Der Arbeitsspeicher dieser Dienste ändert sich über die Laufzeit kaum bis gar nicht. Der einzige Dienst der Speichertechnisch wächst ist FHEM.

Direkt nach einem Reboot sieht die Speicherauslastung wie folgt aus:

root@HNMWFHEM01:/# ps -elf | sort -rnk 10 | head
4 S root      2419  2325  0  80   0 - 191434 -     09:05 ?        00:00:04 homebridge
0 S root      2058     1  0  80   0 - 169515 -     09:05 ?        00:00:03 alexa
4 S mysql     2787  2447  0  80   0 - 91021 -      09:05 ?        00:00:04 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib/mysql/plugin --user=mysql --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/run/mysqld/mysqld.sock --port=3306
1 S fhem      1986     1  1  80   0 - 61216 -      09:05 ?        00:02:53 perl fhem.pl fhem.cfg
5 S www-data  2161  2143  0  80   0 - 55818 -      09:05 ?        00:00:00 /usr/sbin/apache2 -k start
5 S www-data  2160  2143  0  80   0 - 55818 -      09:05 ?        00:00:00 /usr/sbin/apache2 -k start
5 S www-data  2157  2143  0  80   0 - 55818 -      09:05 ?        00:00:00 /usr/sbin/apache2 -k start
5 S www-data  2156  2143  0  80   0 - 55818 -      09:05 ?        00:00:00 /usr/sbin/apache2 -k start
5 S www-data  7065  2143  0  80   0 - 55804 -      10:16 ?        00:00:00 /usr/sbin/apache2 -k start
5 S www-data  2162  2143  0  80   0 - 55804 -      09:05 ?        00:00:00 /usr/sbin/apache2 -k start


Hier ist deutlich zu sehen das die beiden Dienste kaum kleiner sind wie bei meinem letzten Post. FHEM allerdings benötigt ca. 60MB und wächst dann kontinuierlich.

rudolfkoenig

Ich habe in fhemdebug ein memusage Parameter eingebaut, bitte testen. Beschreibung (commandref):
Zitat
memusage [regexp] [nr]
Dump the name of the first nr datastructures with the largest memory footprint. Filter the names by regexp, if specified.
Notes:

    this function depends on the Devel::Size module, so this must be installed first.
    The used function Devel::Size::total_size crashes perl (and FHEM) for Functions and some other data structures. memusage tries to avoid to call it for such data structures, but as the problem is not identified, it may crash your currently running instance. Make sure you saved the config first.
    The known data structures modules and defs are reported in more detail.

Ausgabe-Beispiel:
fhem> fhemdebug memusage     
   1. SIG                              192236
   2. modules::eventTypes              164861
   3. Exporter::Cache                  149540
   4. modules::ZWave                   115758
   5. modules::FS20                     87854
   6. attr                              84867
   7. selectlist                        78322
   8. Net::SSLeay::BEGIN                73122
   9. defs::KM271                       67010
  10. oldvalue                          63730
  11. defs::rg_temp                     61100
  12. ntfyHash                          55244
  13. modules::FHT                      50081
  14. Config::Config_SH_expanded        49496
  15. POSIX::EXPORT_TAGS                42120
  16. modules::FBDECT                   40625
  17. POSIX::EXPORT                     39741
  18. Net::SSLeay::EXPORT_OK            37473
  19. defs::EingangsLampe               35544
  20. defs::wz                          32134
  21. defs::EingangsSensor              30286
  22. modules::CUL_WS                   27554
  23. defs::remo                        26349
  24. defs::kuehlschrank                25783
  25. defs::GartenTor                   24427
  26. defs::fl                          24377
  27. defs::Stehlampe2                  23944
  28. intAt                             23565
  29. defs::remo.8                      22527
  30. defs::remo.1                      21230
  31. defs::remo.2                      21230
  32. defs::remo.3                      21230
  33. defs::remo.7                      21230
  34. defs::EingangsTemp                21217
  35. Socket::EXPORT_TAGS               21016
  36. defs::remo.4                      20447
  37. defs::remo.5                      20447
  38. defs::remo.B                      20037
  39. defs::remo.9                      20034
  40. defs::remo.A                      20034
  41. defs::EingangsLampe_Kanal2        19855
  42. zwave_id2class                    19730
  43. defs::remo.6                      19624
  44. defs::EingangsLicht               19475
  45. modules::KS300                    19309
  46. INC                               18650
  47. readyfnlist::zwd./dev/ttyUSB0     17579
  48. defs::zwd                         17579
  49. defs::out1                        17082
  50. modules::CUL_EM                   16856
fhem>

Verfuegbar per update (wie ueblich) ab morgen um 8, oder ab sofort aus dem SVN.

michael.winkler

#17
danke

hab mir die Datei heruntergeladen und per reload geladen. Leider spukt das Teil folgendes aus

Can't locate Devel/Size.pm in @INC (@INC contains: fhem.p/lib fhem.p/FHEM/lib ./FHEM/lib ./lib ./FHEM ./ /usr/local/FHEM/share/fhem/FHEM/lib . /etc/perl /usr/local/lib/perl/5.14.2 /usr/local/share/perl/5.14.2 /usr/lib/perl5 /usr/share/perl5 /usr/lib/perl/5.14 /usr/share/perl/5.14 /usr/local/lib/site_perl) at (eval 5251) line 2.
BEGIN failed--compilation aborted at (eval 5251) line 2.


Habe ich da noch etwas vergessen?

OK ich habe das Modul Devel::Size nicht installiert. Bin noch auf der Suche wie ich das installieren kann..

OK habe es gefunden. Folgende per SSH installieren

cpanm Devel::Size


Erstes Ergebnis

1. intAt                           9025270
   2. icloud.kalender                 6646993
   3. selectlist                      1222820
   4. attr                             958164
   5. CUL_HM                           702214
   6. HMConfig::culHmRegDefine         647302
   7. Abfall                           608405
   8. teleBot                          587140
   9. Wohnzimmer.Kodi.UPnP             514403
  10. DLNASocket-FHEM.UPnP-41          505995
  11. DLNASocket-FHEM.UPnP-42          505995
  12. DLNASocket-FHEM.UPnP-40          505909
  13. FHEM.UPnP                        504952
  14. FHEM.fronthem                    379392
  15. Service.Spritpreise              372364
  16. utf8::loose_to_file_of           359363
  17. SIG                              284956
  18. BEGIN                            259745
  19. Role::Tiny::INFO                 249519
  20. ntfyHash                         207501
  21. Exporter::Cache                  206753
  22. HMConfig::culHmModel             172179
  23. HMConfig::culHmRegDefShLg        130622
  24. Wohnzimmer.HUB                   127420
  25. oldvalue                         126764
  26. Badezimmer.Klima.DBLog           126637
  27. Buero.Monitore.DBLog             125709
  28. Allgemein.Batterie               125008
  29. Schlafzimmer.Klima.DBLog         124876
  30. Wohnzimmer.Heizung.DBLog         124876
  31. Service.Spritpreise.DBLog        124876
  32. Wohnzimmer.Klima.DBLog           124868
  33. Niklas.Multimedia.DBLog          124868
  34. Mobil.Powermeter.01.DBLog        124860
  35. Garten.Pool.Temp.DBLog           124852
  36. Werkstatt.USV.DBLog              124844
  37. Garten.Klima.DBLog               124844
  38. Kueche.Radio.DBLog               124844
  39. DBI::installed_drh               124766
  40. DBD::SQLite::drh                 120885
  41. Allgemein.Activity               120612
  42. DateTime::Locale::Data::NativeNames   104118
  43. DateTime::Locale::Data::Names    101192
  44. BC_hash                           76648
  45. DateTime::Locale::Data::ISO639Aliases    75415
  46. FritzBoxUG                        74641
  47. HMConfig::culHmRegChan            71814
  48. DateTime::Locale::Data::Codes     71021
  49. Buero.Notebook                    70057
  50. Net::SSLeay::BEGIN                68633


Jetzt warte ich bis der Fehler wieder kommt und vergleiche die Werte


Wernieman

besser wäre gewesen:
apt-get -s install libdevel-size-perl

cpan wird bei einem Systemupdate nicht mitupgedatet ....
- Bitte um Input für Output
- When there is a Shell, there is a Way
- Wann war Dein letztes Backup?

Wie man Fragen stellt: https://tty1.net/smart-questions_de.html

michael.winkler

Fehler ist zwar noch nicht da, aber eventuell sieht man schon woran es liegen könnte.


Name 29.06.2017 30.06.2017 Differenz
intAt 9025270 10213420 1188150
attr 958164 7084327 6126163
icloud.kalender 6646993 6649729 2736
selectlist 1222820 1506547 283727
CUL_HM 702214 715521 13307
HMConfig::culHmRegDefine 647302 647302 0
Abfall 608405 608885 480
teleBot 587140 588417 1277
Niklas.Fernseher.UPnP 124868 514612 389744
Wohnzimmer.Kodi.UPnP 514403 512726 -1677
DLNASocket-FHEM.UPnP-41 505995 504318 -1677
DLNASocket-FHEM.UPnP-42 505995 504318 -1677
DLNASocket-FHEM.UPnP-40 505909 504232 -1677
FHEM.UPnP 504952 503275 -1677
FHEM.fronthem 379392 379392 0
Service.Spritpreise 372364 372364 0
utf8::loose_to_file_of 359363 359363 0
SIG 284956 284956 0
BEGIN 259745 259745 0
Role::Tiny::INFO 249519 249519 0
ntfyHash 207501 207500 -1
Exporter::Cache 206753 206753 0
HMConfig::culHmModel 172179 172179 0
HMConfig::culHmRegDefShLg 130622 130622 0
oldvalue 126764 127687 923
Wohnzimmer.HUB 127420 127420 0
Allgemein.Batterie 125008 125008 0
Badezimmer.Klima.DBLog 126637 120749 -5888
Allgemein.Activity 120612 120612 0
DBI::installed_drh 124766 120078 -4688

rudolfkoenig

Irgendwer fuegt wie wild Attribute hinzu.

intAt ist schwieriger zu interpretieren, da hier auch Parameter fuer die Funktionisaufrufe hinterlegt sind, und das kann alles moegliche sein, und sogar mehrfach gezaehlt werden.

Kannst du bitte folgendes ausfuehren:
{ int(keys %intAt) }
liefert Anzahl der internen Timer zurueck (at/DOIF/etc).


rudolfkoenig

ZitatErgebnis 804
Ich habe in meiner Produktivumgebung 15.

ZitatIst das ein Problem wenn ständig Attribute geändert werden?
Attribute "gehoeren" dem Benutzer, d.h. nur er sollte sie anlegen und aendern, Ausnahmen bestaetigen diesen Regel. Wenn ohne dein Zutun die Attribute sich versechsfachen, dann ist was faul. Da sie nach einem Neustart weniger Platz belegen, gehe ich davon aus, dass irgendwer fuer nicht existierende Geraete Attribute anlegt.

Kannst du bitte auch die Ausgabe von
{ int(keys %defs).":".int(keys %attr) }
hier mitteilen?

FunkOdyssey


Wernieman

Ups .. da ich es in meiner "produktiv" umgeben "getestet" habe ... und dann einfach copy&paste .. ;o)
- Bitte um Input für Output
- When there is a Shell, there is a Way
- Wann war Dein letztes Backup?

Wie man Fragen stellt: https://tty1.net/smart-questions_de.html

michael.winkler

Zitat von: rudolfkoenig am 30 Juni 2017, 09:06:04
Ich habe in meiner Produktivumgebung 15.
Attribute "gehoeren" dem Benutzer, d.h. nur er sollte sie anlegen und aendern, Ausnahmen bestaetigen diesen Regel. Wenn ohne dein Zutun die Attribute sich versechsfachen, dann ist was faul. Da sie nach einem Neustart weniger Platz belegen, gehe ich davon aus, dass irgendwer fuer nicht existierende Geraete Attribute anlegt.

Kannst du bitte auch die Ausgabe von
{ int(keys %defs).":".int(keys %attr) }
hier mitteilen?
Ich habe ein paar devices an denen ich das Attibut icon über ein doif ändere. Das kann ich mal überarbeiten.

Ergebnis 334:24086

rudolfkoenig

ZitatIch habe ein paar devices an denen ich das Attibut icon über ein doif ändere. Das kann ich mal überarbeiten.
Darum gehts mir nicht, du bist der Benutzer.

Zitat334:24086
Ich habe einen Bug in TcpServerUtils.pm gefunden und behoben, das duerfte zumindest fuer einen Teil der sinnlosen attr Eintraege verantwortlich sein. Geaendert habe ich TcpServerUtils.pm und 01_FHEMWEB.pm.

michael.winkler

#27
Muss ich den FHEM Server neu starten wenn ich die beiden Dateien ersetze oder langt ein Reload der Module?

OK, habe die Dateien ersetzt und einen "shutdown restart" gemacht.

Im Log ist jetzt folgendes alle ca. 30 Sekunden zu sehen


2017.06.30 10:53:32 0: Strange call for nonexistent FEHM.Telnet_127.0.0.1_33136: DeleteFn
2017.06.30 10:53:32 1: in DELETED
2017.06.30 10:53:32 1: in DELETED
2017.06.30 10:53:32 1: in DELETED
2017.06.30 10:53:32 1: in DELETED
2017.06.30 10:53:32 1: in DELETED
2017.06.30 10:53:32 1: in DELETED
2017.06.30 10:53:32 1: in DELETED
2017.06.30 10:53:32 1: in DELETED
2017.06.30 10:53:32 1: in DELETED
2017.06.30 10:53:32 1: in DELETED


Nachrtag

Das Ergebnis von { int(keys %defs).":".int(keys %attr) } sieht jetzt auch besser aus.

337:349


rudolfkoenig

ZitatIm Log ist jetzt folgendes alle ca. 30 Sekunden zu sehen
Danke, ich habe es auch gemerkt, und eine neue Version der beiden Dateien eingecheckt.

michael.winkler

#29
Zitat von: rudolfkoenig am 30 Juni 2017, 11:40:19
Danke, ich habe es auch gemerkt, und eine neue Version der beiden Dateien eingecheckt.

Danke, jetzt sieht das Log besser aus. Ich beobachte jetzt mal wieder. Melde mich dann in den nächsten Tagen noch mal.

Noch mal ein fettes DANKE für Deine Hilfe!

Nachtrag:
Das Ergebnis von { int(keys %intAt) } sieht jetzt auch besser aus.

Ergebnis = 80