ERROR: Cannot autoload FS20V - wie weiter eingrenzen?

[yersinia]

Hallo zusammen,

ich habe heute (zum Ersten mal überhaupt) folgende Fehlermeldung im log:

Code: [Auswählen]

2021.11.26 11:20:06 0: ERROR: Cannot autoload FS20V
2021.11.26 11:20:06 1: PERL WARNING: Illegal hexadecimal digit 'm' ignored at ./FHEM/10_FS20.pm line 439.Hatte heute morgen ein Update auf rev 25261 duchgeführt. Aktualisiert worden:

Code: [Auswählen]

2021.11.26 09:11:39 1: UPD ./CHANGED
2021.11.26 09:11:39 1: UPD FHEM/00_THZ.pm
2021.11.26 09:11:39 1: UPD FHEM/10_EnOcean.pm
2021.11.26 09:11:39 1: UPD FHEM/10_KNX.pm
2021.11.26 09:11:39 1: UPD FHEM/10_ZWave.pm
2021.11.26 09:11:39 1: UPD FHEM/31_HUEDevice.pm
2021.11.26 09:11:39 1: UPD FHEM/49_Arlo.pm
2021.11.26 09:11:39 1: UPD FHEM/88_HMCCU.pm
2021.11.26 09:11:40 1: UPD FHEM/88_HMCCUCHN.pm
2021.11.26 09:11:40 1: UPD FHEM/88_HMCCUDEV.pm
2021.11.26 09:11:40 1: UPD FHEM/88_HMCCURPCPROC.pm
2021.11.26 09:11:40 1: UPD FHEM/90_at.pm
2021.11.26 09:11:40 1: UPD FHEM/93_DbRep.pm
2021.11.26 09:11:40 1: UPD FHEM/98_Text2Speech.pm
2021.11.26 09:11:40 1: UPD FHEM/98_WeekdayTimer.pm
2021.11.26 09:11:40 1: UPD FHEM/HMCCUConf.pm
2021.11.26 09:11:40 1: UPD FHEM/lib/AttrTemplate/mqtt2.template
2021.11.26 09:11:40 1: UPD FHEM/lib/openzwave_manufacturer_specific.xmlFHEM läuft bei mir unter RaspiOS 11 (Bullseye) mit perl v5.32.1.

Bevor ich jetzt verbose auf 5 und stacktrace einschalte, würde ich gern vorab versuchen einzugrenzen, was den autoload hätte initiieren können. Auch um den Fehler nachstellen zu können - und ggf. Ausiwrkungen zu bewerten.
Bewusst nutze ich keine FS20 Geräte und 10_FS20.pm letztes Update ist auch schon ein Weilchen her.

Falls es mit CUL_HM zu tun haben könnte, sei der Hinweis ergänzt, dass ich TSCULfw inklusive aller Module von noansi verwende.

Vielleicht kann mich ja jmd in die 'richtigere' Richtung schubsen.

[rudolfkoenig]

Die zitierten Zeilen sind irritierend:
Die Ursache, warum FS20V (kein Standard-Modul) nicht geladen werden konnte, steht vor der "Cannot autoload" Zeile.
Etwas mehr an Details ueber "Illegal hexadecimal digit" sollten in den folgenden Zeilen stehen.

Vermutlich hat die Quelle (CUL?) irgendetwas Komisches geschickt.
Da du die noansi Varianten verwendest (Firmware + FHEM CUL Modul), sollte mMn er das weiter untersuchen.

[yersinia]

Das hab ich bewusst weggelassen weil es einen großen zeitlichen Sprung gibt (fast 40min):

Code: [Auswählen]

