FHEM Log Cannot fork: Cannot allocate memory

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

Vorheriges Thema - Nächstes Thema

abc2006

Hi,
danke für deine Änderung.
Es stürzt immer noch ab, jetzt bekomm ich aber eine lange Liste von ... Devices.

Hier sind die letzten 6, wenn du mehr brauchst, sag Bescheid.
Grüße,
Stephan

2018.01.27 00:30:31.115 5: main::defs::devstateicon
2018.01.27 00:30:31.116 5: main::defs::SVG_Kuehlschrank
2018.01.27 00:30:31.116 5: main::defs::D_Gast
2018.01.27 00:30:31.116 5: main::defs::global
2018.01.27 00:30:31.116 5: main::defs::cmd_sendTelegramSVG
2018.01.27 00:30:31.117 5: main::defs::01static_DbRep
FHEM nightly auf Intel Atom (lubuntu) mit VDSL 50000 ;-)
Nutze zur Zeit OneWire und KNX

rudolfkoenig

Ich habe DbRep zum Blacklist hinzugefuegt.

Es waere interessant rauszukriegen, was HTTPMOD, $modules{MAX} und DbRep gemeinsam haben, und Devel::Size::total_size zum Absturz bringen.

DS_Starter

Hallo zusammen,

weil mich Stephan (abc2006) gerade hierher gelotst hat, habe ich auch gleich mal "fhemdebug memusage" bei mir ausgeführt.
Stürzt aber nichts ab und gibt einwandfrei Rückmeldung.
Ich habe natürlich DbLog und DbRep exzessiv im Einsatz, HTTPMOD allerdings nicht.
Habe bei mir dergleichen wie bei Stephan auftritt noch nicht feststellen können.

LG,
Heiko

ESXi@NUC+Debian+MariaDB, PV: SMA, Victron MPII+Pylontech+CerboGX
Maintainer: SSCam, SSChatBot, SSCal, SSFile, DbLog/DbRep, Log2Syslog, SolarForecast,Watches, Dashboard, PylonLowVoltage
Kaffeekasse: https://www.paypal.me/HMaaz
Contrib: https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter

abc2006

Hi,
Danke für euer Engagement!
Ich hab leider weiterhin Abstürze:


