Pairing schläg fehl: empty name in readingsBeginUpdate

[Uef]

Hallo, ich benötige Eure Hilfe !

Ich versuche, einen Fensterkontakt (MAX_054e32, type ShutterContact, serial JEQ0394420) zu pairen, was aber mit diversen Fehlermeldung scheitert.
Es wird auch kein Device angelegt; in  der fhem.cfh kann ich die ID MAX_054e32 (oder Teile davon) nicht finden.

Die Fehlermeldungen beziehen sich anscheinend auf einen fehlenden Namen.
Der Betrieb der anderen MAX Device funktioniert problemlos, daher gehe ich aktuell davon aus, dass es nicht der CUL ist.

Hier ist der Auszug aus dem Log, für den in verbose sowohl im CUL als auch im CUL_MAX auf 5 getzt hatte:

Code: [Auswählen]

...
2022.07.30 14:05:45.513 5: CUL_Read: CUL_0 /Z17030400054E321234560013040F4A4551303339343432300A
2022.07.30 14:05:45.514 4: CUL_Parse: CUL_0 Z17030400054E321234560013040F4A4551303339343432300A -69
2022.07.30 14:05:45.515 5: CUL_0: dispatch Z17030400054E321234560013040F4A455130333934343230
2022.07.30 14:05:45.519 3: CUL_MAX, source device 054e32 has no name !
2022.07.30 14:05:45.519 5: CUL_MAX, IODev CUL_0, len 23, msgcnt 03, msgflag 04, msgType PairPing, src 054e32, dst 123456, group 0, payload 13040F4A455130333934343230, rssi -69
2022.07.30 14:05:45.520 4: CUL_MAX, PairPing (dst 123456, pairmode 1), firmware 19, type ShutterContact, testresult 15, serial JEQ0394420
2022.07.30 14:05:45.520 3: CUL_MAX, Re-Pairing device MAX_054e32 of type ShutterContact with serial JEQ0394420
2022.07.30 14:05:45.521 5: CUL_MAX: dispatch MAX,1,define,054e32,ShutterContact,JEQ0394420,0
2022.07.30 14:05:45.521 5: MAX_Parse, MAX,1,define,054e32,ShutterContact,JEQ0394420,0
2022.07.30 14:05:45.522 1: MAX_Parse, ohne Namen msg: MAX,1,define,054e32,ShutterContact,JEQ0394420,0
2022.07.30 14:05:45.539 1: ERROR: empty name in readingsBeginUpdate
2022.07.30 14:05:45.539 1: stacktrace:
2022.07.30 14:05:45.540 1:     main::readingsBeginUpdate           called by ./FHEM/14_CUL_MAX.pm (862)
2022.07.30 14:05:45.540 1:     main::CUL_MAX_Parse                 called by fhem.pl (4128)
2022.07.30 14:05:45.540 1:     main::Dispatch                      called by ./FHEM/00_CUL.pm (975)
2022.07.30 14:05:45.541 1:     main::CUL_Parse                     called by ./FHEM/00_CUL.pm (840)
2022.07.30 14:05:45.541 1:     main::CUL_Read                      called by fhem.pl (3932)
2022.07.30 14:05:45.541 1:     main::CallFn                        called by fhem.pl (781)
2022.07.30 14:05:45.542 1: PERL WARNING: Use of uninitialized value $name in concatenation (.) or string at fhem.pl line 4982.
2022.07.30 14:05:45.542 1: readingsUpdate(,firmware,1.3) missed to call readingsBeginUpdate first.
2022.07.30 14:05:45.543 1: stacktrace:
2022.07.30 14:05:45.543 1:     main::readingsBulkUpdate            called by ./FHEM/14_CUL_MAX.pm (863)
2022.07.30 14:05:45.543 1:     main::CUL_MAX_Parse                 called by fhem.pl (4128)
2022.07.30 14:05:45.544 1:     main::Dispatch                      called by ./FHEM/00_CUL.pm (975)
2022.07.30 14:05:45.544 1:     main::CUL_Parse                     called by ./FHEM/00_CUL.pm (840)
2022.07.30 14:05:45.544 1:     main::CUL_Read                      called by fhem.pl (3932)
2022.07.30 14:05:45.544 1:     main::CallFn                        called by fhem.pl (781)
2022.07.30 14:05:45.545 1: readingsUpdate(,testresult,15) missed to call readingsBeginUpdate first.
2022.07.30 14:05:45.545 1: stacktrace:
2022.07.30 14:05:45.546 1:     main::readingsBulkUpdate            called by ./FHEM/14_CUL_MAX.pm (864)
2022.07.30 14:05:45.546 1:     main::CUL_MAX_Parse                 called by fhem.pl (4128)
2022.07.30 14:05:45.546 1:     main::Dispatch                      called by ./FHEM/00_CUL.pm (975)
2022.07.30 14:05:45.546 1:     main::CUL_Parse                     called by ./FHEM/00_CUL.pm (840)
2022.07.30 14:05:45.547 1:     main::CUL_Read                      called by fhem.pl (3932)
2022.07.30 14:05:45.547 1:     main::CallFn                        called by fhem.pl (781)
2022.07.30 14:05:45.547 1: readingsUpdate(,PairedTo,123456) missed to call readingsBeginUpdate first.
2022.07.30 14:05:45.548 1: stacktrace:
2022.07.30 14:05:45.548 1:     main::readingsBulkUpdate            called by ./FHEM/14_CUL_MAX.pm (865)
2022.07.30 14:05:45.548 1:     main::CUL_MAX_Parse                 called by fhem.pl (4128)
2022.07.30 14:05:45.549 1:     main::Dispatch                      called by ./FHEM/00_CUL.pm (975)
2022.07.30 14:05:45.549 1:     main::CUL_Parse                     called by ./FHEM/00_CUL.pm (840)
2022.07.30 14:05:45.549 1:     main::CUL_Read                      called by fhem.pl (3932)
2022.07.30 14:05:45.549 1:     main::CallFn                        called by fhem.pl (781)
2022.07.30 14:05:45.550 1: readingsUpdate(,SerialNr,JEQ0394420) missed to call readingsBeginUpdate first.
2022.07.30 14:05:45.550 1: stacktrace:
2022.07.30 14:05:45.550 1:     main::readingsBulkUpdate            called by ./FHEM/14_CUL_MAX.pm (866)
2022.07.30 14:05:45.551 1:     main::CUL_MAX_Parse                 called by fhem.pl (4128)
2022.07.30 14:05:45.551 1:     main::Dispatch                      called by ./FHEM/00_CUL.pm (975)
2022.07.30 14:05:45.551 1:     main::CUL_Parse                     called by ./FHEM/00_CUL.pm (840)
2022.07.30 14:05:45.552 1:     main::CUL_Read                      called by fhem.pl (3932)
2022.07.30 14:05:45.552 1:     main::CallFn                        called by fhem.pl (781)
2022.07.30 14:05:45.552 1: PERL WARNING: Use of uninitialized value $d in hash element at fhem.pl line 4718.
2022.07.30 14:05:45.553 1: PERL WARNING: Use of uninitialized value $dev in hash element at fhem.pl line 3796.
2022.07.30 14:05:45.553 4: CUL_MAX, send -> cmd:PairPong, msgcnt:01, flags:00, Cmd2id:01, src:MAX_123456 , dst:MAX_054e32 , gid:00 , payload:00 , cul:none
2022.07.30 14:05:45.554 5: CUL_MAX, send packet: 0b010001123456054e320000
2022.07.30 14:05:45.554 5: CUL_MAX, Send Queue 1 packet in queue
2022.07.30 14:05:45.572 5: DevIo_SimpleWrite CUL_0: X
2022.07.30 14:05:45.574 5: CUL_ReadAnswer CUL_0: 21  900

