merkwürdige Fehlermeldungen im 20Minuten-Takt

cs-online · 25 November 2020, 13:03:32

Hallo,

ich hatte am Wochenanfang einen Crash meiner SD-Karte im RPI4 und musste aus einer älteren Sicherung (vom Januar 2020) für das OS und einer neuen FHEM-Sicherung wiederherstellen. Nun bekomme ich ungewohnterweise viele Fehlermeldungen und zwar eine Bestimmte im genauen 20 Minuten-Takt. Hat jemand eine Idee, was da das Problem sein könnte ?

Hier mal ein Ausschnitt aus dem LOG:

Code Auswählen

020.11.25 11:42:03 0: Strange call for nonexistent : ReadFn
2020.11.25 11:42:03 1: stacktrace:
2020.11.25 11:42:03 1:     main::CallFn                        called by fhem.pl (755)
2020.11.25 11:42:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 50853) line 1.
2020.11.25 11:42:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 50854) line 1.
2020.11.25 11:43:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 51414) line 1.
2020.11.25 11:43:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 51415) line 1.
2020.11.25 11:44:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 51854) line 1.
2020.11.25 11:44:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 51855) line 1.
2020.11.25 11:45:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 52348) line 1.
2020.11.25 11:45:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 52349) line 1.
2020.11.25 11:46:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 52773) line 1.
2020.11.25 11:46:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 52774) line 1.
2020.11.25 11:47:03 0: Strange call for nonexistent : ReadFn
2020.11.25 11:47:03 1: stacktrace:
2020.11.25 11:47:03 1:     main::CallFn                        called by fhem.pl (755)
2020.11.25 11:47:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 53228) line 1.
2020.11.25 11:47:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 53229) line 1.
2020.11.25 11:48:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 53848) line 1.
2020.11.25 11:48:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 53849) line 1.
2020.11.25 11:49:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 54277) line 1.
2020.11.25 11:49:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 54278) line 1.
2020.11.25 11:50:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 54683) line 1.
2020.11.25 11:50:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 54684) line 1.
2020.11.25 11:50:47 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 54787) line 37.
2020.11.25 11:50:47 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 54787) line 38.
2020.11.25 11:51:04 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 54904) line 37.
2020.11.25 11:51:04 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 54904) line 38.
2020.11.25 11:51:23 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 55101) line 37.
2020.11.25 11:51:23 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 55101) line 38.
2020.11.25 11:51:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 55181) line 1.
2020.11.25 11:51:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 55182) line 1.
2020.11.25 11:51:40 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 55237) line 37.
2020.11.25 11:51:40 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 55237) line 38.
2020.11.25 11:52:03 0: Strange call for nonexistent : ReadFn
2020.11.25 11:52:03 1: stacktrace:
2020.11.25 11:52:03 1:     main::CallFn                        called by fhem.pl (755)
2020.11.25 11:52:18 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 55508) line 37.
2020.11.25 11:52:18 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 55508) line 38.
2020.11.25 11:52:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 55619) line 1.
2020.11.25 11:52:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 55620) line 1.
2020.11.25 11:53:11 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 55982) line 37.
2020.11.25 11:53:11 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 55982) line 38.
2020.11.25 11:53:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 56134) line 1.
2020.11.25 11:53:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 56135) line 1.
2020.11.25 11:54:03 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 56313) line 37.
2020.11.25 11:54:03 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 56313) line 38.
2020.11.25 11:54:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 56593) line 1.
2020.11.25 11:54:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 56594) line 1.
2020.11.25 11:54:56 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 56734) line 37.
2020.11.25 11:54:56 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 56734) line 38.
2020.11.25 11:55:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 56980) line 1.
2020.11.25 11:55:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 56981) line 1.
2020.11.25 11:55:48 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 57081) line 37.
2020.11.25 11:55:48 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 57081) line 38.
2020.11.25 11:56:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 57382) line 1.
2020.11.25 11:56:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 57383) line 1.
2020.11.25 11:56:38 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 57436) line 37.
2020.11.25 11:56:38 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 57436) line 38.
2020.11.25 11:57:03 0: Strange call for nonexistent : ReadFn
2020.11.25 11:57:03 1: stacktrace:
2020.11.25 11:57:03 1:     main::CallFn                        called by fhem.pl (755)
2020.11.25 11:57:31 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 57814) line 37.
2020.11.25 11:57:31 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 57814) line 38.
2020.11.25 11:57:34 1: PERL WARNING: Argument "-" isn't numeric in division (/) at (eval 57846) line 1.