2018.01.27 16:53:49.598 5: Cmd: >fhemdebug memusage<
2018.01.27 16:53:49.599 5: Loading ./FHEM/98_fhemdebug.pm
2018.01.27 16:53:49.622 5: main::authenticate
2018.01.27 16:53:49.623 5: main::157487574
2018.01.27 16:53:49.623 5: main::inform
2018.01.27 16:53:49.623 5: main::FW_dir
2018.01.27 16:53:49.624 5: main::cvsid
2018.01.27 16:53:49.626 5: main::Socket::__ANON__
2018.01.27 16:53:49.626 5: main::Socket::EXPORT_TAGS
2018.01.27 16:53:49.627 5: main::Socket::EXPORT_OK
2018.01.27 16:53:49.630 5: main::Socket::EXPORT
2018.01.27 16:53:49.630 5: main::Socket::ISA
2018.01.27 16:53:49.631 5: main::Socket::EXPORT_FAIL
2018.01.27 16:53:49.632 5: main::Socket::BEGIN
2018.01.27 16:53:49.633 5: main::readingFnAttributes
2018.01.27 16:53:49.633 5: main::TGB_BINFILE
2018.01.27 16:53:49.634 5: main::fhem_started
2018.01.27 16:53:49.634 5: main::FW_hiddenroom
2018.01.27 16:53:49.634 5: main::selectlist::WEB_192.168.0.201_5592
2018.01.27 16:53:49.635 5: main::selectlist::telnetPort_192.168.0.113_40742
2018.01.27 16:53:49.635 5: main::selectlist::telnetPort_192.168.0.105_43182
2018.01.27 16:53:49.635 5: main::selectlist::WEB_192.168.0.201_5593
2018.01.27 16:53:49.636 5: main::selectlist::WEB_192.168.0.201_5597
2018.01.27 16:53:49.636 5: main::selectlist::WEB_192.168.0.201_5596
2018.01.27 16:53:49.636 5: main::selectlist::HASH(0x560e90585720)
2018.01.27 16:53:49.640 1: PERL WARNING: Devel::Size: Unknown variable type: 255 encountered
2018.01.27 16:53:49.640 1: stacktrace:
2018.01.27 16:53:49.640 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (148)
2018.01.27 16:53:49.641 1:     (eval)                              called by ./FHEM/98_fhemdebug.pm (124)
2018.01.27 16:53:49.641 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (166)
2018.01.27 16:53:49.641 1:     main::fhemdebug_memusage            called by ./FHEM/98_fhemdebug.pm (41)
2018.01.27 16:53:49.641 1:     main::fhemdebug_Fn                  called by fhem.pl (1172)
2018.01.27 16:53:49.641 1:     main::AnalyzeCommand                called by fhem.pl (1025)
2018.01.27 16:53:49.642 1:     main::AnalyzeCommandChain           called by ./FHEM/01_FHEMWEB.pm (2486)
2018.01.27 16:53:49.642 1:     main::FW_fC                         called by ./FHEM/01_FHEMWEB.pm (881)
2018.01.27 16:53:49.642 1:     main::FW_answerCall                 called by ./FHEM/01_FHEMWEB.pm (525)
2018.01.27 16:53:49.642 1:     main::FW_Read                       called by fhem.pl (3498)
2018.01.27 16:53:49.642 1:     main::CallFn                        called by fhem.pl (689)
2018.01.27 16:53:49.642 1: PERL WARNING: Devel::Size: Unknown variable type: 111 encountered
2018.01.27 16:53:49.643 1: stacktrace:
2018.01.27 16:53:49.643 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (148)
2018.01.27 16:53:49.643 1:     (eval)                              called by ./FHEM/98_fhemdebug.pm (124)
2018.01.27 16:53:49.643 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (166)
2018.01.27 16:53:49.643 1:     main::fhemdebug_memusage            called by ./FHEM/98_fhemdebug.pm (41)
2018.01.27 16:53:49.643 1:     main::fhemdebug_Fn                  called by fhem.pl (1172)
2018.01.27 16:53:49.644 1:     main::AnalyzeCommand                called by fhem.pl (1025)
2018.01.27 16:53:49.644 1:     main::AnalyzeCommandChain           called by ./FHEM/01_FHEMWEB.pm (2486)
2018.01.27 16:53:49.644 1:     main::FW_fC                         called by ./FHEM/01_FHEMWEB.pm (881)
2018.01.27 16:53:49.644 1:     main::FW_answerCall                 called by ./FHEM/01_FHEMWEB.pm (525)
2018.01.27 16:53:49.644 1:     main::FW_Read                       called by fhem.pl (3498)
2018.01.27 16:53:49.645 1:     main::CallFn                        called by fhem.pl (689)
2018.01.27 16:53:49.645 1: PERL WARNING: Devel::Size: Unknown variable type: 69 encountered
2018.01.27 16:53:49.645 1: stacktrace:
2018.01.27 16:53:49.645 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (148)
2018.01.27 16:53:49.645 1:     (eval)                              called by ./FHEM/98_fhemdebug.pm (124)
2018.01.27 16:53:49.645 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (166)
2018.01.27 16:53:49.646 1:     main::fhemdebug_memusage            called by ./FHEM/98_fhemdebug.pm (41)
2018.01.27 16:53:49.646 1:     main::fhemdebug_Fn                  called by fhem.pl (1172)
2018.01.27 16:53:49.646 1:     main::AnalyzeCommand                called by fhem.pl (1025)
2018.01.27 16:53:49.646 1:     main::AnalyzeCommandChain           called by ./FHEM/01_FHEMWEB.pm (2486)
2018.01.27 16:53:49.646 1:     main::FW_fC                         called by ./FHEM/01_FHEMWEB.pm (881)
2018.01.27 16:53:49.646 1:     main::FW_answerCall                 called by ./FHEM/01_FHEMWEB.pm (525)
2018.01.27 16:53:49.647 1:     main::FW_Read                       called by fhem.pl (3498)
2018.01.27 16:53:49.647 1:     main::CallFn                        called by fhem.pl (689)
2018.01.27 16:53:49.647 1: PERL WARNING: Devel::Size: Unknown variable type: 108 encountered
2018.01.27 16:53:49.647 1: stacktrace:
2018.01.27 16:53:49.647 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (148)
2018.01.27 16:53:49.648 1:     (eval)                              called by ./FHEM/98_fhemdebug.pm (124)
2018.01.27 16:53:49.648 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (166)
2018.01.27 16:53:49.648 1:     main::fhemdebug_memusage            called by ./FHEM/98_fhemdebug.pm (41)
2018.01.27 16:53:49.648 1:     main::fhemdebug_Fn                  called by fhem.pl (1172)
2018.01.27 16:53:49.648 1:     main::AnalyzeCommand                called by fhem.pl (1025)
2018.01.27 16:53:49.648 1:     main::AnalyzeCommandChain           called by ./FHEM/01_FHEMWEB.pm (2486)
2018.01.27 16:53:49.649 1:     main::FW_fC                         called by ./FHEM/01_FHEMWEB.pm (881)
2018.01.27 16:53:49.649 1:     main::FW_answerCall                 called by ./FHEM/01_FHEMWEB.pm (525)
2018.01.27 16:53:49.649 1:     main::FW_Read                       called by fhem.pl (3498)
2018.01.27 16:53:49.649 1:     main::CallFn                        called by fhem.pl (689)



könnte evtl doch meine Hardware der Grund sein?
Habe das ganze jetzt mal wiederholt. Interessanterweise mit anderen Logeinträgen:


2018.01.27 16:59:38.562 5: main::DBD::_::st::BEGIN
2018.01.27 16:59:38.563 5: main::DBD::_::st::FH
2018.01.27 16:59:38.563 5: main::DBD::_::db::ISA
2018.01.27 16:59:38.564 5: main::DBD::_::db::BEGIN
2018.01.27 16:59:38.564 5: main::DBD::Switch::dr_mem::ISA
2018.01.27 16:59:38.564 5: main::DBD::Switch::db::ISA
2018.01.27 16:59:38.565 5: main::DBD::Switch::st::ISA
2018.01.27 16:59:38.565 5: main::DBD::Switch::db_mem::ISA
2018.01.27 16:59:38.566 5: main::DBD::Switch::st_mem::ISA
2018.01.27 16:59:38.566 5: main::DBD::Switch::dr::ISA
2018.01.27 16:59:38.566 5: main::DBD::Switch::dr::imp_data_size
2018.01.27 16:59:38.567 5: main::DBD::_mem::db::ISA
2018.01.27 16:59:38.567 5: main::DBD::_mem::st::ISA
2018.01.27 16:59:38.567 5: main::DBD::_mem::dr::ISA
2018.01.27 16:59:38.568 5: main::DBD::mysql::QUIET
2018.01.27 16:59:38.568 5: main::DBD::mysql::err
2018.01.27 16:59:38.568 5: main::DBD::mysql::BEGIN
2018.01.27 16:59:38.569 5: main::DBD::mysql::db_mem::ISA
2018.01.27 16:59:38.569 5: main::DBD::mysql::st_mem::ISA
2018.01.27 16:59:38.570 5: main::DBD::mysql::dr::imp_data_size
2018.01.27 16:59:38.570 5: main::DBD::mysql::dr::ISA
2018.01.27 16:59:38.571 5: main::DBD::mysql::dr::GetInfoType
2018.01.27 16:59:38.571 5: main::DBD::mysql::dr::BEGIN
2018.01.27 16:59:38.572 5: main::DBD::mysql::ISA
2018.01.27 16:59:38.572 5: main::DBD::mysql::db::b
2018.01.27 16:59:38.573 5: main::DBD::mysql::db::BEGIN
2018.01.27 16:59:38.573 5: main::DBD::mysql::db::ISA
2018.01.27 16:59:38.574 5: main::DBD::mysql::db::__ANON__
2018.01.27 16:59:38.574 5: main::DBD::mysql::db::imp_data_size
2018.01.27 16:59:38.575 5: main::DBD::mysql::db::a
2018.01.27 16:59:38.575 5: main::DBD::mysql::st::imp_data_size
2018.01.27 16:59:38.576 5: main::DBD::mysql::st::BEGIN
2018.01.27 16:59:38.576 5: main::DBD::mysql::st::ISA
2018.01.27 16:59:38.577 5: main::DBD::mysql::st::__ANON__
2018.01.27 16:59:38.577 5: main::DBD::mysql::dr_mem::ISA
2018.01.27 16:59:38.578 5: main::DBD::mysql::GetInfo::info
2018.01.27 16:59:38.578 5: main::DBD::mysql::errstr
2018.01.27 16:59:38.578 5: main::DBD::mysql::drh


und noch ein drittes mal, wieder mit anderen Einträgen... :

2018.01.27 17:08:38.514 5: main::Config::Config_SH_expanded
2018.01.27 17:08:38.514 5: main::Config::BEGIN
2018.01.27 17:08:38.514 5: main::Config::byteorder
2018.01.27 17:08:38.514 5: main::Config::Git_Data
2018.01.27 17:08:38.515 5: main::Config::EXPORT_OK
2018.01.27 17:08:38.515 5: main::Config::Config
2018.01.27 17:08:38.515 5: main::Config::summary
2018.01.27 17:08:38.516 5: main::INPUTFILE
2018.01.27 17:08:38.517 5: main::intAt::3391
2018.01.27 17:08:38.517 5: main::intAt::93
2018.01.27 17:08:38.517 5: main::intAt::2996
2018.01.27 17:08:38.518 5: main::intAt::117
2018.01.27 17:08:38.518 5: main::intAt::75
2018.01.27 17:08:38.519 5: main::intAt::3010
2018.01.27 17:08:38.519 5: main::intAt::3386
2018.01.27 17:08:38.519 5: main::intAt::2992
2018.01.27 17:08:38.520 5: main::intAt::76
2018.01.27 17:08:38.520 5: main::intAt::83
2018.01.27 17:08:38.521 5: main::intAt::2983
2018.01.27 17:08:38.521 5: main::intAt::78
2018.01.27 17:08:38.522 5: main::intAt::3019
2018.01.27 17:08:38.522 5: main::intAt::101
2018.01.27 17:08:38.523 5: main::intAt::3033
2018.01.27 17:08:38.523 5: main::intAt::3000
2018.01.27 17:08:38.524 5: main::intAt::99
2018.01.27 17:08:38.524 5: main::intAt::2437
2018.01.27 17:08:38.525 5: main::intAt::105
2018.01.27 17:08:38.525 5: main::intAt::18
2018.01.27 17:08:38.526 5: main::intAt::3073
2018.01.27 17:08:38.526 5: main::intAt::3393
2018.01.27 17:08:38.526 5: main::intAt::3004
2018.01.27 17:08:38.527 5: main::intAt::3389
2018.01.27 17:08:38.527 5: main::intAt::80
2018.01.27 17:08:38.528 5: main::intAt::3016
2018.01.27 17:08:38.528 5: main::intAt::88
2018.01.27 17:08:38.529 5: main::intAt::97
2018.01.27 17:08:38.529 5: main::intAt::2939
2018.01.27 17:08:38.530 5: main::intAt::3018
2018.01.27 17:08:38.530 5: main::intAt::2940
2018.01.27 17:08:38.531 5: main::intAt::3350
2018.01.27 17:08:38.531 5: main::intAt::95
2018.01.27 17:08:38.531 5: main::intAt::3013
2018.01.27 17:08:38.532 5: main::intAt::3022
2018.01.27 17:08:38.532 5: main::intAt::87
2018.01.27 17:08:38.533 5: main::intAt::1441
2018.01.27 17:08:38.533 5: main::intAt::92
2018.01.27 17:08:38.534 5: main::intAt::3012
2018.01.27 17:08:38.534 5: main::intAt::2877