2022.07.30 14:05:45.608 5: CUL_MAX, Send Queue CUL_0 -> needPreamble: 1, necessaryCredit: 110, credit10ms: 900, CUL_0 CMD_LAST_H: 4
2022.07.30 14:05:45.609 5: CUL_0 sending Zs0b010001123456054e320000
2022.07.30 14:05:45.609 5: DevIo_SimpleWrite CUL_0: Zs0b010001123456054e320000
2022.07.30 14:05:45.611 4: CUL_MAX, Send Queue packet send : Zs0b010001123456054e320000 to MAX_054e32 with CUL_0
2022.07.30 14:05:46.557 5: CUL_MAX, Send Queue 1 packet in queue
2022.07.30 14:05:46.675 5: CUL_Read: CUL_0 /Z0C010202054E3212345600011006

2022.07.30 14:05:46.676 4: CUL_Parse: CUL_0 Z0C010202054E3212345600011006 -71
2022.07.30 14:05:46.677 5: CUL_0: dispatch Z0C010202054E32123456000110
2022.07.30 14:05:46.682 3: CUL_MAX, source device 054e32 has no name !
2022.07.30 14:05:46.683 5: CUL_MAX, IODev CUL_0, len 12, msgcnt 01, msgflag 02, msgType Ack, src 054e32, dst 123456, group 0, payload 0110, rssi -71
2022.07.30 14:05:46.684 5: CUL_MAX, ACK from MAX_054e32 for cmd PairPong , packet will be removed soon
2022.07.30 14:05:46.684 5: CUL_MAX, delete packet Index 0 in SendQueue direct !
2022.07.30 14:05:46.686 5: CUL_MAX: dispatch MAX,1,Ack,054e32,0110
2022.07.30 14:05:46.686 5: MAX_Parse, MAX,1,Ack,054e32,0110
2022.07.30 14:05:46.687 1: MAX_Parse, ohne Namen msg: MAX,1,Ack,054e32,0110
2022.07.30 14:05:47.059 5: CUL_MAX, Send Queue 0 packets in queue
2022.07.30 14:06:05.496 5: CUL_Read: CUL_0 /Z0C4D04420769D00992430009D500

