search

RFD-FHEM / RFFHEM

Counterpart of SIGNALDuino, it's the code for FHEM to work with the data received from the uC
GNU General Public License v3.0
44 stars 33 forks source link

Sendmsg causes stacktrace for LED_XM21_0 #1185

Open sidey79 opened 10 months ago

sidey79 commented 10 months ago

Expected Behavior

No error with undefined value

Actual Behavior


2023.08.29 19:26:26 3: sduino: wz.WBaum set off
2023.08.29 19:26:26 1:     main::CallFn                        called by fhem.pl (784)
2023.08.29 19:26:26 1:     main::FW_Read                       called by fhem.pl (3980)
2023.08.29 19:26:26 1:     main::FW_answerCall                 called by ./FHEM/01_FHEMWEB.pm (609)
2023.08.29 19:26:26 1:     main::FW_fC                         called by ./FHEM/01_FHEMWEB.pm (980)
2023.08.29 19:26:26 1:     main::AnalyzeCommand                called by ./FHEM/01_FHEMWEB.pm (2858)
2023.08.29 19:26:26 1:     main::CommandSet                    called by fhem.pl (1278)
2023.08.29 19:26:26 1:     main::DoSet                         called by fhem.pl (1998)
2023.08.29 19:26:26 1:     main::CallFn                        called by fhem.pl (1966)
2023.08.29 19:26:26 1:     main::SD_UT_Set                     called by fhem.pl (3975)
2023.08.29 19:26:26 1:     main::IOWrite                       called by ./FHEM/14_SD_UT.pm (1444)
2023.08.29 19:26:26 1:     main::SIGNALduino_Write             called by fhem.pl (1066)
2023.08.29 19:26:26 1:     main::SIGNALduino_Set               called by ./FHEM/00_SIGNALduino.pm (1650)
2023.08.29 19:26:26 1:     main::SIGNALduino_Set_sendMsg       called by ./FHEM/00_SIGNALduino.pm (656)
2023.08.29 19:26:26 1:     main::__ANON__                      called by ./FHEM/00_SIGNALduino.pm (933)
2023.08.29 19:26:26 1: stacktrace:
2023.08.29 19:26:26 1: PERL WARNING: Use of uninitialized value within %signalHash in concatenation (.) or string at ./FHEM/00_SIGNALduino.pm line 933.
2023.08.29 19:26:26 1:     main::CallFn                        called by fhem.pl (784)
2023.08.29 19:26:26 1:     main::FW_Read                       called by fhem.pl (3980)
2023.08.29 19:26:26 1:     main::FW_answerCall                 called by ./FHEM/01_FHEMWEB.pm (609)
2023.08.29 19:26:26 1:     main::FW_fC                         called by ./FHEM/01_FHEMWEB.pm (980)
2023.08.29 19:26:26 1:     main::AnalyzeCommand                called by ./FHEM/01_FHEMWEB.pm (2858)
2023.08.29 19:26:26 1:     main::CommandSet                    called by fhem.pl (1278)
2023.08.29 19:26:26 1:     main::DoSet                         called by fhem.pl (1998)
2023.08.29 19:26:26 1:     main::CallFn                        called by fhem.pl (1966)
2023.08.29 19:26:26 1:     main::SD_UT_Set                     called by fhem.pl (3975)
2023.08.29 19:26:26 1:     main::IOWrite                       called by ./FHEM/14_SD_UT.pm (1444)
2023.08.29 19:26:26 1:     main::SIGNALduino_Write             called by fhem.pl (1066)
2023.08.29 19:26:26 1:     main::SIGNALduino_Set               called by ./FHEM/00_SIGNALduino.pm (1650)
2023.08.29 19:26:26 1:     main::SIGNALduino_Set_sendMsg       called by ./FHEM/00_SIGNALduino.pm (656)
2023.08.29 19:26:26 1:     main::__ANON__                      called by ./FHEM/00_SIGNALduino.pm (933)
2023.08.29 19:26:26 1: stacktrace:
2023.08.29 19:26:26 1: PERL WARNING: Use of uninitialized value within %signalHash in concatenation (.) or string at ./FHEM/00_SIGNALduino.pm line 933.