Grüße,
Stephan 
FHEM nightly auf Intel Atom (lubuntu) mit VDSL 50000 ;-)
Nutze zur Zeit OneWire und KNX

rudolfkoenig

Ich habe memusage umgebaut, dass es Devel::Size::size() statt total_size() verwendet. Dadurch wird vermutlich etliches nicht gemessen, dafuer scheint es nicht mehr abzustuerzen. Und ich hoffe, man kann es trotzdem zum lokalisieren von Speicherloechern verwenden.

Weiterhin problematisch ist die Zuordnung von mehrfach referenzierten Hashes: memusage rechnet solche dem "erstbesten" Referenzierer zu. Z.Bsp. wenn ein Modul die Struktur $modules{ModulName}{defptr} zusaetzlich in jedem GeraeteInstanz dieses Typs ($defs{GeraeteName}) eintraegt, dann ist es Zufall, wem diese Daten zugeordnet werden. Immerhin sollte memusage sowas nur einmal zaehlen.

abc2006

#95
Hi,
sorry, aber es stürzt bei mir immer noch ab:


Zitat2018.01.30 17:04:54.346 5:  CHECK main::count / main:: / count /
2018.01.30 17:04:54.346 5:  CHECK main::cvsid / main:: / cvsid /
2018.01.30 17:04:54.347 5:  CHECK main::data / main:: / data /
2018.01.30 17:04:54.347 5:  CHECK main::defaultattr / main:: / defaultattr /
2018.01.30 17:04:54.347 5:  CHECK main::defs / main:: / defs / HASH
2018.01.30 17:04:54.349 5:  CHECK main::defs::01static_DbRep / main::defs / 01static_DbRep / HASH
2018.01.30 17:04:54.349 5:  CHECK main::defs::01static_DbRep::DATABASE / main::defs::01static_DbRep / DATABASE /
2018.01.30 17:04:54.349 5:  CHECK main::defs::01static_DbRep::DBH / main::defs::01static_DbRep / DBH / DBI::db
2018.01.30 17:04:54.350 1: PERL WARNING: Devel::Size: Unknown variable type: 22 encountered
2018.01.30 17:04:54.350 1: stacktrace:
2018.01.30 17:04:54.350 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (140)
2018.01.30 17:04:54.350 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (137)
2018.01.30 17:04:54.350 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (137)
2018.01.30 17:04:54.351 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (151)
2018.01.30 17:04:54.351 1:     main::fhemdebug_memusage            called by ./FHEM/98_fhemdebug.pm (41)
2018.01.30 17:04:54.351 1:     main::fhemdebug_Fn                  called by fhem.pl (1172)
2018.01.30 17:04:54.351 1:     main::AnalyzeCommand                called by fhem.pl (1025)
2018.01.30 17:04:54.351 1:     main::AnalyzeCommandChain           called by ./FHEM/01_FHEMWEB.pm (2486)
2018.01.30 17:04:54.351 1:     main::FW_fC                         called by ./FHEM/01_FHEMWEB.pm (881)
2018.01.30 17:04:54.352 1:     main::FW_answerCall                 called by ./FHEM/01_FHEMWEB.pm (525)
2018.01.30 17:04:54.352 1:     main::FW_Read                       called by fhem.pl (3511)
2018.01.30 17:04:54.352 1:     main::CallFn                        called by fhem.pl (689)

Grüße,
Stephan

edit:

gerade ist mir passiert, dass ich von dem Rechner, auf dem der Browser offen war, in dem ich fhemdebug ausgeführt habe, die Netzwerkverbindung verloren habe.
Ich versuche noch, herauszufinden, warum. Google, Fhem Forum, Owncloud, FHEM, selbst meine FritzBox war nicht mehr erreichbar ...

FHEM nightly auf Intel Atom (lubuntu) mit VDSL 50000 ;-)
Nutze zur Zeit OneWire und KNX

rudolfkoenig