2022.07.30 14:06:05.497 4: CUL_Parse: CUL_0 Z0C4D04420769D00992430009D500 -74
2022.07.30 14:06:05.498 5: CUL_0: dispatch Z0C4D04420769D00992430009D5
2022.07.30 14:06:05.502 5: CUL_MAX, IODev CUL_0, len 12, msgcnt 4D, msgflag 04, msgType WallThermostatControl, src 0769d0, dst 099243, group 0, payload 09D5, rssi -74

Ich hatte vor einiger Zeit ein sehr ähnliches Problem https://forum.fhem.de/index.php/topic,127574.msg1220904.html#msg1220904 , aber die Lösung funktioniert hier nicht, da ich diese ID auch in jahrealten LogFile oder fhem.cfg nicht gefunden habe.

Hat jemand einen Tipp dazu ?
Mir gehen da die Ideen aus ....

Gruß aus Aachen
Uwe

[Wzut]

Welche Version von 10_MAX bzw 14_CUL_MAX benutzt du ? Beta oder die aus dem svn ?
Ist bei die autocreate aktiv ? - so wie ich das Log lese schlägt wohl autocreate fehl, daher halt auch kein FHEM Name zur MAX ID 054e32
Lösung : Leg dir doch einfach via define ein MAX Gerät von Typ ShutterContact mit der ID 054e32 von Hand an.

[Uef]

Danke Wzut.

Hier die Versionen (beide sollten aus dem normalen Update stammen):
# $Id: 10_MAX.pm 23517 2021-01-13 15:38:49Z Wzut $
# $Id: 14_CUL_MAX.pm 22175 2020-06-13 17:32:49Z Wzut $

autocreate war leider nicht aktiviert (ich hatte das mit autosave verwechselt), ist aber korrigiert.
Die Fehlermeldungen sind nur leicht anders. Der leere Name wird aber immer noch bemängelt.