Steps to Reproduce the Problem

  1. Define following Device:
  2. define wz.WBaum SD_UT LED_XM21_0 FFFFFFFFFFFFFF
attr wz.WBaum IODev sduino
attr wz.WBaum alexaName weihnachtsbaum
attr wz.WBaum group Licht
attr wz.WBaum model LED_XM21_0
attr wz.WBaum repeats 9
attr wz.WBaum room Wohnzimmer
#   DEF        LED_XM21_0 FFFFFFFFFFFFFF
#   FUUID      5c4cb3d9-f33f-f610-a3df-844d9cac4439b4d3
#   IODev      sduino
#   NAME       wz.WBaum
#   NR         515
#   STATE      off
#   TYPE       SD_UT
#   bitMSG     no data
#   eventCount 2
#   lastMSG    no data
#   versionModule 2022-09-13
#   READINGS:
#     2023-08-29 12:27:23   IODev           sduino
#     2023-08-29 19:26:26   LastAction      send
#     2023-08-29 19:26:26   state           off
#
setstate wz.WBaum off
setstate wz.WBaum 2023-08-29 12:27:23 IODev sduino
setstate wz.WBaum 2023-08-29 19:26:26 LastAction send
setstate wz.WBaum 2023-08-29 19:26:26 state off
    1. send off command
    2. look into logfile

Specifications

sidey79 commented 10 months ago

@elektron-bbs

Kommt das eventuell auch bei anderen Geräten vor?

HomeAutoUser commented 10 months ago

@sidey79, ich für mich kann nur sagen, mir fiel es bisher nicht auf. Ich werde mal genauer auf den Systemen darauf acht geben.

elektron-bbs commented 10 months ago

Das ist mir bisher auch nicht aufgefallen. Allerdings ist das auch nicht der normale Weg, wie das Device angelegt wird. Ich habe probehalber nur das Gerät, ohne die div. Attribute angelegt:

define wz.WBaum SD_UT LED_XM21_0 FFFFFFFFFFFFFF

Dann bekomme ich beim ersten set-Befehl auch diese Warnung:

2023.08.29 20:44:53 1: PERL WARNING: Use of uninitialized value within %signalHash in concatenation (.) or string at ./FHEM/00_SIGNALduino.pm line 939.

HomeAutoUser commented 6 months ago

Ich habe nun ein Device mit define wz.WBaum SD_UT LED_XM21_0 FFFFFFFFFFFFFF erstellt und anschließend sofort gesendet. Dabei generiert das Device keine Meldung im Logfile.

2024.01.02 20:06:46.060 3: sduino_nano_433Mhz: CheckCcpatableResponse, patable: 84
2024.01.02 20:10:08.671 3: sduino_nano_433Mhz: wz.WBaum set on

list vom Device