Ich habe jetzt eine FHEM-Instanz mit DbLog definiert: war etwas schwierig, da die Fehlermeldung der Bibliothek in DbLog.pm unterdrueckt wird, und man sieht nur "Can't connect to database", aber kein warum. Nachdem ich das eval in DbLog.pm entfernt habe, kam die Meldung per PERL WARNING zum Vorschein, und ich konnte das Problem loesen :)

Mit einem Funktionierenden DbLog war fhemdebug memusage bei mir auch abgestuerzt.
Das habe ich jetzt gefixt, indem Klassenvariablen (wie DBI::db) nicht mehr gemessen werden.
Ich wuerde mich ueber erneuten Feedback freuen.

DS_Starter

Hallo Rudi,

ZitatNachdem ich das eval in DbLog.pm entfernt habe,....
An welcher Stelle hast du das eval rausgenommen ?
Eigentlich gebe ich überall beim DBI-connect nach dem eval die resultierende Meldung $@ aus sofern sie existiert, damit solche Warnungen rauskommen.
Wenn ich eine  Stelle übersehen habe, würde ich das gerne nachziehen, habe aber bisher keine gefunden wo es fehlen könnte.

LG,
Heiko



ESXi@NUC+Debian+MariaDB, PV: SMA, Victron MPII+Pylontech+CerboGX
Maintainer: SSCam, SSChatBot, SSCal, SSFile, DbLog/DbRep, Log2Syslog, SolarForecast,Watches, Dashboard, PylonLowVoltage
Kaffeekasse: https://www.paypal.me/HMaaz
Contrib: https://svn.fhem.de/trac/browser/trunk/fhem/contrib/DS_Starter

abc2006

#98
Hi Rudi, hi Heiko,
hier mein Log-Beitrag. Das Ergebnis (Absturz von FHEM) hat sich leider nicht geändert...

2018.01.31 01:37:44.035 5:  CHECK main::b / main:: / b /
2018.01.31 01:37:44.035 5:  CHECK main::base:: / main:: / base:: /
2018.01.31 01:37:44.036 5:  CHECK main::bytes:: / main:: / bytes:: /
2018.01.31 01:37:44.036 5:  CHECK main::cfgDB_FW_fileList / main:: / cfgDB_FW_fileList /
2018.01.31 01:37:44.036 5:  CHECK main::cfgDB_FileRead / main:: / cfgDB_FileRead /
2018.01.31 01:37:44.037 5:  CHECK main::cfgDB_FileWrite / main:: / cfgDB_FileWrite /
2018.01.31 01:37:44.037 5:  CHECK main::cfgDB_Fileversion / main:: / cfgDB_Fileversion /
2018.01.31 01:37:44.037 5:  CHECK main::cfgDB_Read99 / main:: / cfgDB_Read99 /
2018.01.31 01:37:44.038 5:  CHECK main::cfgDB_svnId / main:: / cfgDB_svnId /
2018.01.31 01:37:44.038 5:  CHECK main::cmdFromAnalyze / main:: / cmdFromAnalyze /
2018.01.31 01:37:44.038 5:  CHECK main::cmds / main:: / cmds /
2018.01.31 01:37:44.039 5:  CHECK main::common:: / main:: / common:: /
2018.01.31 01:37:44.039 5:  CHECK main::constant:: / main:: / constant:: /
2018.01.31 01:37:44.039 5:  CHECK main::controlVL_ARD / main:: / controlVL_ARD /
2018.01.31 01:37:44.040 5:  CHECK main::count / main:: / count /
2018.01.31 01:37:44.040 5:  CHECK main::cvsid / main:: / cvsid /
2018.01.31 01:37:44.040 5:  CHECK main::data / main:: / data /
2018.01.31 01:37:44.041 5:  CHECK main::defaultattr / main:: / defaultattr /
2018.01.31 01:37:44.041 5:  CHECK main::defs / main:: / defs / HASH
2018.01.31 01:37:44.042 5:  CHECK main::defs::01static_DbRep / main::defs / 01static_DbRep / HASH
2018.01.31 01:37:44.042 5:  CHECK main::defs::01static_DbRep::DATABASE / main::defs::01static_DbRep / DATABASE /
2018.01.31 01:37:44.043 5:  CHECK main::defs::01static_DbRep::DBH / main::defs::01static_DbRep / DBH / DBI::db
2018.01.31 01:37:44.043 1: PERL WARNING: Devel::Size: Unknown variable type: 139 encountered
2018.01.31 01:37:44.043 1: stacktrace:
2018.01.31 01:37:44.044 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (140)
2018.01.31 01:37:44.044 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (137)
2018.01.31 01:37:44.044 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (137)
2018.01.31 01:37:44.044 1:     main::__ANON__                      called by ./FHEM/98_fhemdebug.pm (151)
2018.01.31 01:37:44.044 1:     main::fhemdebug_memusage            called by ./FHEM/98_fhemdebug.pm (41)
2018.01.31 01:37:44.044 1:     main::fhemdebug_Fn                  called by fhem.pl (1172)
2018.01.31 01:37:44.045 1:     main::AnalyzeCommand                called by fhem.pl (1025)
2018.01.31 01:37:44.045 1:     main::AnalyzeCommandChain           called by ./FHEM/01_FHEMWEB.pm (2486)
2018.01.31 01:37:44.045 1:     main::FW_fC                         called by ./FHEM/01_FHEMWEB.pm (881)
2018.01.31 01:37:44.045 1:     main::FW_answerCall                 called by ./FHEM/01_FHEMWEB.pm (525)
2018.01.31 01:37:44.045 1:     main::FW_Read                       called by fhem.pl (3508)
2018.01.31 01:37:44.046 1:     main::CallFn                        called by fhem.pl (689)