2021.11.26 10:41:12 3: CUL_HM set KellerfensterGarten getConfig noArg
2021.11.26 10:41:44 2: HMinfo hm get:configCheck :-f,^(KellerfensterGarten|KellerfensterGarten)$
2021.11.26 11:20:06 0: ERROR: Cannot autoload FS20V
2021.11.26 11:20:06 1: PERL WARNING: Illegal hexadecimal digit 'm' ignored at ./FHEM/10_FS20.pm line 439.
2021.11.26 12:18:19 3: HMinfo hm get:update :
2021.11.26 12:18:19 3: CUL_HM set ActionDetector update noArg
2021.11.26 12:18:19 3: CUL_HM set VCCU update noArgWie gesagt, ich fahre zZt verbose 3 ohne stacktrace. Aber beides will ich auch nicht einschalten solange ich das nicht deutlich weiter eingrenzen kann - müllt mir nur den log voll.

Danke, dann schau' ich mal im noansi Thread weiter.

[noansi]

Hallo yersinia,

Du benutzt auch noch einmal aculfw, vermutlich über das CUL Modul eingebunden?
Zumindest sagt Dein Footer was von aculfw.

Ich wüsste zur Zeit nicht, wo ein 'm' von tsculfw her kommen sollte. Das wird von einem nanoCUL mit tsculfw 0.39 nicht gesendet.
Weiterhin wird bei vollem TX buffer beim nanoCUL bei display_char gewartet, bis wieder Platz im Puffer ist. Somit kann Durcheinander bei Zeichenfolgen nicht von dieser Quelle kommen, bis auf die Ausnahme eines Watchdog Resets des tsculs. Einen Restart Eintrag zu so einem Event sehe ich nicht in Deinem Log Auszug. Aber auch solch ein Watchdog Reset führt nicht zu einem 'm' bei einem nanoCUL.

Aber die aculfw sendet ein 'm' wenn sie Manchester Code auf SlowRf empfangen hat (oder glaubt empfangen zu haben). Und wenn der TX Puffer bei der aculfw voll läuft, dann wird nur noch zu gesehen, dass ein '\n' und/oder '\r' an das Puffer Ende gequetscht werden kann. Zeichenfolgensalat ist hier also möglich was dann bei der Interpretation im CUL oder TSCUL Modul zu Fehlleitungen an weitere Module führen kann. Daher vermute ich mal bei dem aculfw device die Quelle für Deine Log Einträge aus den bisherigen Informationen.

Kommt das öfter seit dem Update? Dann besteht vielleicht ein Zusammenhang. Ansonsten wäre es ein seltenes Zufallsereignis.

Wenn es öfter passieren würde, müsstest Du mit mehr verbose Log-Daten der empfangenen Zeichenfolgen liefern.

Gruß, Ansgar.

[yersinia]

Du benutzt auch noch einmal aculfw, vermutlich über das CUL Modul eingebunden?

Ja, korrekt. Für 433MHz (vier Tempsensoren) nutz ich einen nanoCUL mit aculfw 1.26.08

Code: [Auswählen]