Ein define habe ich ebenfalls probiert:
define Keller_Tuer MAX ShutterContact 054e32
Ergebnis: "MAX_Define, a MAX device with address 054e32 is already defined as " (die Zeile ist so komplett, d.h. sie endet hinter dem 'as')
Das passt also zum Fehler mit dem leeren Namen.

Bleibt wieder die Frage, wie ich die Definition des Devices finden soll.
Ich habe schon ohne Erfolg eine Volltextsuche nach '054e32' auf den gesamten fhem-Verzeichnisbaum gemacht.
Und im Gegensatz zum letzten Mal hat die Liste der Logfiles keine Erinnerung daran geweckt, wo ich das Device schon mal eingesetzt haben sollte.

Bisher sind solche Probleme nur im Zusammenhang mit den MAX-Devices und auch erst seit kurzem aufgetreten (habe sie aber auch schon länger nicht mehr angefasst; HMs konnte ich letztens jedoch hinzufügen)
Oder ob ich von in der Vergangenheit aufgetretenen Problemen wie einer gestorbenen SD-Karte irgendwelche verborgenen Leichen in meiner config habe.
Und ggf. mal alles neu aufsetzen sollte - was ich natürlich gern vermeiden würde :-)
Andere Probleme als die hier genannten habe ich allerdings aktuell nicht (ausser denen vorm Rechner).

Gruß
Uwe

[Beta-User]

a) https://forum.fhem.de/index.php/topic,127574.0.html hilft nicht weiter?
b) Eventuell gibt es auch Probleme, weil das Attribut IODev nicht (richtig) gesetzt ist. Sowas kann neuerdings vorkommen, evtl. sind die "alten" Versionen der MAX-Module darauf nicht optimiert.
c) Klone von gestorbenen SD-Karten sind vermutlich auch immer für Überraschungen gut....

@Wzut: Checkst du die "Beta-Test"-Versionen eigentlich irgendwann ein? (Oder ist das schon passiert).
@Uef: Falls es die immer noch als Test-Versionen gibt, solltest du m.E. in Erwägung ziehen, die einzusetzen...

[Uef]

Danke Beta-User

zu a) das war ja eher ein Zufallstreffer, weil ich über den alten Namen des Devices auf die entsprechenden LogFiles geschlossen habe. Das war aber nur geraten ...
Eine entsprechende Assoziation habe ich hier leider nicht :-(  . Ich könnte höchstens auf Verdacht mal alle Logfiles aus der fhem.cfg nehmen und dann schauen. Da weiß ich aktuell nicht genau, wann ich dazu komme.

zu b) würde ich ja gerne korrigieren, aber ohne Zugriff auf die Definition des Devices wüsste ich nicht wie

zu c) ich denke eh über FHEM im Container nach (was ja eine gute Gelegenheit wäre), aber das braucht ja einige dieser legendären langen Winterabende ... und so lange wollte ich das aktuelle Projekt eigentlich nicht ruhen lassen.

Was ich auf jeden Fall mal versuchen werde zu testen: falls ich ein garantiert noch nie gepairtes MAX Device in meiner Bastelkiste habe, versuche ich mal, das einzubinden.   

Beta-Test-Versionen probiere ich natürlich gerne mal aus; schlimmer kann das Pairing-Problem ja nicht werden.

[Beta-User]

zu b) würde ich ja gerne korrigieren, aber ohne Zugriff auf die Definition des Devices wüsste ich nicht wie

Das mit dem IODev war/ist nur so ein "Bauchgefühl", weil es ein paar weitere Meldungen (mit ganz anderen Modulfamilien) gab, die in diese Richtung gehen.

Was du versuchen könntest: Alle potentiellen IO-Devices, die für MAX in Frage kommen (insbes.: Falls da ein CUL (für HM, SlowRF, egal!) im Spiel ist), sollten in der "richtigen Reihenfolge" in der cfg aufgelistet sein, nämlich das effektiv zu nutzende als letztes von den genannten (aber vermutlich noch vor den Client-Geräten!).
Kann sein, dass das hilft, aber wie gesagt: ist nur so ein diffuses Gefühl...

