Autor Thema: main::CallFn called by fhem.pl (773)  (Gelesen 891 mal)

Offline TomLee

  • Hero Member
  • *****
  • Beiträge: 3583
  • ... wer sät, der erntet ...
main::CallFn called by fhem.pl (773)
« am: 12 September 2021, 12:16:01 »
Hallo,

hab seit Wochen i.d.R einmal in der Nacht diesen Eintrag im Log, heute mehrfach, kann mir bitte wer einen Tipp geben wie ich die Ursache finde ?

2021.09.12 00:00:00 3: alexa: using logfile: ./log/alexa-2021-09-12.log
2021.09.12 03:04:45 1: OWXTHERM_BinValues:  EG_Innensensor_Buero: invalid CRC,  -0.0625  0xff 0xff 0xff 0xff 0xff 0xff 0xff 0xff 0xff
2021.09.12 03:35:08 0: Strange call for nonexistent : ReadFn
2021.09.12 03:35:08 1: stacktrace:
2021.09.12 03:35:08 1:     main::CallFn                        called by fhem.pl (773)
2021.09.12 04:24:03 3: MQTT2_Server: MQTT2_Server_192.168.188.34_39492/ebusd_3.3_505 left us (keepalive check)
2021.09.12 04:27:28 3: MQTT2_Server: MQTT2_Server_192.168.188.128_50764/mysensors-1 left us (keepalive check)
2021.09.12 04:43:09 0: Strange call for nonexistent : ReadFn
2021.09.12 04:43:09 1: stacktrace:
2021.09.12 04:43:09 1:     main::CallFn                        called by fhem.pl (773)
2021.09.12 04:43:49 0: Strange call for nonexistent : ReadFn
2021.09.12 04:43:49 1: stacktrace:
2021.09.12 04:43:49 1:     main::CallFn                        called by fhem.pl (773)
2021.09.12 04:51:49 0: Strange call for nonexistent : ReadFn
2021.09.12 04:51:49 1: stacktrace:
2021.09.12 04:51:49 1:     main::CallFn                        called by fhem.pl (773)
2021.09.12 04:53:09 0: Strange call for nonexistent : ReadFn
2021.09.12 04:53:09 1: stacktrace:
2021.09.12 04:53:09 1:     main::CallFn                        called by fhem.pl (773)
2021.09.12 04:55:49 0: Strange call for nonexistent : ReadFn
2021.09.12 04:55:49 1: stacktrace:
2021.09.12 04:55:49 1:     main::CallFn                        called by fhem.pl (773)
2021.09.12 05:05:49 0: Strange call for nonexistent : ReadFn
2021.09.12 05:05:49 1: stacktrace:
2021.09.12 05:05:49 1:     main::CallFn                        called by fhem.pl (773)
2021.09.12 11:28:31 2: After sleep: done

Offensichtlich hat es ja was mit Homematic zu tun, hier mal vorsichtshalber vorab mal meine HMUARTLGW- und VCCU-Definitionen:

defmod HMUART1 HMUARTLGW /dev/ttyAMA0
attr HMUART1 hmId F12030
attr HMUART1 room Homematic

setstate HMUART1 opened
setstate HMUART1 2021-09-08 11:28:35 D-HMIdAssigned F12030
setstate HMUART1 2021-09-08 11:28:35 D-HMIdOriginal 6A5832
setstate HMUART1 2021-09-08 11:28:37 D-firmware 1.4.1
setstate HMUART1 2021-09-08 11:28:39 D-serialNr PEQ0533394
setstate HMUART1 2021-09-08 11:27:11 D-type HM-MOD-UART
setstate HMUART1 2021-09-08 11:28:41 cond ok
setstate HMUART1 2021-09-12 11:57:00 load 0
setstate HMUART1 2021-09-08 11:28:41 loadLvl low
setstate HMUART1 2021-09-08 11:27:26 state opened

defmod VCCU CUL_HM F12030
attr VCCU .mId FFF0
attr VCCU IOList HMUART1
attr VCCU IOgrp VCCU
attr VCCU expert defReg,rawReg
attr VCCU model CCU-FHEM
attr VCCU room Homematic
attr VCCU subType virtual
attr VCCU webCmd virtual

setstate VCCU HMUART1:ok
setstate VCCU 2021-03-04 11:07:18 .associatedWith VCCU,VCCU_Btn1,VCCU
setstate VCCU 2021-09-08 11:28:12 IODev HMUART1
setstate VCCU 2021-09-08 11:28:41 IOopen 1
setstate VCCU 2021-09-08 11:28:41 state HMUART1:ok

