Perl Warning in notify

Joker · 06 März 2017, 22:50:41

Hi,
seit FHEM 5.8 bekomme ich folgende Warnings im Log:

2017.03.06 19:07:44 3: Kinderzimmer.Fenster closed
2017.03.06 19:07:44 1: PERL WARNING: Use of uninitialized value $VALUE in pattern match (m//) at (eval 254785) line 1.
2017.03.06 19:07:44 3: eval: my $EVTPART0='closed';my $EVENT='closed';my $TYPE='CUL_HM';my $NAME='Kinderzimmer.Fenster';my $SELF='onWindowClose';{winOpenStop($NAME)}
2017.03.06 19:07:45 1: PERL WARNING: Use of uninitialized value $VALUE in pattern match (m//) at (eval 254791) line 1.
2017.03.06 19:07:45 3: eval: my $EVTPART0='closed';my $EVENT='closed';my $TYPE='CUL_HM';my $NAME='Kinderzimmer.Fenster';my $SELF='onWindowClose';{winOpenStop($NAME)}

Im Prinzip immer wenn ein Homematic Fensterkontakt einen Status meldet. Ich verstehe, dass da eine nicht initialisierte Variable namens $VALUE sein soll. Aber ich steh auf dem Schlauch- wo muss ich da jetzt suchen? Im notify "onWindowClose"? Das ist so definiert:

Code Auswählen

Internals: 
   .COMMAND   {winOpenStop($NAME)} 
   CFGFN      /opt/fhem/FHEM/intelligence.cfg 
   DEF        .*:closed {winOpenStop($NAME)} 
   NAME       onWindowClose 
   NR         784 
   NTFY_ORDER 50-onWindowClose 
   REGEXP     .*:closed 
   STATE      active 
   TYPE       notify 
   Readings: 
     2017-03-06 21:03:57   state           active 
Attributes:

Oder in der Funktion "winOpenStop"? Da finde ich aber keine Variable die nicht initialisiert ist...?

KernSani · 06 März 2017, 22:59:04

wie sieht denn winOpenStop($) aus?

Joker · 06 März 2017, 23:03:55

So:

Code Auswählen

sub winOpenStop($) 
{
	my ($dev) = @_;
      
    # check if the given device exists. Filter out the 'WindowRec' event for the thermostats
    if ($defs{$dev} and $dev !~ 'WindowRec') 
    {
		blinds_onWindowClosed($dev);
	
		# and consider only devs for which notifications shall be sent
    	my $maxtrigger = AttrVal($dev, 'winOpenMaxTrigger', 0);
		
		if($maxtrigger)
		{
			Log(3, "$dev closed");

			checkKitchenExhaustHoodConditions($dev);
			stopWindowTimer($dev);
			stopWindowLiveTimer($dev);
		}
    }
}

Liegt es evtl. an dem

Code Auswählen

$dev !~ 'WindowRec' ?

Bin mir nicht mehr ganz sicher warum ich das gebraucht habe...

KernSani · 06 März 2017, 23:22:15

Zitat von: Joker am 06 März 2017, 23:03:55
Liegt es evtl. an dem
Code Auswählen Erweitern
$dev !~ 'WindowRec' ?

Die Warnung würde darauf hinweisen, dass $dev undef ist, was aber ganz offensichtlich nicht zutrifft... Kannst du mal stacktrace einschalten und die Warnung reproduzieren?

Joker · 06 März 2017, 23:28:14

Ah ok... stacktrace kannte ich noch gar nicht, aber hier ist er (schon wieder was gelernt

)

Code Auswählen

2017.03.06 23:24:59 3: Arbeitszimmer.Fenster closed
2017.03.06 23:24:59 1: PERL WARNING: Use of uninitialized value $VALUE in pattern match (m//) at (eval 22197) line 1.
2017.03.06 23:24:59 3: eval: my $EVENT='closed';my $TYPE='CUL_HM';my $EVTPART0='closed';my $NAME='Arbeitszimmer.Fenster';my $SELF='onWindowClose';{winOpenStop($NAME)}
2017.03.06 23:24:59 1: stacktrace:
2017.03.06 23:24:59 1:     main::__ANON__                      called by (eval 22197) (1)
2017.03.06 23:24:59 1:     (eval)                              called by ./FHEM/33_readingsProxy.pm (128)
2017.03.06 23:24:59 1:     main::readingsProxy_update          called by ./FHEM/33_readingsProxy.pm (84)
2017.03.06 23:24:59 1:     main::readingsProxy_updateDevices   called by ./FHEM/33_readingsProxy.pm (185)
2017.03.06 23:24:59 1:     main::readingsProxy_Notify          called by fhem.pl (3312)
2017.03.06 23:24:59 1:     main::CallFn                        called by fhem.pl (3233)
2017.03.06 23:24:59 1:     main::DoTrigger                     called by fhem.pl (2004)
2017.03.06 23:24:59 1:     main::CommandDelete                 called by fhem.pl (1108)
2017.03.06 23:24:59 1:     main::AnalyzeCommand                called by fhem.pl (977)
2017.03.06 23:24:59 1:     main::AnalyzeCommandChain           called by fhem.pl (3352)
2017.03.06 23:24:59 1:     main::fhem                          called by ./FHEM/99_myUtilsWindows.pm (156)
2017.03.06 23:24:59 1:     main::stopWindowTimer               called by ./FHEM/99_myUtilsWindows.pm (61)
2017.03.06 23:24:59 1:     main::winOpenStop                   called by (eval 22193) (1)
2017.03.06 23:24:59 1:     (eval)                              called by fhem.pl (1029)
2017.03.06 23:24:59 1:     main::AnalyzePerlCommand            called by fhem.pl (1049)
2017.03.06 23:24:59 1:     main::AnalyzeCommand                called by fhem.pl (977)
2017.03.06 23:24:59 1:     main::AnalyzeCommandChain           called by ./FHEM/91_notify.pm (102)
2017.03.06 23:24:59 1:     main::notify_Exec                   called by fhem.pl (3312)
2017.03.06 23:24:59 1:     main::CallFn                        called by fhem.pl (3233)
2017.03.06 23:24:59 1:     main::DoTrigger                     called by fhem.pl (3589)
2017.03.06 23:24:59 1:     main::Dispatch                      called by ./FHEM/00_HMUARTLGW.pm (1357)
2017.03.06 23:24:59 1:     main::HMUARTLGW_Parse               called by ./FHEM/00_HMUARTLGW.pm (1459)
2017.03.06 23:24:59 1:     main::HMUARTLGW_Read                called by fhem.pl (3312)
2017.03.06 23:24:59 1:     main::CallFn                        called by fhem.pl (675)
2017.03.06 23:24:59 1: PERL WARNING: Use of uninitialized value $VALUE in pattern match (m//) at (eval 22203) line 1.
2017.03.06 23:24:59 3: eval: my $EVENT='closed';my $TYPE='CUL_HM';my $EVTPART0='closed';my $NAME='Arbeitszimmer.Fenster';my $SELF='onWindowClose';{winOpenStop($NAME)}
2017.03.06 23:24:59 1: stacktrace:
2017.03.06 23:24:59 1:     main::__ANON__                      called by (eval 22203) (1)
2017.03.06 23:24:59 1:     (eval)                              called by ./FHEM/33_readingsProxy.pm (128)
2017.03.06 23:24:59 1:     main::readingsProxy_update          called by ./FHEM/33_readingsProxy.pm (84)
2017.03.06 23:24:59 1:     main::readingsProxy_updateDevices   called by ./FHEM/33_readingsProxy.pm (185)
2017.03.06 23:24:59 1:     main::readingsProxy_Notify          called by fhem.pl (3312)
2017.03.06 23:24:59 1:     main::CallFn                        called by fhem.pl (3233)
2017.03.06 23:24:59 1:     main::DoTrigger                     called by fhem.pl (2004)
2017.03.06 23:24:59 1:     main::CommandDelete                 called by fhem.pl (1108)
2017.03.06 23:24:59 1:     main::AnalyzeCommand                called by fhem.pl (977)
2017.03.06 23:24:59 1:     main::AnalyzeCommandChain           called by fhem.pl (3352)
2017.03.06 23:24:59 1:     main::fhem                          called by ./FHEM/99_myUtilsWindows.pm (201)
2017.03.06 23:24:59 1:     main::stopWindowLiveTimer           called by ./FHEM/99_myUtilsWindows.pm (62)
2017.03.06 23:24:59 1:     main::winOpenStop                   called by (eval 22193) (1)
2017.03.06 23:24:59 1:     (eval)                              called by fhem.pl (1029)
2017.03.06 23:24:59 1:     main::AnalyzePerlCommand            called by fhem.pl (1049)
2017.03.06 23:24:59 1:     main::AnalyzeCommand                called by fhem.pl (977)
2017.03.06 23:24:59 1:     main::AnalyzeCommandChain           called by ./FHEM/91_notify.pm (102)
2017.03.06 23:24:59 1:     main::notify_Exec                   called by fhem.pl (3312)
2017.03.06 23:24:59 1:     main::CallFn                        called by fhem.pl (3233)
2017.03.06 23:24:59 1:     main::DoTrigger                     called by fhem.pl (3589)
2017.03.06 23:24:59 1:     main::Dispatch                      called by ./FHEM/00_HMUARTLGW.pm (1357)
2017.03.06 23:24:59 1:     main::HMUARTLGW_Parse               called by ./FHEM/00_HMUARTLGW.pm (1459)
2017.03.06 23:24:59 1:     main::HMUARTLGW_Read                called by fhem.pl (3312)
2017.03.06 23:24:59 1:     main::CallFn                        called by fhem.pl (675)

Ich werd nicht so recht schlau draus..? Heißt das es hat was mit Readingsproxy zu tun?

KernSani · 06 März 2017, 23:39:13

Zitat von: Joker am 06 März 2017, 23:28:14
Ich werd nicht so recht schlau draus..? Heißt das es hat was mit Readingsproxy zu tun?

sieht so aus... Hast du denn da noch einen readingsproxy rumhängen? (Mit dem kenne ich mich aber garnicht aus)

Joker · 06 März 2017, 23:46:25

Hm... ich hab schon ReadingsProxys... aber eigentlich keinen der in Verbindung mit den Fenstern steht... komisch.
Aber ich werde da morgen mal nachforschen, danke für deine Hilfe soweit- ich melde mich wieder

justme1968 · 07 März 2017, 00:03:01

der fehler kommt aus der valueFn einer deiner redingsProxys.

die valueFn wird in diesem fall durch ein global:DELETED event für ein device das auf die device liste des readingsProxy matched.

kann es sein das du in deinem notify irgend ein device löschst? vielleicht ein temporäres at?

falls ja: schau mal ob der device name des at auf die eine regex im DEF eines readingsProxy passt. falls ja mach die regex genauer, ändere den namen des at oder verwendet statt des at ein benanntes sleep.

falls nein: habe ich gerade keine idee. versuch an hand der beschreibung oben mehr rauszufinden...

Joker · 07 März 2017, 00:10:46

Ja, jetzt hats mir doch keine Ruhe gelassen...
Also ich habe folgenden Readingsproxy:

Code Auswählen

Internals: 
   DEF        HM:ERR_battery 
   DEVICE     HM 
   NAME       proxy_battery_error 
   NOTIFYDEV  HM,global 
   NR         1060 
   NTFY_ORDER 50-proxy_battery_error 
   READING    ERR_battery 
   STATE      false 
   TYPE       readingsProxy 
   Content: 
     HM         1 
   Readings: 
     2017-03-07 00:03:08   state           false 
Attributes: 
   DbLogExclude .* 
   setList    true false 
   valueFn    { return 'true' if($VALUE =~ /low/);; return 'false';; }

Der ist dazu gedacht dass ich da drin stehen habe ob gerade ein Gerät mit Batteriestatus low existiert.
Ich verstehe jetzt aber noch nicht wirklich, warum der triggert...? Es wird ein temporäres at in dem notify gelöscht, ja. Das heißt aber sowas wie "Kinderzimmer.Fenster_OpenTimer"... wieso führt es zur Triggerung?
Auf jeden Fall ist das der Grund für die Warning, wenn ich die ValueFn so ändere:

Code Auswählen

{ return 'true' if($VALUE && ($VALUE =~ /low/));; return 'false';; }
Dann ist die Warning erstmal weg...

justme1968 · 07 März 2017, 00:14:09

readingsProxy (und readingsGroup und readingsHistory) reagieren auf global:DELETED um mit zu bekommen ob ein device für das sie zuständig sind gelöscht wurde. das gleiche gilt für das umbenennen.

eigentlich sollte alles weitere intern aber nur aufgerufen werden wenn das device auch matched.

Joker · 07 März 2017, 21:52:15

Hm. Also ich habe das gerade noch mal nachvollzogen. Der "at", der gelöscht wird, wenn das Fenster geschlossen wird, sieht folgendermaßen aus:

Code Auswählen

Internals: 
   CFGFN 
   COMMAND    {sendNotification('Arbeitszimmerfenster ist noch offen!', 'Fenster Warnung');startWindowTimer('Arbeitszimmer.Fenster','1');} 
   DEF        2017-03-07T22:02:21 {sendNotification('Arbeitszimmerfenster ist noch offen!', 'Fenster Warnung');startWindowTimer('Arbeitszimmer.Fenster','1');} 
   NAME       Arbeitszimmer.Fenster_OpenTimer 
   NR         3674 
   NTM        22:02:21 
   PERIODIC   no 
   RELATIVE   yes 
   STATE      Next: 22:02:21 
   TIMESPEC   00:15:00 
   TRIGGERTIME 1488920541.75828 
   TRIGGERTIME_FMT 2017-03-07 22:02:21 
   TYPE       at 
   VOLATILE   1 
   Readings: 
     2017-03-07 21:47:21   state           Next: 22:02:21 
Attributes: 
   DbLogExclude .* 
   room       System

Und folgende ReadingsProxys werden davon aus irgendeinem Grund getriggert:

Code Auswählen



Internals: 
   DEF        dummy_waste_Papier:state 
   DEVICE     dummy_waste_Papier 
   NAME       proxy_waste_paper_yellow 
   NOTIFYDEV  global,dummy_waste_Papier 
   NR         1057 
   NTFY_ORDER 50-proxy_waste_paper_yellow 
   READING    state 
   STATE      none 
   TYPE       readingsProxy 
   Content: 
     dummy_waste_Papier 1 
   Readings: 
     2017-03-07 21:48:38   state           none 
Attributes: 
   DbLogExclude .* 
   setFn      { return undef;; } 
   setList    today tomorrow none 
   valueFn    { return 'today' if( $VALUE eq 'Heute' );; return 'tomorrow' if( $VALUE eq 'Morgen' );; return 'none';; }

Code Auswählen

Internals: 
   DEF        dummy_waste_Restmuell:state 
   DEVICE     dummy_waste_Restmuell 
   NAME       proxy_waste_residual_bio 
   NOTIFYDEV  dummy_waste_Restmuell,global 
   NR         1056 
   NTFY_ORDER 50-proxy_waste_residual_bio 
   READING    state 
   STATE      none 
   TYPE       readingsProxy 
   Content: 
     dummy_waste_Restmuell 1 
   Readings: 
     2017-03-07 21:48:38   state           none 
Attributes: 
   DbLogExclude .* 
   setFn      { return undef;; } 
   setList    today tomorrow none 
   valueFn    { return 'today' if( $VALUE eq 'Heute' );; return 'tomorrow' if( $VALUE eq 'Morgen' );; return 'none';; }

Code Auswählen

Internals: 
   DEF        HM:ERR_battery 
   DEVICE     HM 
   NAME       proxy_battery_error 
   NOTIFYDEV  HM,global 
   NR         1060 
   NTFY_ORDER 50-proxy_battery_error 
   READING    ERR_battery 
   STATE      false 
   TYPE       readingsProxy 
   Content: 
     HM         1 
   Readings: 
     2017-03-07 21:48:38   state           false 
Attributes: 
   DbLogExclude .* 
   setList    true false 
   valueFn    { return 'true' if($VALUE && ($VALUE =~ /low/));; return 'false';; }

Irgendeine Idee woran das liegen könnte? Wie man sieht ist das state Reading von allen drei Proxies 21:48:38, das ist genau die Zeit wo ich das Fenster geschlossen habe- hier noch das List vom Fensterkontakt:

Code Auswählen

Internals: 
   CFGFN      /opt/fhem/FHEM/arbeitszimmer.cfg 
   DEF        35AD34 
   HMLAN1_MSGCNT 67 
   HMLAN1_RAWMSG E35AD34,0000,9127ADAA,FF,FFB6,44A64135AD3426ED1201EA00 
   HMLAN1_RSSI -74 
   HMLAN1_TIME 2017-03-07 21:48:38 
   HMUART1_MSGCNT 67 
   HMUART1_RAWMSG 0500003144A64135AD3426ED1201EA00 
   HMUART1_RSSI -49 
   HMUART1_TIME 2017-03-07 21:48:38 
   IODev      HMLAN1 
   LASTInputDev HMUART1 
   MSGCNT     134 
   NAME       Arbeitszimmer.Fenster 
   NOTIFYDEV  global 
   NR         484 
   NTFY_ORDER 50-Arbeitszimmer.Fenster 
   STATE      closed 
   TYPE       CUL_HM 
   lastMsg    No:44 - t:41 s:35AD34 d:26ED12 01EA00 
   peerList   Arbeitszimmer.Wandthermostat.WindowRec, 
   protLastRcv 2017-03-07 21:48:38 
   protSnd    54 last_at:2017-03-07 21:48:38 
   protState  CMDs_done 
   rssi_at_HMLAN1 max:-67 cnt:67 lst:-74 avg:-74.49 min:-81 
   rssi_at_HMUART1 cnt:67 max:-39 min:-66 avg:-44.58 lst:-49 
   Readings: 
     2016-09-24 07:49:59   .D-devInfo      810101 
     2016-09-24 07:49:59   .D-stc          80 
     2016-09-23 22:27:57   .R-msgScPosA    open 
     2016-09-23 22:27:57   .R-msgScPosB    closed 
     2016-09-23 22:27:57   .R-transmDevTryMax 6 
     2016-09-23 22:27:57   .R-transmitTryMax 6 
     2016-10-10 01:11:19   .peerListRDate  2016-10-10 01:11:19 
     2017-03-07 21:48:38   .protLastRcv    2017-03-07 21:48:38 
     2017-03-06 21:04:01   Activity        alive 
     2016-09-24 07:49:28   CommandAccepted no 
     2016-09-24 07:49:59   D-firmware      1.0 
     2016-09-24 07:49:59   D-serialNr      LEQ1469169 
     2016-10-10 01:11:18   PairedTo        0x26ED12 
     2016-09-23 22:28:00   R-Arbeitszimmer.Wandthermostat.WindowRec-expectAES off 
     2016-09-23 22:28:00   R-Arbeitszimmer.Wandthermostat.WindowRec-peerNeedsBurst on 
     2016-09-23 22:27:57   R-cyclicInfoMsg on 
     2016-09-23 22:27:57   R-eventDlyTime  3 s 
     2016-09-23 22:27:57   R-pairCentral   0x26ED12 
     2016-09-23 22:27:57   R-sabotageMsg   on 
     2016-09-23 22:27:57   R-sign          on 
     2016-10-10 01:11:18   RegL_00.        02:01 09:01 0A:26 0B:ED 0C:12 10:01 14:06 00:00 
     2016-10-10 01:11:19   RegL_01.        08:01 20:9C 21:03 30:06 00:00 
     2016-10-10 01:11:20   RegL_04.Arbeitszimmer.Wandthermostat.WindowRec 01:01 00:00 
     2017-03-07 21:15:41   alive           yes 
     2017-03-07 21:48:38   battery         ok 
     2017-03-07 21:48:38   contact         closed (to VCCU) 
     2017-03-07 21:48:38   duration_live   0 
     2017-03-06 21:04:01   peerList        Arbeitszimmer.Wandthermostat.WindowRec, 
     2016-09-24 07:48:38   powerOn         2016-09-24 07:48:38 
     2017-03-07 21:15:41   recentStateType info 
     2017-03-07 21:15:41   sabotageError   off 
     2017-03-07 21:48:38   state           closed 
     2017-03-07 21:48:38   trigger_cnt     234 
   Helper: 
     HM_CMDNR   68 
     mId        00C7 
     rxType     28 
     supp_Pair_Rep 0 
     Ack: 
     Expert: 
       def        1 
       det        0 
       raw        1 
       tpl        0 
     Io: 
       newChn     +35AD34,00,00,00 
       nextSend   1488919718.70518 
       rxt        2 
       vccu       VCCU 
       p: 
         35AD34 
         00 
         00 
         00 
     Mrssi: 
       mNo        44 
       Io: 
         HMLAN1     -72 
         HMUART1    -49 
     Prt: 
       bErr       0 
       sProc      0 
       sleeping   0 
       Rspwait: 
     Q: 
       qReqConf 
       qReqStat 
     Role: 
       chn        1 
       dev        1 
     Rpt: 
       IO         HMLAN1 
       flg        A 
       ts         1488919718.36943 
       ack: 
         HASH(0x4003580) 
         44800226ED1235AD340101C800 
     Rssi: 
       At_hmlan1: 
         avg        -74.4925373134328 
         cnt        67 
         lst        -74 
         max        -67 
         min        -81 
       At_hmuart1: 
         avg        -44.5820895522388 
         cnt        67 
         lst        -49 
         max        -39 
         min        -66 
     Shadowreg: 
     Tmpl: 
Attributes: 
   DbLogExclude duration_live 
   IODev      HMLAN1 
   IOgrp      VCCU 
   actCycle   001:05 
   actStatus  alive 
   autoReadReg 4_reqStatus 
   event-on-change-reading .* 
   expert     2_full 
   firmware   1.0 
   model      HM-SEC-SCo 
   peerIDs    00000000,34B06003, 
   room       System 
   serialNr   LEQ1469169 
   subType    threeStateSensor 
   userattr   winOpenMaxTrigger winOpenTimer winOpenTimer2 winOpenType:Fenster,Tür winOpenName 
   winOpenMaxTrigger 5 
   winOpenName Arbeitszimmerfenster 
   winOpenTimer 00:15:00 
   winOpenTimer2 00:20:00 
   winOpenType Fenster