Internals:
   CFGFN      
   DEF        LED_XM21_0 FFFFFFFFFFFFFF
   FUUID      65945f8a-f33f-33fd-6551-ba213a04a5c5d579
   FVERSION   14_SD_UT.pm:v1.0.2-s0/2023-12-19
   IODev      [sduino_nano_433Mhz](http://192.168.2.20:8083/fhem?detail=sduino_nano_433Mhz)
   NAME       [wz.WBaum](http://192.168.2.20:8083/fhem?detail=wz.WBaum)
   NR         830
   STATE      on
   TYPE       SD_UT
   bitMSG     no data
   eventCount 1
   lastMSG    no data
   versionModule 2023-12-19
   READINGS:
     2024-01-02 20:10:02   IODev           [sduino_nano_433Mhz](http://192.168.2.20:8083/fhem?detail=sduino_nano_433Mhz)
     2024-01-02 20:10:08   LastAction      send
     2024-01-02 20:10:08   state           on
Attributes:
   model      LED_XM21_0

Das gleiche habe ich noch einmal getestet nachdem ich unmittelbar nach dem Definieren ein IO-Dev via Attribut festlegte. Dies führte auch zu keiner Warnung.

2024.01.02 20:13:35.164 3: SD_UT_Attr set IODev to sduino_nano_433Mhz
2024.01.02 20:13:43.211 3: sduino_nano_433Mhz: wz.WBaum set on

Ob somit das Problem noch aktiv ist bei Euch, bitte nochmal testen. Vielleicht ist das ISSUES erledigt.

sidey79 commented 6 months ago

Gerade bei noch mal getestet. Wird leider immer noch generiert

sidey79 commented 6 months ago 

define wz.WBaum SD_UT LED_XM21_0 FFFFFFFFFFFFFF
attr wz.WBaum IODev sduino
attr wz.WBaum alexaName weihnachtsbaum
attr wz.WBaum group Licht
attr wz.WBaum model LED_XM21_0
attr wz.WBaum repeats 9
attr wz.WBaum room Wohnzimmer
#   DEF        LED_XM21_0 FFFFFFFFFFFFFF
#   FUUID      5c4cb3d9-f33f-f610-a3df-844d9cac4439b4d3
#   IODev      sduino
#   LASTInputDev sduino
#   MSGCNT     230
#   NAME       wz.WBaum
#   NR         515
#   STATE      on
#   TYPE       SD_UT
#   bitMSG     111111111111111111111111111111111111111111111111111111111100
#   eventCount 399
#   lastMSG    FFFFFFFFFFFFFFC
#   sduino_DMSG P76#FFFFFFFFFFFFFFC
#   sduino_MSGCNT 258
#   sduino_Protocol_ID 76
#   sduino_RAWMSG MU;P0=-6976;P1=435;P2=-182;P3=128;D=01212121232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232121212123232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323232323212121;CP=3;O;
#   sduino_TIME 2023-12-31 01:11:30
#   versionModule 2023-07-19
#   .attraggr:
#   .attrminint:
#   READINGS:
#     2023-12-09 18:32:42   IODev           sduino
#     2024-01-02 20:49:17   LastAction      send
#     2023-12-31 01:11:30   deviceCode      11111111111111111111111111111111111111111111111111111111
#     2024-01-02 20:49:17   state           on
#
setstate wz.WBaum on
setstate wz.WBaum 2023-12-09 18:32:42 IODev sduino
setstate wz.WBaum 2024-01-02 20:49:17 LastAction send
setstate wz.WBaum 2023-12-31 01:11:30 deviceCode 11111111111111111111111111111111111111111111111111111111
setstate wz.WBaum 2024-01-02 20:49:17 state on
elektron-bbs commented 6 months ago

Ich habe es eben auch nochmal probiert, diesmal kommt die Warnung beim 2. Sendebefehl:

2024.01.02 21:15:20 4: sduinoUSB0: SD_UT_Set attr_model=LED_XM21_0 name=wz.WBaum (before check)
2024.01.02 21:15:20 4: sduinoUSB0: SD_UT_Set attr_model=LED_XM21_0 msg=P76#11111111111111111111111111111111111111111111111111111111 msgEnd=#R5
2024.01.02 21:15:20 5: sduinoUSB0: SD_UT_Set attr_model=LED_XM21_0 msg=P76#1111111111111111111111111111111111111111111111111111111111111111#R5 cmd=on value=on (cmd loop)
2024.01.02 21:15:20 3: sduinoUSB0: wz.WBaum set on
2024.01.02 21:15:20 4: sduinoUSB0: wz.WBaum SD_UT_Set sendMsg P76#1111111111111111111111111111111111111111111111111111111111111111#R5
2024.01.02 21:15:20 5: sduinoESP8266: SD_UT_Parse devicedef=LED_XM21_0 FFFFFFFFFFFFFF attr_model=LED_XM21_0 protocol=76 state=unknown (before check)
2024.01.02 21:15:20 5: sduinoESP8266: SD_UT_Parse devicedef=LED_XM21_0 FFFFFFFFFFFFFF attr_model=LED_XM21_0 protocol=76 devicecode=11111111111111111111111111111111111111111111111111111111 state=11111111
2024.01.02 21:15:20 5: sduinoESP8266: SD_UT_Parse devicedef=LED_XM21_0 FFFFFFFFFFFFFF attr_model=LED_XM21_0 typ=remote (after check)
2024.01.02 21:15:20 5: sduinoESP8266: SD_UT_Parse devicedef=LED_XM21_0 FFFFFFFFFFFFFF attr_model=LED_XM21_0 typ=remote key=on (state loop)

2024.01.02 21:20:14 4: sduinoUSB0: SD_UT_Set attr_model=LED_XM21_0 name=wz.WBaum (before check)
2024.01.02 21:20:14 4: sduinoUSB0: SD_UT_Set attr_model=LED_XM21_0 msg=P76#11111111111111111111111111111111111111111111111111111111 msgEnd=#R5
2024.01.02 21:20:14 5: sduinoUSB0: SD_UT_Set attr_model=LED_XM21_0 msg=P76#111111111111111111111111111111111111111111111111111111111100#R5 cmd=off value=off (cmd loop)
2024.01.02 21:20:14 1: PERL WARNING: Use of uninitialized value within %signalHash in concatenation (.) or string at ./FHEM/00_SIGNALduino.pm line 940.
2024.01.02 21:20:14 3: sduinoUSB0: wz.WBaum set off
2024.01.02 21:20:14 4: sduinoUSB0: wz.WBaum SD_UT_Set sendMsg P76#111111111111111111111111111111111111111111111111111111111100#R5
2024.01.02 21:20:15 5: sduinoESP8266_1: SD_UT_Parse devicedef=LED_XM21_0 FFFFFFFFFFFFFF attr_model=LED_XM21_0 protocol=76 state=unknown (before check)
2024.01.02 21:20:15 5: sduinoESP8266_1: SD_UT_Parse devicedef=LED_XM21_0 FFFFFFFFFFFFFF attr_model=LED_XM21_0 protocol=76 devicecode=11111111111111111111111111111111111111111111111111111111 state=1100
2024.01.02 21:20:15 5: sduinoESP8266_1: SD_UT_Parse devicedef=LED_XM21_0 FFFFFFFFFFFFFF attr_model=LED_XM21_0 typ=remote (after check)
2024.01.02 21:20:15 5: sduinoESP8266_1: SD_UT_Parse devicedef=LED_XM21_0 FFFFFFFFFFFFFF attr_model=LED_XM21_0 typ=remote key=off (state loop)

Allerdings ist die Fehlermeldung wieder mal irreführend. In Zeile 940 wird kein %signalHash verwendet. Die Logausgabe erfolgt allerdings auch nicht:

940: $hash->{logMethod}->($hash->{NAME}, 4, "$hash->{NAME}: Set_sendMsg, sending : $sendData");

EDIT: Die Logausgabe konnte auch nicht erfolgen, da $hash ja vom IODev ist und den SIGNALduino hatte ich nicht auf verbose 4.

HomeAutoUser commented 6 months ago

Soeben habe ich es 3x reproduzieren können nachdem ich FHEM neu startete mit anschließendem Define define wz.WBaum SD_UT LED_XM21_0 FFFFFFFFFFFFFF

2024.01.02 21:43:48.653 3: signalESP_Easy_MR_2_433Mhz: wz.WBaum set on
2024.01.02 21:43:51.349 1: PERL WARNING: Use of uninitialized value within %signalHash in concatenation (.) or string at ./FHEM/00_SIGNALduino.pm line 934.
2024.01.02 21:43:51.349 1: stacktrace:
2024.01.02 21:43:51.349 1:     main::__ANON__                      called by ./FHEM/00_SIGNALduino.pm (934)
2024.01.02 21:43:51.350 1:     main::SIGNALduino_Set_sendMsg       called by ./FHEM/00_SIGNALduino.pm (657)
2024.01.02 21:43:51.350 1:     main::SIGNALduino_Set               called by ./FHEM/00_SIGNALduino.pm (1651)
2024.01.02 21:43:51.350 1:     main::SIGNALduino_Write             called by fhem.pl (1070)
2024.01.02 21:43:51.350 1:     main::IOWrite                       called by ./FHEM/14_SD_UT.pm (1539)
2024.01.02 21:43:51.350 1:     main::SD_UT_Set                     called by fhem.pl (3980)
2024.01.02 21:43:51.350 1:     main::CallFn                        called by fhem.pl (1970)
2024.01.02 21:43:51.350 1:     main::DoSet                         called by fhem.pl (2002)
2024.01.02 21:43:51.351 1:     main::CommandSet                    called by fhem.pl (1282)
2024.01.02 21:43:51.351 1:     main::AnalyzeCommand                called by ./FHEM/01_FHEMWEB.pm (2861)
2024.01.02 21:43:51.351 1:     main::FW_fC                         called by ./FHEM/01_FHEMWEB.pm (1025)
2024.01.02 21:43:51.351 1:     main::FW_answerCall                 called by ./FHEM/01_FHEMWEB.pm (609)
2024.01.02 21:43:51.351 1:     main::FW_Read                       called by fhem.pl (3985)
2024.01.02 21:43:51.351 1:     main::CallFn                        called by fhem.pl (786)
2024.01.02 21:43:51.352 1: PERL WARNING: Use of uninitialized value within %signalHash in concatenation (.) or string at ./FHEM/00_SIGNALduino.pm line 934.
2024.01.02 21:43:51.352 1: stacktrace:
2024.01.02 21:43:51.352 1:     main::__ANON__                      called by ./FHEM/00_SIGNALduino.pm (934)
2024.01.02 21:43:51.352 1:     main::SIGNALduino_Set_sendMsg       called by ./FHEM/00_SIGNALduino.pm (657)
2024.01.02 21:43:51.352 1:     main::SIGNALduino_Set               called by ./FHEM/00_SIGNALduino.pm (1651)
2024.01.02 21:43:51.352 1:     main::SIGNALduino_Write             called by fhem.pl (1070)
2024.01.02 21:43:51.353 1:     main::IOWrite                       called by ./FHEM/14_SD_UT.pm (1539)
2024.01.02 21:43:51.353 1:     main::SD_UT_Set                     called by fhem.pl (3980)
2024.01.02 21:43:51.353 1:     main::CallFn                        called by fhem.pl (1970)
2024.01.02 21:43:51.353 1:     main::DoSet                         called by fhem.pl (2002)
2024.01.02 21:43:51.353 1:     main::CommandSet                    called by fhem.pl (1282)
2024.01.02 21:43:51.353 1:     main::AnalyzeCommand                called by ./FHEM/01_FHEMWEB.pm (2861)
2024.01.02 21:43:51.353 1:     main::FW_fC                         called by ./FHEM/01_FHEMWEB.pm (1025)
2024.01.02 21:43:51.354 1:     main::FW_answerCall                 called by ./FHEM/01_FHEMWEB.pm (609)
2024.01.02 21:43:51.354 1:     main::FW_Read                       called by fhem.pl (3985)
2024.01.02 21:43:51.354 1:     main::CallFn                        called by fhem.pl (786)
2024.01.02 21:43:51.354 3: signalESP_Easy_MR_2_433Mhz: wz.WBaum set off

Zeile: $SignalData.=$signalHash{$bitconv{$bit}}; ## Add the signal to our data string in der 00_SIGNALduino.pm

Das Modul ruft IOWrite($hash, 'sendMsg', $msg); auf mit dem Ergebnis der Warnung.

sidey79 commented 6 months ago

Zeile: $SignalData.=$signalHash{$bitconv{$bit}}; ## Add the signal to our data string in der 00_SIGNALduino.pm

Das liegt meiner Meinung nach daran, dass die bitmsg = "111111111111111111111111111111111111111111111111111111111100" ist und mit zwei mal 0 endet.

Zero / 0 ist aber im Protokoll nicht definiert und in besagter Zeile bzw. davor prüfen wir nicht, ob es in signalHash einen Wert für das gesuchte "Bit" gibt.

HomeAutoUser commented 6 months ago

Wo sollten wir da ansetzen bzw. überarbeiten?

Zero / 0 ist aber im Protokoll nicht definiert (Protokolldefinition) oder besagter Zeile bzw. davor prüfen wir nicht, ob es in signalHash einen Wert für das gesuchte "Bit" gibt. (00_SIGNALduino.pm)

sidey79 commented 6 months ago

00_SIGNALduino.pm)

Da wir uns aktuell darauf verlassen, dass wir eine Nachricht bekommen, die der Protokolldefinition entspricht, aber das ist warum auch immer nicht der Fall.