Gruß

Thomas

Offline TomLee

  • Hero Member
  • *****
  • Beiträge: 3583
  • ... wer sät, der erntet ...
Antw:main::CallFn called by fhem.pl (773)
« Antwort #1 am: 12 September 2021, 19:09:34 »
Welches Unterforum wäre denn das Richtige wenn es um fhem.pl geht ?

Offline Beta-User

  • Developer
  • Hero Member
  • ****
  • Beiträge: 15761
Antw:main::CallFn called by fhem.pl (773)
« Antwort #2 am: 12 September 2021, 20:37:26 »
Hast du eine aktuelle CUL_HM im Einsatz? Wenn ja: welche? Das Problem ist jedenfalls nicht fhem.pl, das ist nur das "ausführende Organ", das nach dem Motto handelt "Melden macht frei".

Falls CUL_HM: Ich habe da was gesehen, was in die Richtung gehen könnte, und hatte das in meinen letzten Testversionen (nicht mehr der allerletzten!) gefixt. (Die Stellen sind noch markiert und hoffentlich gut zu finden, siehe kommentierter patch in https://forum.fhem.de/index.php/topic,122422.msg1174414.html#msg1174414)
Server: HP-T620@Debian 10, aktuelles FHEM + ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn:MySensors, Weekday-&RandomTimer, Twilight,  AttrTemplate {u.a. mqtt2, mysensors, zwave}

Offline TomLee

  • Hero Member
  • *****
  • Beiträge: 3583
  • ... wer sät, der erntet ...
Antw:main::CallFn called by fhem.pl (773)
« Antwort #3 am: 12 September 2021, 21:52:48 »
Zitat
10_CUL_HM.pm 24851 2021-08-15 05:57:45Z martinp876

Hatte nicht vor mich damit weiter/tiefer mit zu beschäftigen, die angehängte Datei hab ich mir (noch) nicht angeschaut, mach ich vlt. noch.

Offline Beta-User

  • Developer
  • Hero Member
  • ****
  • Beiträge: 15761
Antw:main::CallFn called by fhem.pl (773)
« Antwort #4 am: 12 September 2021, 22:34:57 »
...brauchst du nicht, ich war vermutlich auf dem Holzweg...

Das zu finden wird vermutlich schwierig, es sei denn, die Zeiten könnte man irgendwie zuordnen.
ReadFn klingt nach DevIo-Nutzung, vielleicht schaust du mal mit "fhemdebug timerList" (?), ob da irgendwo was komisches zu finden ist? Es müsste sich um ein Modul handeln, das von irgendwo her Daten liest.
Server: HP-T620@Debian 10, aktuelles FHEM + ConfigDB | CUL_HM (VCCU) | MQTT2: MiLight@ESP-GW, BT@OpenMQTTGw | MySensors: seriell, v.a. 2.3.1@RS485 | ZWave | ZigBee@deCONZ | SIGNALduino | MapleCUN | RHASSPY
svn:MySensors, Weekday-&RandomTimer, Twilight,  AttrTemplate {u.a. mqtt2, mysensors, zwave}

Offline betateilchen

  • Developer
  • Hero Member
  • ****
  • Beiträge: 17481
  • s/fhem\.cfg/configDB/g
Antw:main::CallFn called by fhem.pl (773)
« Antwort #5 am: 12 September 2021, 22:57:19 »
Welches Unterforum wäre denn das Richtige wenn es um fhem.pl geht ?

Ein Blick in die MAINTAINER.txt könnte helfen, diese Frage zu beantworten.
-----------------------
Unaufgeforderte Anfragen per email werden von mir nicht beantwortet. Dafür ist das Forum da.
-----------------------
Lesen gefährdet die Unwissenheit!

Offline betateilchen

  • Developer
  • Hero Member
  • ****
  • Beiträge: 17481
  • s/fhem\.cfg/configDB/g
Antw:main::CallFn called by fhem.pl (773)
« Antwort #6 am: 12 September 2021, 23:03:10 »
Ich würde einfach in die fhem.pl direkt vor der Zeile 773 die Zeile

Debug $hash->{NAME};
einfügen und schauen, was dann im Log auftaucht.
-----------------------
Unaufgeforderte Anfragen per email werden von mir nicht beantwortet. Dafür ist das Forum da.
-----------------------
Lesen gefährdet die Unwissenheit!

Offline TomLee

  • Hero Member
  • *****
  • Beiträge: 3583
  • ... wer sät, der erntet ...
Antw:main::CallFn called by fhem.pl (773)
« Antwort #7 am: 12 September 2021, 23:15:15 »
fhemdebug timerList kannte ich noch nicht, Danke, das gefällt mir.

OT: Ist es korrekt das mir in der Liste alle ATs angezeigt werden die eigentlich inactive gesetzt sind ?



Zitat
Debug $hash->{NAME};

Danke, mach ich, sieht/hört sich vielversprechend aus/an.
« Letzte Änderung: 12 September 2021, 23:22:29 von TomLee »

Offline betateilchen

  • Developer
  • Hero Member
  • ****
  • Beiträge: 17481
  • s/fhem\.cfg/configDB/g
Antw:main::CallFn called by fhem.pl (773)
« Antwort #8 am: 13 September 2021, 08:20:13 »
OT: Ist es korrekt das mir in der Liste alle ATs angezeigt werden die eigentlich inactive gesetzt sind ?

Logischerweise ja.
Die at werden trotzdem gestartet, sie tun nur nix. Das ist wichtig, um bei wiederkehrenden at den nächsten Ausführungszeitpunkt berechnen zu können.
-----------------------
Unaufgeforderte Anfragen per email werden von mir nicht beantwortet. Dafür ist das Forum da.
-----------------------
Lesen gefährdet die Unwissenheit!
Informativ Informativ x 1 Liste anzeigen

Offline TomLee

  • Hero Member
  • *****
  • Beiträge: 3583
  • ... wer sät, der erntet ...
Antw:main::CallFn called by fhem.pl (773)
« Antwort #9 am: 13 September 2021, 16:34:24 »
Aus Interesse, hab eben die debug-Ausgabe erst ergänzt, geh davon aus das die Änderung doch erst nach einem restart greift oder würd auch einfach reload fhem.pl ausreichen ?

edit:

Ok, reload fhem.pl geht gar nicht.

Can't read ./FHEM/fhem.pl.pm: No such file or directory
« Letzte Änderung: 14 September 2021, 11:34:00 von TomLee »

Offline TomLee

  • Hero Member
  • *****
  • Beiträge: 3583
  • ... wer sät, der erntet ...
Antw:main::CallFn called by fhem.pl (773)
« Antwort #10 am: 14 September 2021, 22:05:50 »
Wenn ich die debug-Ausgabe kurze Zeit aktiviere sehe ich im Log in kurzer Zeit etliche Devices die nicht in Frage kommen, die Log-Datei würde ewig groß werden wenn ich das über Nacht aktiviert lasse, würde das gerne vermeiden, man kann das doch bestimmt irgendwie ? bspw. mit einem regulären Ausdruck der die Namen ausnimmt die nicht in Frage kommen (meinetwegen geb ich die Namen alle einzeln an), kompensieren ?

Offline Jamo

  • Hero Member
  • *****
  • Beiträge: 1430
Antw:main::CallFn called by fhem.pl (773)
« Antwort #11 am: 20 September 2021, 17:58:28 »
Hallo TomLee,
ich habe auch die Fehlermeldung, allerdings tritt das bei mir nur Nachts zwischen 2 und 3 Uhr bei der Zwangstrennung auf.
Ich habe folgendes in fhem.pl ergänzt, um den Log File nicht überlaufen zu lassen:
my ($sec,$min,$hour,$mday,$month,$year,$wday,$yday,$isdst) = localtime(gettimeofday());
my $hms = sprintf("%02d:%02d:%02d", $hour, $min, $sec);
if ($hms ge "02:00:00" && $hms le "03:00:00") {Debug $hash->{NAME};}

Äquivalent kannst Du Dir deine eigenen Bedingungen definieren.
Linux Debian, Homematic (UART/HMUSB), HUEBridge, Zigbee, FB, Alexa (fhem-lazy), livetracking, fhemApp Frontend für FHEM

Offline TomLee

  • Hero Member
  • *****
  • Beiträge: 3583
  • ... wer sät, der erntet ...
Antw:main::CallFn called by fhem.pl (773)
« Antwort #12 am: 20 September 2021, 18:27:27 »
Danke.

Ja, so um die Zwangstrennung war mir eigentlich auch in Erinnerung, bis zum ersten Post, da war mir halt aufgefallen das es später wie sonst und dann auch gleich mehrfach zu der Meldung kam, deshalb hatte ich dann auch mal nachgefragt.
Natürlich kam die Meldung bisher nicht mehr, zumindest ist sie mir nicht aufgefallen, hab die letzten Tage aber auch hier und da was ausprobiert wozu ich dann das Log immer löschte und auf die Meldung nicht achtete. Ich werds einfach mal einbauen.

Offline Jamo

  • Hero Member
  • *****
  • Beiträge: 1430
Antw:main::CallFn called by fhem.pl (773)
« Antwort #13 am: 21 September 2021, 10:18:55 »
Ich habe jetzt die Zwangstrennung in der FB einfach manuell herbeigeführt, und kann die Meldung reproduzieren.
Das passiert jedesmal nach dem Aufruf von den Presence collect devices. Hier die def vom den Presence devices (stellvertretend für alle), und die Log einträge.

In fhem.pl ist "Debug $hash->{NAME};" eingefügt, wie betateilchen vorgeschlagen hatte.

Wo kommt die Meldung jetzt her??

defmod Presence_GTag_RED_collect PRESENCE lan-bluetooth 7C:2F:80:98:C2:2A 127.0.0.1:5222 300 300
attr Presence_GTag_RED_collect absenceThreshold 3
attr Presence_GTag_RED_collect alias PresenceRED_LE
attr Presence_GTag_RED_collect event-on-change-reading batteryPercent,presence
attr Presence_GTag_RED_collect group PRESENCE,SERVER
attr Presence_GTag_RED_collect room Favourites,Presence
attr Presence_GTag_RED_collect sortby 041
attr Presence_GTag_RED_collect stateFormat {myPresenceGTagCollectStateFormat($name)}
attr Presence_GTag_RED_collect verbose 0
attr Presence_GTag_RED_collect webCmd statusRequest

 2021.09.21 09:47:23 1: DEBUG>WEB_192.168.0.14_56513
2021.09.21 09:47:23 1: DEBUG>DLNASocket-myRenderer-1900
2021.09.21 09:47:23 1: DEBUG>DLNASocket-myRenderer-1900
2021.09.21 09:47:23 1: DEBUG>deCONZ
2021.09.21 09:47:24 1: DEBUG>Presence_GTag_RED_collect
2021.09.21 09:47:24 1: DEBUG>Presence_GTag_White_collect
2021.09.21 09:47:24 1: DEBUG>Presence_Gast_Orange_collect
2021.09.21 09:47:24 1: DEBUG>
2021.09.21 09:47:24 0: Strange call for nonexistent : ReadFn
2021.09.21 09:47:24 1: stacktrace:
2021.09.21 09:47:24 1:     main::CallFn                        called by /opt/fhem/fhem.pl (773)
2021.09.21 09:47:25 1: DEBUG>HMUART1
2021.09.21 09:47:25 1: DEBUG>HMUART1
2021.09.21 09:47:25 1: DEBUG>HMUART1
2021.09.21 09:47:25 1: DEBUG>HMUART2
2021.09.21 09:47:25 1: DEBUG>HMUART3
2021.09.21 09:47:25 1: DEBUG>HMUSB1
2021.09.21 09:47:25 1: DEBUG>d_rpc000001HmIP_RF
2021.09.21 09:47:26 1: DEBUG>DLNASocket-myRenderer-1900
2021.09.21 09:47:26 1: DEBUG>DLNASocket-myRenderer-1900
2021.09.21 09:47:26 1: DEBUG>DLNASocket-myRenderer-1900
2021.09.21 10:01:18 1: DEBUG>telnetForBlockingFn_1632210020_127.0.0.1_45950
2021.09.21 10:01:19 1: DEBUG>Presence_GTag_Black_collect
2021.09.21 10:01:20 1: DEBUG>deCONZ
2021.09.21 10:01:21 1: DEBUG>deCONZ
2021.09.21 10:01:21 1: DEBUG>deCONZ
2021.09.21 10:01:21 1: DEBUG>deCONZ
2021.09.21 10:01:22 1: DEBUG>Presence_GTag_RED_collect
2021.09.21 10:01:23 1: DEBUG>Presence_Jamo_Orange_collect
2021.09.21 10:01:23 1: DEBUG>Presence_GTag_Black_collect
2021.09.21 10:01:23 1: DEBUG>Presence_Jamo_Orange_collect
2021.09.21 10:01:23 1: DEBUG>Presence_GTag_RED_collect
2021.09.21 10:01:24 1: DEBUG>
2021.09.21 10:01:24 0: Strange call for nonexistent : ReadFn
2021.09.21 10:01:24 1: stacktrace:
2021.09.21 10:01:24 1:     main::CallFn                        called by /opt/fhem/fhem.pl (773)
2021.09.21 10:01:24 1: DEBUG>Presence_GTag_Black_collect
2021.09.21 10:01:24 1: DEBUG>Presence_GTag_White_collect
2021.09.21 10:01:24 1: DEBUG>Presence_Gast_Orange_collect
2021.09.21 10:01:24 1: DEBUG>Presence_GTag_RED_collect
2021.09.21 10:01:26 1: DEBUG>HMUART1
2021.09.21 10:01:26 1: DEBUG>HMUART1
2021.09.21 10:01:26 1: DEBUG>HMUART1
2021.09.21 10:01:26 1: DEBUG>HMUART1
2021.09.21 10:01:26 1: DEBUG>HMUART3
2021.09.21 10:01:26 1: DEBUG>HMUSB1
2021.09.21 10:01:26 1: DEBUG>HMUART2
2021.09.21 10:01:26 1: DEBUG>deCONZ
2021.09.21 10:01:26 1: DEBUG>DLNASocket-myRenderer-1900
2021.09.21 10:07:22.487 1: DEBUG>WEB_192.168.0.14_60567
2021.09.21 10:07:23.322 1: DEBUG>Presence_Jamo_Orange_collect
2021.09.21 10:07:23.327 1: DEBUG>Presence_Jamo_Orange_collect
2021.09.21 10:07:23.332 1: DEBUG>Presence_GTag_RED_collect
2021.09.21 10:07:23.336 1: DEBUG>Presence_GTag_Black_collect
2021.09.21 10:07:24.327 1: DEBUG>Presence_GTag_White_collect
2021.09.21 10:07:24.328 1: DEBUG>Presence_GTag_White_collect
2021.09.21 10:07:24.330 1: DEBUG>Presence_Gast_Orange_collect
2021.09.21 10:07:24.332 1: DEBUG>Presence_GTag_RED_collect
2021.09.21 10:07:24.784 1: DEBUG>
2021.09.21 10:07:24.785 0: Strange call for nonexistent : ReadFn
2021.09.21 10:07:24.785 1: stacktrace:
2021.09.21 10:07:24.785 1:     main::CallFn                        called by /opt/fhem/fhem.pl (773)
2021.09.21 10:07:25.287 1: DEBUG>HMUSB1
2021.09.21 10:07:26.751 1: DEBUG>DLNASocket-myRenderer-1900
2021.09.21 10:07:26.752 1: DEBUG>DLNASocket-myRenderer-1900
2021.09.21 10:07:26.752 1: DEBUG>DLNASocket-myRenderer-1900
2021.09.21 10:07:28.833 1: DEBUG>HMUART2
2021.09.21 10:07:28.895 1: DEBUG>HMUART3
2021.09.21 10:07:28.925 1: DEBUG>d_rpc000001HmIP_RF
2021.09.21 10:07:28.946 1: DEBUG>d_rpc000001HmIP_RF
2021.09.21 10:07:29.155 1: DEBUG>HMUART1
« Letzte Änderung: 21 September 2021, 10:20:49 von Jamo »
Linux Debian, Homematic (UART/HMUSB), HUEBridge, Zigbee, FB, Alexa (fhem-lazy), livetracking, fhemApp Frontend für FHEM

Offline frank

  • Hero Member
  • *****
  • Beiträge: 10388
Antw:main::CallFn called by fhem.pl (773)
« Antwort #14 am: 21 September 2021, 10:32:29 »
$hash->{NAME} ist leer oder nicht definiert, wenn der fehler kommt.
FHEM: 6.0(SVN) => Pi3(buster)
IO: CUL433|CUL868|HMLAN|HMUSB2|HMUART
CUL_HM: CC-TC|CC-VD|SEC-SD|SEC-SC|SEC-RHS|Sw1PBU-FM|Sw1-FM|Dim1TPBU-FM|Dim1T-FM|ES-PMSw1-Pl
IT: ITZ500|ITT1500|ITR1500|GRR3500
WebUI [hm.js]: https://forum.fhem.de/index.php/topic,106959.0.html