Vorher würde ich aber die Beta-Versionen versuchen .

[Uef]

OK, das mit der Reihenfolge der Geräte schaue ich mir an. Wer weiß ...

Wo kann ich mir denn die Beta-Versionen herunterladen ?
Sind das die aus diesem Thread: https://forum.fhem.de/index.php/topic,115018.0.html  ?

[Beta-User]

Der Link sollte passen, und da Wzut (soviel ich mitbekommen habe) den IO-Unterbau da gehörig renoviert hat, macht es vermutlich auch keinen großen Sinn, in der cfg rumzueditieren (=Vermeindung einer potentiellen Gefahrenquelle)...

[Wzut]

define Keller_Tuer MAX ShutterContact 054e32
Ergebnis: "MAX_Define, a MAX device with address 054e32 is already defined as " (die Zeile ist so komplett, d.h. sie endet hinter dem 'as')
Das passt also zum Fehler mit dem leeren Namen.

Bleibt wieder die Frage, wie ich die Definition des Devices finden soll.

Das finden ist relativ einfach : FHEM neu starten
Hintergrund 
Das Device wurde nicht angelegt, daher auch kein Name und kein Eintrag in der fhem.cfg , aaaaber es  belegt einen Eintrag unter $modules{MAX}{defptr} und solange der da ist kann kein Device mit dieser Adresse neu angelegt werden. Nach einem FHEM Neustart ist daher das Problem beseitigt.

@Wzut: Checkst du die "Beta-Test"-Versionen eigentlich irgendwann ein? (Oder ist das schon passiert).

Ich selbst nutze nur noch die Beta Module, leider gibt es aber ein paar User die massive Probleme mit ihnen haben und es konnte nie geklärt werden warum und wieso
Da ich keine Lust habe das ganz große Chaos zu veranstalten belasse ich es einfach bei den schlechten Versionen im svn und wer es besser haben will nimmt als bewusste Entscheidung die Betas.

[Beta-User]

Da ich keine Lust habe das ganz große Chaos zu veranstalten belasse ich es einfach bei den schlechten Versionen im svn und wer es besser haben will nimmt als bewusste Entscheidung die Betas.

Kann ich einerseits verstehen, andererseits: In der Regel (!) scheinen die Beta-Versionen besser zu laufen. Falls also jemand künftig noch in MAX einsteigt, wäre es eigentlich besser, das direkt mit den "neuen" Versionen zu machen. Wer Problem hat und auf dem bisherigen Stand verbleiben will, kann ja die Module vom Update ausnehmen, Änderungen wird es ja eh' keine mehr geben. Wer "versehentlich" updated, kann die alten Fassungen ja notfalls auch per "Svn_GetFile()" geziehlt aus dem svn holen (jedenfalls unter Linux), das müßte man dann halt nur irgendwo kurz näher beschreiben, wie das geht...

Aber klar: Mußt du wissen .

PS: es waren da noch ein paar andere patches zu anderen Modulen in der Pipeline, ohne dass bisher dazu eine Rückmeldung gekommen wäre?

[Uef]

So, sorry für die späte Antwort; ein paar andere Dinge hatten kurzfristig höhere Priorität.

@Wzut: das define direkt nach einem Neustart hat 1a funktioniert !!! 
Das Device konnte ich direkt im Anschluss verwenden. Danach konnte man es auch problemlos löschen und per define wieder anlegen (ohne Neustart)
Der Test erfolgte noch mit den "alten" Original-Modulen. Die Betas werde ich bei Gelegenheit testen.

Den gesamten Zyklus aus "Device löschen" und via "Neu-Pairen" automatisch erzeugen zu lassen, habe ich mangels Zeit noch nicht getestet.
Ich habe aber noch eine Sensore in der Bastelkiste, das ergibt sich also sicher noch mal.

Ganz vielen Dank für Eure Hilfe !!
Uwe