Grüße Christian

cs-online · 27 November 2020, 14:53:03

Hallo,

inzwischen konnte ich fast alle anderen Fehler entfernen, es bleibt aber der hier

Code Auswählen

020.11.25 11:42:03 0: Strange call for nonexistent : ReadFn
2020.11.25 11:42:03 1: stacktrace:
2020.11.25 11:42:03 1:     main::CallFn                        called by fhem.pl (755)

und merkwürdigerweise nicht mehr im 20-Minuten-Takt sondern völlig unterschiedlich. Soweit ich verstanden habe, wird in Zeile 755 eine Funktion aufgerufen, die etwas mit "Rückmeldung von Geräten" zu tun hat. Gibt es eine Möglichkeit, rauszufinden, welches Gerät den Fehler erzeugt ? Ich habe versucht vor dem Funktionsaufruf die Variable $hash ins Log schreiben zu lassen, das hat aber nur dazu geführt, dass FHEM gar nicht mehr gestartet ist...

Grüße

Christian

Beta-User · 27 November 2020, 15:01:48

Würde tippen, dass irgendeines deiner FHEM-Module kaputt ist.

Da du (scheinbar) der einzige bist, der das berichtet, würde ich bei "exotischen" Modulen aus fremder Quelle beginnen, tendenziell ist es ein Client-Modul nach dem zweistufigen Modell. Vermutlich ist da in der "initialize"-Routine eine {ReadFn} genannt, die es in dem Modul gar nicht gibt (Schreibfehler oder so).

cs-online · 27 November 2020, 18:48:03

hmmm... ich hab schon ein update force durchlaufen lassen, da sind ja alle Module neu geladen worden, trotzdem der Fehler. Inzwischen hab ich das hinbekommen, den $hash bzw. den $isDev ausgeben zu lassen und das sieht um den Fehler dann so aus:

Code Auswählen

2020.11.27 18:39:05 1: Gerät: HASH(0x2a45ff8)
2020.11.27 18:39:06 1: Gerät: HASH(0x108d4e0)
2020.11.27 18:39:06 1: Gerät: HASH(0x5491618)
2020.11.27 18:39:06 1: Gerät: 
2020.11.27 18:39:06 0: Strange call for nonexistent : ReadFn
2020.11.27 18:39:06 1: stacktrace:
2020.11.27 18:39:06 1:     main::CallFn                        called by fhem.pl (756)
2020.11.27 18:39:06 1: Gerät: HASH(0x5491618)
2020.11.27 18:39:06 1: Gerät: HASH(0x34f8538)
2020.11.27 18:39:06 1: Gerät: HASH(0x34f8538)

Wie man sehen kann, ist im Fehlerfall der $isDev leer und dann läuft das wohl ins Leere... Aber warum ? Kann man den Fehler noch genauer eingrenzen, dass z.B. das misteriöse Device mit ausgegeben wird ? Natürlich könnte man nun einfach abfangen, dass bei leerem Wert die CallFn aufgerufen wird, aber.......

EDIT: Das mit dem Namen des Devices hab ich schon selber hinbekommen, nun bin ich gespannt, welches den Fehler auslöst...

cs-online · 27 November 2020, 20:10:25

also.... es wird kein Gerät übergeben wie es aussieht

Code Auswählen