Internals:
   CMDS       ABCeFfGiKLlMNRTtUVWXx
   Clients    :FS20:FHT.*:KS300:USF1000:BS:HMS:FS20V: :CUL_EM:CUL_WS:CUL_FHTTK:CUL_HOERMANN: :ESA2000:CUL_IR:CUL_TX:Revolt:IT:UNIRoll:SOMFY: :STACKABLE_CC:TSSTACKED:STACKABLE:CUL_RFR::CUL_TCM97001:CUL_REDIRECT::OREGON::Hideki:
   DEF        /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A50285BI-if00-port0@38400 0000
   DeviceName /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A50285BI-if00-port0@38400
   FD         11
   FHTID      0000
   FUUID      5c443cee-f33f-3151-e168-c4667b4184539660
   NAME       nanoCUL_433_1
   NR         36
   PARTIAL   
   RAWMSG     s9798039528F5;  512: 9088
   RSSI       -89
   STATE      2021-11-27 16:19:53 Initialized
   TIME       1638026376.4989
   TYPE       CUL
   VERSION    V 1.26.08 a-culfw Build: 323 (2019-08-03_09-32-54) nanoCUL433 (F-Band: 433MHz)
   devioNoSTATE 1
   initString X21
   nanoCUL_433_1_MSGCNT 13975
   nanoCUL_433_1_TIME 2021-11-27 16:19:53
   .attraggr:
   .attreocr:
     .*
   .attrminint:
   .clientArray:
     FS20
     IT
     UNIRoll
     CUL_REDIRECT
     CUL_TCM97001
     Hideki
     OREGON
   MatchList:
     0:FS20V    ^81..(04|0c)..0101a001......00[89a-f]...
     1:USF1000  ^81..(04|0c)..0101a001a5ceaa00....
     2:BS       ^81..(04|0c)..0101a001a5cf
     3:FS20     ^81..(04|0c)..0101a001
     4:FHT      ^81..(04|09|0d)..(0909a001|83098301|c409c401)..
     5:KS300    ^810d04..4027a001
     6:CUL_WS   ^K.....
     7:CUL_EM   ^E0.................$
     8:HMS      ^810e04......a001
     9:CUL_FHTTK ^T[A-F0-9]{8}
     A:CUL_RFR  ^[0-9A-F]{4}U.
     B:CUL_HOERMANN ^R..........
     C:ESA2000  ^S................................$
     C:Hideki   ^P12#75[A-F0-9]{17,30}
     C:OREGON   ^(3[8-9A-F]|[4-6][0-9A-F]|7[0-8]).*
     D:CUL_IR   ^I............
     E:CUL_TX   ^TX[A-F0-9]{10}
     F:Revolt   ^r......................$
     G:IT       ^i......
     H:STACKABLE_CC ^\*
     I:UNIRoll  ^[0-9A-F]{5}(B|D|E)
     J:SOMFY    ^Y[r|t|s]:?[A-F0-9]+
     K:CUL_TCM97001 ^s[A-F0-9]+
     L:CUL_REDIRECT ^o+
     M:TSSTACKED ^\*
     N:STACKABLE ^\*
   READINGS:
     2021-11-26 09:11:56   Initialized     
     2018-03-05 17:04:02   ccconf          freq:433.920MHz bWidth:325KHz rAmpl:42dB sens:4dB
     2021-11-26 09:12:17   cmds             A B C e F f G i K L l M N R T t U V W X x
     2019-11-26 17:01:41   raw             is1F1D111F1F1F
     2021-11-27 16:19:53   state           Initialized
     2021-08-25 15:34:56   uptime          0 00:04:56
     2021-09-24 11:30:31   version         V 1.26.08 a-culfw Build: 323 (2019-08-03_09-32-54) nanoCUL433 (F-Band: 433MHz)
     2018-03-11 21:18:26   |               Initialized
Attributes:
   event-on-change-reading .*
   group      CUL
   icon       cul_cul
   longids    1
   model      nanoCUL
   stateFormat {return ReadingsTimestamp($name,'state','')." ".ReadingsVal($name,'state','');}
   verbose    2

Aber die aculfw sendet ein 'm' wenn sie Manchester Code auf SlowRf empfangen hat (oder glaubt empfangen zu haben). Und wenn der TX Puffer bei der aculfw voll läuft, dann wird nur noch zu gesehen, dass ein '\n' und/oder '\r' an das Puffer Ende gequetscht werden kann. Zeichenfolgensalat ist hier also möglich was dann bei der Interpretation im CUL oder TSCUL Modul zu Fehlleitungen an weitere Module führen kann. Daher vermute ich mal bei dem aculfw device die Quelle für Deine Log Einträge aus den bisherigen Informationen.

Kommt das öfter seit dem Update? Dann besteht vielleicht ein Zusammenhang. Ansonsten wäre es ein seltenes Zufallsereignis.

Interessant, dann ist dies möglicherweise im aculfw nanoCUL zu verorten. Und nein, ich sehe (bewusst) diese Meldung bisher zum ersten Mal und wiederholt sich auch nicht. Vielleicht gab es durch einen (wahrscheinlich sehr seltenen) Zufall Zeichensalat. Ich werde das beobachten und wenn es nochmal auftreten sollte, weiter untersuchen und mich dann hier wieder melden. Aber dank deines Hinweises hab ich jetzt eine Richtung auf die ich genauer schauen kann. Danke.