Dazu muss ich sagen, ich hab die Version

fhem.pl                16050 2018-01-30 20:21:02Z rudolfkoenig

aus dem SVN geholt. Kann bis zum Wochenende wahrscheinlich nicht weiter testen.
Danke euch und Grüße,
Stephan

Edit: an der DbLog hattest du nichts geändert - oder?
Die Versionsnummer scheint gleich zu sein...
FHEM nightly auf Intel Atom (lubuntu) mit VDSL 50000 ;-)
Nutze zur Zeit OneWire und KNX

rudolfkoenig

@Heiko: Ich habe alle 12 connect Aufrufe mit Log versehen, da ich nicht wusste, welcher bei mir zutrifft, und Nr 6 hat zugeschlagen (DbLog_ConnectPush, # Server default). $@ war in meinem Fall nichtssagend, es kam nur
ZitatDbLog db -> DbLog_Push Returncode: Can't connect to database.
Nach dem Ausbau von eval habe ich
ZitatPERL WARNING: DBI connect('database=fhem;host=localhost;port=3306','fhemuser',...) failed:Can't connect to local MySQL server through socket '/tmp/mysql.sock' (2) at ./FHEM/93_DbLog.pm line 2277.
bekommen, woraufhin ich statt localhost die IP konfiguriert habe in db.conf, und schon ging es. Diese spezifische Meldung ist nicht als Fehlermeldung an DbLog zu verstehen (ist eher ein DBD::mysql Konfigurations-Bug), sondern nur als Erklaerung, dass ich mit einer besseren Fehlermeldung mehr anfangen kann. Und es bedeutet auch nicht, dass ich das Verfahren, wie DBI die Fehler meldet, fuer richtig finde.

@Stephan: bist du sicher, dass due diese Version auch verwendet (sprich FHEM neugestartet) hast?
Wenn ja, dann bin ich ratlos, eine CHECK Zeile mit :: im letzten Wort ($ref) duerfte gar nicht kommen.

abc2006

Hi,


2018.01.31 01:36:27.411 4: WEB: /fhem?cmd=setreading%20tempOWarduino%20289B8489060000%2062.06&XHR=1 / RL:0 / text/plain; charset=UTF-8 /  /
2018.01.31 01:36:27.412 4: Connection accepted from WEB_192.168.0.100_48948
2018.01.31 01:36:27.415 4: WEB_192.168.0.100_48948 POST /fhem?XHR=1&cmd=shutdown%20restart&fw_id=40303; BUFLEN:0
2018.01.31 01:36:27.416 5: Cmd: >shutdown restart<
2018.01.31 01:36:27.416 5: Starting notify loop for global, 1 event(s), first is SHUTDOWN
2018.01.31 01:36:27.417 5: statistics stats_KNX: Notify.266 Notification of 'global' received. Device not monitored.
2018.01.31 01:36:27.456 5: End notify loop for global
2018.01.31 01:36:27.456 0: Server shutdown


Ja, bin mir sicher. Ich mach aber nochmal nen Reboot, weil auch "reload" ab und zu nicht den gewünschten erfolg bringt.




2018.01.31 12:47:25.991 5:  CHECK main::cmdFromAnalyze / main:: / cmdFromAnalyze /
2018.01.31 12:47:25.992 5:  CHECK main::cmds / main:: / cmds /
2018.01.31 12:47:25.992 5:  CHECK main::common:: / main:: / common:: /
2018.01.31 12:47:25.993 5:  CHECK main::constant:: / main:: / constant:: /
2018.01.31 12:47:25.993 5:  CHECK main::controlVL_ARD / main:: / controlVL_ARD /
2018.01.31 12:47:25.993 5:  CHECK main::count / main:: / count /
2018.01.31 12:47:25.994 5:  CHECK main::cvsid / main:: / cvsid /
2018.01.31 12:47:25.994 5:  CHECK main::data / main:: / data /
2018.01.31 12:47:25.995 5:  CHECK main::defaultattr / main:: / defaultattr /
2018.01.31 12:47:25.995 5:  CHECK main::defs / main:: / defs / HASH
2018.01.31 12:47:25.996 5:  CHECK main::defs::01static_DbRep / main::defs / 01static_DbRep / HASH
2018.01.31 12:47:25.997 5:  CHECK main::defs::01static_DbRep::DATABASE / main::defs::01static_DbRep / DATABASE /
2018.01.31 12:47:25.997 5:  CHECK main::defs::01static_DbRep::DBH / main::defs::01static_DbRep / DBH / DBI::db


sorry :( Immerhin jetzt anscheinend reproduzierbar an der gleichen Stelle ....
Vielleicht stürzt fhem ab, bevor es die ganze Zeile loggen kann?

Grüße,
Stephan
FHEM nightly auf Intel Atom (lubuntu) mit VDSL 50000 ;-)
Nutze zur Zeit OneWire und KNX

rudolfkoenig

Sehr merkwuerdig, kann ich nicht erklaeren.
Habe trotzdem eine neue Version eingecheckt, die die Groessen der defs Eintraege an richtigen Stelle zaehlen sollte, und keine Sinnlose symbole in main:: anlegt.

Jens_B

... ich habe hier dasselbe Problem, und es tritt erst auf seitdem ich homebridge auf demselben pi wie fhem laufen lasse.
Bevor ich homebridge benutzt habe (inkl fhem Plugin) lief Fhem wochenlang, es gab auch kein Speicher voll laufen.
Ich habe den Verdacht das das Homebridge Modul in Fhem oder homebridge selbst  dafür verantwortlich ist.

RaspberryPi 4 (Raspian Buster)FHEM+Homebridge
HMLAN für Homematic
Z-Wave USB Stick
Shelly Devices
Fritz!Box 7590Ax

andies

Ich habe nun auch diese Fehlermeldungen (cannot fork), obwohl der RPi 3 drei Monate mit FHEM durchlief und ich tausende Kilometer davon entfernt war. Inzwischen in drei Tagen fünf Abstürze. Ich habe nur freezemon definiert und hinzugefügt, sonst mW nichts geändert. Ich gebe mal an, was ich so ausgelesen habe.

memusage
   1. defs                             829081
   2. modules                          433412
   3. modules::eventTypes              187594
   4. modules::eventTypes::ldata       186532
   5. attr                              95641
   6. defs::sysmon                      49940
   7. defs::MeinWetter                  47322
   8. defs::MeinWetter::READINGS        45306
   9. defs::Gasrechner                  35094
  10. defs::Gasrechner::READINGS        33577
  11. POSIX::                           32038
  12. defs::sysmon::READINGS            30735
  13. defs::X10_prog                    26643
  14. defs::Stromrechner                24435
  15. defs::X10_prog::READINGS          24237
  16. B::                               20324
  17. defs::TelegramBot                 19410
  18. modules::eventTypes::ldata::sduino    19298
  19. defs::Viessmann                   17765
  20. modules::eventTypes::ldata::MeinWetter    17141
  21. Socket::                          16978
  22. modules::eventTypes::ldata::Schulferien    16706
  23. defs::Stromrechner::READINGS      16633
  24. defs::Sonoff_pow1                 14195
  25. defs::Anwesenheitssimulation_Slampher    14166
  26. defs::Viessmann::READINGS         14094
  27. GetInfoType                       13572
  28. defs::sysmon::helper              13505
  29. INC                               13435
  30. defs::WEB_127.0.0.1_49054         13386
  31. defs::Anwesenheitssimulation_B1    12588
  32. defs::wetter                      12574
  33. modules::CUL_TCM97001             12506
  34. defs::WEB_127.0.0.1_49054::inform    11844
  35. defs::GarageOffenDOIF             11663
  36. defs::TelefonListe                11639
  37. defs::Sonoff_TH10a                11638
  38. modules::eventTypes::ldata::TelegramBot    11622
  39. defs::sduino                      11509
  40. defs::sysmon::helper::cur_readings_map    11321
  41. defs::Anwesenheitssimulation_A_Strich    11263
  42. defs::WEB_127.0.0.1_49054::inform::devices    11167
  43. defs::Schulferien                 11025
  44. defs::Kaffeemaschine              10996
  45. modules::CUL_TCM97001::AutoCreate    10934
  46. defs::TelefonListe::helper        10711
  47. defs::DECT1                       10670
  48. defs::Sonoff_pow1::READINGS       10612
  49. defs::Heizungskeller              10570
  50. defs::SensorHydrAbgleich_rot      10520


ps -elf | sort -rnk 10 | head
4 S root      1738  1734  0  80   0 - 222309 -     20:50 ?        00:00:02 ./grafana-server
4 S mysql     1195   851 11  80   0 - 81218 -      20:48 ?        00:03:57 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib/mysql/plugin --user=mysql --log-error=/var/log/mysql/error.log --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/run/mysqld/mysqld.sock --port=3306
0 S pi         824     1  0  80   0 - 33953 SyS_ep 20:48 ?        00:00:04 homebridge             
5 S www-data  1245  1224  0  80   0 - 29657 -      20:48 ?        00:00:00 /usr/sbin/apache2 -k start
5 S www-data  1249  1224  0  80   0 - 29645 -      20:48 ?        00:00:00 /usr/sbin/apache2 -k start
5 S www-data  1248  1224  0  80   0 - 29645 -      20:48 ?        00:00:00 /usr/sbin/apache2 -k start
5 S www-data  1247  1224  0  80   0 - 29645 -      20:48 ?        00:00:00 /usr/sbin/apache2 -k start
5 S www-data  1246  1224  0  80   0 - 29645 -      20:48 ?        00:00:00 /usr/sbin/apache2 -k start
5 S root      1224     1  0  80   0 - 29639 -      20:48 ?        00:00:00 /usr/sbin/apache2 -k start
1 S fhem      2100     1  1  80   0 - 25230 -      20:58 ?        00:00:25 perl fhem.pl fhem.cfg


{ join(",", grep { !$defs{$_} } sort keys %attr) }
HASH(0x2e85a50),HASH(0x38c87b0),secDbLog


{ int(keys %defs).":".int(keys %attr) }
144:136

{ join(",", grep { !$defs{$_} } sort keys %attr) }
HASH(0x2e85a50),HASH(0x38c87b0),secDbLog


blockinginfo
No BlockingCall processes running currently

{ join("\n", map { "$intAt{$_}{TRIGGERTIME} / $intAt{$_}{FN}" } (sort {$intAt{$a}{TRIGGERTIME}<=>$intAt{$b}{TRIGGERTIME}} keys %intAt)[0..49]) }
1524338303.0287 / BlockingKill
1524338308 / FW_closeInactiveClients
1524338308.01267 / SIGNALduino_KeepAlive
1524338308.0135 / SYSMON_Update
1524338314.7129 / FBAHAHTTP_Poll
1524338314.86999 / HTTPMOD_GetUpdate
1524338314.87649 / HTTPMOD_GetUpdate
1524338315.05323 / VZLOGGER_StatusTimer
1524338360.34303 / HttpUtils_Err
1524338760 / DOIF_TimerTrigger
1524338911.16104 / VCLIENT_Update
1524338914.88248 / HTTPMOD_GetUpdate
1524340714.87097 / HTTPMOD_GetUpdate
1524340718.1983 / Weather_GetUpdate
1524340920 / DOIF_TimerTrigger
1524341160 / DOIF_TimerTrigger
1524343114.76058 / HTTPMOD_GetUpdate
1524344305.9826 / DBPlan_Get_DB_Info
1524344460 / DOIF_TimerTrigger
1524344520 / at_Exec
1524344520 / DOIF_TimerTrigger
1524344580 / DOIF_TimerTrigger
1524346114.87351 / HTTPMOD_GetUpdate
1524346114.87612 / HTTPMOD_GetUpdate
1524346114.87861 / HTTPMOD_GetUpdate
1524346114.88373 / HTTPMOD_GetUpdate
1524346114.8862 / HTTPMOD_GetUpdate
1524346114.88869 / HTTPMOD_GetUpdate
1524346114.89377 / HTTPMOD_GetUpdate
1524347400 / at_Exec
1524347850 / at_Exec
1524348001 / FileLog_dailySwitch
1524348002.71843 / holiday_refresh
1524348060 / at_Exec
1524358716.32815 / Pushover_ValidateUser
1524358800 / at_Exec
1524369900 / DOIF_TimerTrigger
1524373200 / DOIF_TimerTrigger
1524373800 / DOIF_TimerTrigger
1524373800 / DOIF_TimerTrigger
1524373800 / DOIF_TimerTrigger
1524374400 / DOIF_TimerTrigger
1524374400 / DOIF_TimerTrigger
1524375900 / DOIF_TimerTrigger
1524375960 / DOIF_TimerTrigger
1524377700 / DOIF_TimerTrigger
1524379500 / DOIF_TimerTrigger
1524379500 / at_Exec
1524380700 / DOIF_TimerTrigger
1524420060 / DOIF_TimerTrigger


{ int(keys %intAt) }
58



Hat jemand eine Idee, wo ich weitersuchen kann?
FHEM 6.1 auf RaspPi3 (Raspbian:  6.1.21-v8+; Perl: v5.32.1)
SIGNALduino (433 MHz) und HM-UART (868 MHz), Sonoff, Blitzwolf, Somfy RTS, CAME-Gartentor, Volkszähler, Keyence-Sensor, Homematic-Sensoren und -thermostat, Ferraris-Zähler für Wasseruhr, Openlink-Nachbau Viessmann

Shadow3561

Moin,
bei mir auch seit ein paar Tagen ein cannot fork im Log.

Leider kann ich fhemdebug memusage nicht nutzen.
Folgende Meldung kommt dann
Can't load '/usr/local/lib/arm-linux-gnueabihf/perl/5.22.1/auto/Devel/Size/Size.so' for module Devel::Size: /usr/lib/arm-linux-gnueabihf/libc.so: invalid ELF header at /usr/local/lib/arm-linux-gnueabihf/perl/5.22.1/XSLoader.pm line 96.
at /usr/local/lib/arm-linux-gnueabihf/perl/5.22.1/Devel/Size.pm line 19.
Compilation failed in require at (eval 3278) line 2.
BEGIN failed--compilation aborted at (eval 3278) line 2.


Habe das Modul libdevel-size-perl installiert und auch mit cpan Devel::Size versucht.
kann evtl jemand helfen?
mfg