2020.11.27 20:01:53 1: Gerät: HASH(0x29d0f48) - LaCrosseGateway
2020.11.27 20:01:53 1: Gerät: HASH(0x29d0f48) - LaCrosseGateway
2020.11.27 20:01:53 1: Gerät: HASH(0x29d0f48) - LaCrosseGateway
2020.11.27 20:01:53 1: Gerät:  - 
2020.11.27 20:01:53 0: Strange call for nonexistent : ReadFn
2020.11.27 20:01:53 1: stacktrace:
2020.11.27 20:01:53 1:     main::CallFn                        called by fhem.pl (756)
2020.11.27 20:01:54 1: Gerät: HASH(0x29d0f48) - LaCrosseGateway
2020.11.27 20:01:54 1: Gerät: HASH(0x29d0f48) - LaCrosseGateway
2020.11.27 20:01:54 1: Gerät: HASH(0x346bd18) - Stromzaehler
2020.11.27 20:01:54 1: Gerät: HASH(0x346bd18) - Stromzaehler

Vielleicht fällt Rudi da ja noch was zu ein, ich werd das einfach mal abfangen, wenn das leer ist, wird die Funktion einfach nicht ausgeführt...

Beta-User · 28 November 2020, 14:33:25

Nochmal: Schau mal nach, ob du irgendein Modul im Einsatz hast, das NIÇHT im FHEM-Standard ist. Klingt für mich nach einem Fehler in was "selbstgestricktem"...
Da müßte es einen Eintrag für ReadFn in der Initialisierung geben, aber nicht weiter unten im Code auch was, was tatsächlich unter dem Namen oben aufrufbar ist.

frank · 28 November 2020, 14:41:31

bei 20min würde ich auch fhem.cfg durchsuchen:
1. "00:20"
2. "1200" (sekunden)

cs-online · 28 November 2020, 20:43:40

Zitat von: Beta-User am 28 November 2020, 14:33:25
Nochmal: Schau mal nach, ob du irgendein Modul im Einsatz hast, das NIÇHT im FHEM-Standard ist. Klingt für mich nach einem Fehler in was "selbstgestricktem"...
Da müßte es einen Eintrag für ReadFn in der Initialisierung geben, aber nicht weiter unten im Code auch was, was tatsächlich unter dem Namen oben aufrufbar ist.

Danke für die Anregung, aber ich habe ausser den "normalen", die über FHEM-Update kommen, nur die 99_myUtils.pm und da gibt es kein ReadFn drin

cs-online · 28 November 2020, 21:20:38

Zitat von: frank am 28 November 2020, 14:41:31
bei 20min würde ich auch fhem.cfg durchsuchen:
1. "00:20"
2. "1200" (sekunden)

die Idee hatte ich auch und leider gab es nirgends z.B. einen 20 Minuten Timer oder sowas . Aber wie bereits geschrieben, war das dann irgendwann nicht mehr 20 Minuten... Aber ich habe einen 5 und einen 10 Minuten Timer, die hab ich nun mal abgeschaltet, mal schauen was passiert...

KernSani · 06 April 2021, 23:06:35

Ich hänge mich mal mit rein. Ich habe die Meldung ebenfalls.
@cs-online: Hast du das Problem beheben können?

M.E. ist der Auslöser HttpUtils_gethostbyname, konkret der non-blocking DNS Call. Bei mir tritt der Fehler nicht regelmäßig auf, aber nachvollziehbar nur wenn dnsServer in global gesetzt ist (egal, ob ich meinen eigenen pihole oder z.B. 8.8.8.8 eintrage). Im Verdacht habe ich das echodevice Modul, kann aber nicht ausschließen, dass es auch bei anderen Modulen auftritt. Soweit ich das beurteilen kann, macht das echodevice einen ganz normalen HttpUtils_NonblockingGet.

Grüße,

Oli

EDIT: Fortsetzung hier: https://forum.fhem.de/index.php/topic,120173.msg1146516.html#msg1146516

cs-online · 14 April 2021, 20:29:52

Hi Oli,

ich hab mir zwischendurch so geholfen, dass ich in der fhem.pl in der Zeile, die die Fehlermeldung auslöste, den $hash abgefragt habe und die Funktion nur ausgeführt habe, wenn der nicht leer war... aber nach jedem Update musste ich das wieder neu machen, also hab ich das dann irgendwann angefangen zu ignorieren...

Grüße Christian