From a7a618ed7d5791391a756d6552f9ffb72b57f8d0 Mon Sep 17 00:00:00 2001 From: tobiasfaust <> Date: Tue, 24 Jun 2014 17:43:33 +0000 Subject: [PATCH] 97_SprinkleControl.pm, 98_Sprinkle.pm: more logging with verbose=5 git-svn-id: https://svn.fhem.de/fhem/trunk/fhem@6159 2b470e98-0d58-463d-a4d8-8e2adae1ed80 --- contrib/97_SprinkleControl.pm | 21 ++++++++++--- contrib/98_Sprinkle.pm | 58 ++++++++++++++++++++++++++--------- 2 files changed, 60 insertions(+), 19 deletions(-) diff --git a/contrib/97_SprinkleControl.pm b/contrib/97_SprinkleControl.pm index fcf8be3a9..fb25a6cf9 100644 --- a/contrib/97_SprinkleControl.pm +++ b/contrib/97_SprinkleControl.pm @@ -176,6 +176,8 @@ sub SprinkleControl_AllocateNewThread($@) { my ($me, $dev, $cmd, $prio) = @_; my $hash = $defs{$me}; + Log3 $hash, 4, "$me: Anforderung Thread allokieren durch '$dev' mit comand '$cmd'"; + return 1 if(IsDisabled($me)); my $threads = ReadingsVal($me, "CountThreads",0); @@ -186,14 +188,19 @@ sub SprinkleControl_AllocateNewThread($@) { $present = 1 if(defined($hash->{helper}{Queue}{$dev})); if($present == 0) { - # noch nciht in der queue vorhanden + # noch nicht in der queue vorhanden + Log3 $hash, 4, "$me: Füge Device '$dev' der Queue hinzu"; $hash->{helper}{Queue}{$dev}{priority} = $prio; $hash->{helper}{Queue}{$dev}{command} = $cmd; - } + } else { + Log3 $hash, 4, "$me: Device '$dev' bereits in der Queue vorhanden"; + } if($present == 0 || ($present == 1 && $hash->{helper}{Queue}{$dev}{active} == 0)) { # schon in der Queue vorhanden aber in Wartestellung + Log3 $hash, 4, "$me: Device '$dev' aktuell in der Queue vorhanden oder in Wartestellung, prüfe auf freien Thread"; if($threads < $max) { + Log3 $hash, 4, "$me: freier Thread vorhanden, gebe Thread frei für Device '$dev' und markiere als 'active'"; $threads += 1; $hash->{helper}{Queue}{$dev}{active} = 1; readingsBeginUpdate($hash); @@ -205,11 +212,13 @@ sub SprinkleControl_AllocateNewThread($@) { } else { # abgelehnt da MAX erreicht, in queue gelegt + Log3 $hash, 4, "$me: kein freier Thread vorhanden, MAXTHREADS wurde erreicht, markiere Device '$dev' in der Queue als 'inactive'"; $hash->{helper}{Queue}{$dev}{active} = 0; return undef ; } } else { # Device ist bereits in der Queue vorhanden + Log3 $hash, 4, "$me: Device '$dev' bereits in der Queue vorhanden, mache nichts"; return undef; } @@ -225,10 +234,13 @@ sub SprinkleControl_DeallocateThread($@) { my ($me, $dev) = @_; my $hash = $defs{$me}; + Log3 $hash, 4, "$me: Anforderung Thread löschen durch '$dev'"; + my $threads = ReadingsVal($me, "CountThreads",0); my $max = $hash->{MaxParallel}; if(defined($hash->{helper}{Queue}{$dev})) { + Log3 $hash, 4, "$me: Device '$dev' in der Queue erkannt und gelöscht. Thread freigegeben"; $threads -= 1; $threads = 0 if($threads<0); delete $hash->{helper}{Queue}{$dev}; @@ -242,12 +254,11 @@ sub SprinkleControl_DeallocateThread($@) { # den nächsten wartenden Thread aus der Queue starten #my %queue = %{$hash->{helper}{Queue}}; my @queue = sort keys %{$hash->{helper}{Queue}}; -#Log3 $hash, 3, "Queue: \n".Dumper(@queue); for(my $i=0; $i < @queue; $i++) { my $d = $queue[$i]; -#Log3 $hash,3, "Device: $d"; + Log3 $hash, 4, "$me: wartendes Device in der Queue erkannt: '$d'"; if($hash->{helper}{Queue}{$d}{active} == 0) { -#Log3 $hash, 3, "DoIt: $d -> ".$hash->{helper}{Queue}{$d}{command}; + Log3 $hash, 4, "$me: Starte wartendes Device, rufe DoIt für Device '$d' mit Command '".$hash->{helper}{Queue}{$d}{command}."'' auf"; Sprinkle_DoIt($defs{$d}, $hash->{helper}{Queue}{$d}{command}); last; } diff --git a/contrib/98_Sprinkle.pm b/contrib/98_Sprinkle.pm index 5e4800a77..8e40dba46 100644 --- a/contrib/98_Sprinkle.pm +++ b/contrib/98_Sprinkle.pm @@ -95,8 +95,8 @@ sub Sprinkle_Define($$) return "Given device not exists: $device" if(!$defs{$device}); return "Given Sensordevice not exists: $sensor" if(defined($sensor) && !$defs{$sensor}); - return "The specified reading of device not exists: $deviceport" if (defined($deviceport) && !defined(ReadingsVal($device, $deviceport, undef))); - return "The specified reading of sensor not exists: $sensorport" if (defined($sensorport) && !defined(ReadingsVal($sensor, $sensorport, undef))); + #return "The specified reading of device not exists: $deviceport" if (defined($deviceport) && !defined(ReadingsVal($device, $deviceport, undef))); + #return "The specified reading of sensor not exists: $sensorport" if (defined($sensorport) && !defined(ReadingsVal($sensor, $sensorport, undef))); return "Wrong timespec, use \"[+]::\"" if(defined($timespec) && $timespec !~ m/^([\+]?)([\d]{2}):([\d]{2}):([\d]{2})$/); @@ -139,10 +139,12 @@ sub Sprinkle_Define($$) ##################################### sub Sprinkle_Undefine($$) { - my ($hash, $arg) = @_; + my ($hash, $arg) = @_; + my $me = $hash->{NAME}; - RemoveInternalTimer($hash); - return undef; + Log3 $hash, 4, "$me: Lösche alle internen Timer"; + RemoveInternalTimer($hash); + return undef; } ################################### @@ -200,7 +202,7 @@ sub Sprinkle_Set($@) #if($cmd ne "tts") { # return "$cmd needs $sets{$cmd} parameter(s)" if(@a-$sets{$cmd} != 0); #} - + Log3 $hash, 4, "$me: Lösche alle internen Timer"; RemoveInternalTimer($hash); if($cmd eq "Disable" && !IsDisabled($me)) { @@ -232,6 +234,7 @@ sub Sprinkle_Set($@) } } + Log3 $hash, 4, "$me: Rufe Funktion DoIt mit Command: $cmd auf"; Sprinkle_DoIt($hash, $cmd); return undef; @@ -246,9 +249,14 @@ sub Sprinkle_Notify($$) { my ($hash, $dev) = @_; my $me = $hash->{NAME}; my $devname = $dev->{NAME}; + + Log3 $hash, 4, "$me: NotifyFn: Statusänderung des überwachten Aktors '$devname' von '".OldValue($devname)."' nach '".Value($devname)."' festgestellt"; + return undef if(IsDisabled($me)); return undef if($hash->{Device} ne $dev->{NAME}); + return undef if(OldValue($devname) eq Value($devname)); + Log3 $hash, 4, "$me: NotifyFn: überwachter Aktor $devname, Statuswechsel von '".OldValue($devname)."' nach '".Value($devname)."'"; my $SprinkleControl = AttrVal($me, "SprinkleControl", undef); my $newState; @@ -256,8 +264,10 @@ sub Sprinkle_Notify($$) { $newState = "Aus" if(lc(ReadingsVal($devname, "state", "")) =~ m/(aus|off)/); if($newState eq "An") { + Log3 $hash, 4, "$me: NotifyFn: Allokiere einen neuen Thread im SprinkleControl: $SprinkleControl" if($SprinkleControl); SprinkleControl_AllocateNewThread($SprinkleControl, $me, "An") if($SprinkleControl); } elsif($newState eq "Aus") { + Log3 $hash, 4, "$me: NotifyFn: Gebe einen Thread frei im SprinkleControl: $SprinkleControl" if($SprinkleControl); SprinkleControl_DeallocateThread($SprinkleControl, $me) if($SprinkleControl); } @@ -265,15 +275,19 @@ sub Sprinkle_Notify($$) { $newState = "Auto(An)" if ($newState eq "An"); $newState = "Auto" if ($newState eq "Aus"); } - + Log3 $hash, 4, "$me: NotifyFn: Setze neuen Status auf: $newState" if($newState); readingsSingleUpdate($hash, "state", $newState, 1) if($newState); return undef; } ################################################ +# Setzt den Internen Timer und startet die +# Hauptprozedur. # -# +# param1: $hash +# param2: DoIt = 1 -> Starte InternalTimer und DoIt +# DoIt = 2 -> Starte nur InternalTimer ############################################### sub Sprinkle_InternalTimerDoIt(@) { my ($hash, $DoIt) = @_; @@ -294,16 +308,19 @@ sub Sprinkle_InternalTimerDoIt(@) { $nt += (($hr*3600)+($min*60)+$sec); # Plus relative time @lt = localtime($nt); - my $ntm = sprintf("%02d:%02d:%02d", $lt[2], $lt[1], $lt[0]); - $hash->{NextTime} = $ntm; + my $ntm = sprintf("%02d.%02d.%04d %02d:%02d:%02d", $lt[3], ($lt[4]+1), ($lt[5]+1900), $lt[2], $lt[1], $lt[0]); + $hash->{TriggerTime_FMT} = $ntm; $hash->{TriggerTime} = $nt; my $DefaultCmd = AttrVal($me, "Sprinkle_DefaultCmd", "Auto"); + + Log3 $hash, 4, "$me: InternalTimerDoIt: Lösche alle internen Timer"; RemoveInternalTimer($hash); Sprinkle_DoIt($hash, $DefaultCmd) if($DoIt == 1); - InternalTimer($nt, "Sprinkle_InternalTimerDoIt", $hash, 0); + Log3 $hash, 4, "$me: InternalTimerDoIt: Setze InternalTimer auf: $ntm"; + InternalTimer($nt, "Sprinkle_InternalTimerDoIt", $hash, 0); } else { - delete $hash->{NextTime}; + delete $hash->{TriggerTime_FMT}; delete $hash->{TriggerTime}; } @@ -319,9 +336,10 @@ sub Sprinkle_InternalTimerDoIt(@) { sub Sprinkle_DoIt($$) { my ($hash, $cmd) = @_; my $me = $hash->{NAME}; + Log3 $hash, 4, "$me: DoIt: Mache etwas, Command: $cmd"; return undef if(IsDisabled($me)); return undef if((lc(ReadingsVal($me, "state", undef)) =~ m/an/) && - (lc($cmd) !~ m/aus/)) ; # Aufruf durch InternalTimer und manuell wurde bereits angeschaltet + (lc($cmd) !~ m/aus/)) ; # Aufruf durch InternalTimer und manuell wurde bereits angeschaltet oder Wartestellung my $SensorTreshold = AttrVal($me, "Sprinkle_SensorThreshold", undef); my $OnTimeSec = AttrVal($me, "Sprinkle_OnTimeSec", undef); @@ -340,6 +358,7 @@ sub Sprinkle_DoIt($$) { } else { $oldState = lc(ReadingsVal($device, "state", undef)); } + Log3 $hash, 4, "$me: DoIt: ermittelter Status des Aktors: $oldState"; return "actual state of given device not accessable, please check definition of $me" if(!$oldState); # Status des Sensors abfragen @@ -353,7 +372,9 @@ sub Sprinkle_DoIt($$) { #Bodenfeuchte ist kein Messwert sondern nur ein on/off Reading $sensorvalue = 0 if(lc($sensorvalue) =~ m/^(on)/); $sensorvalue = 999 if(lc($sensorvalue) =~ m/^(off)/); - } + } + Log3 $hash, 4, "$me: DoIt: ermittelter Wert des Sensors: $sensorvalue"; + return "AutoMode not accessable. Please check your Sprinkle attributes and value of Sensor" if(lc($cmd) eq "auto" && (!defined($OnTimeSec) || $OnTimeSec <= 0 || !defined($sensorvalue) || !defined($SensorTreshold))); @@ -378,9 +399,11 @@ sub Sprinkle_DoIt($$) { if(lc($cmd) eq "an") { $newState = $cmd; if($oldState ne $newState && (($SprinkleControl && SprinkleControl_AllocateNewThread($SprinkleControl, $me, $cmd)) || !$SprinkleControl)) { + Log3 $hash, 4, "$me: DoIt: Schalte Aktor $device auf $OnCmd"; fhem "set $device $OnCmdAdd $OnCmd"; $doit = 1; } elsif($oldState ne $newState) { + Log3 $hash, 4, "$me: Setze Status auf: wait"; $newState = "Wait"; $doit = 2; } @@ -388,23 +411,29 @@ sub Sprinkle_DoIt($$) { } elsif(lc($cmd) eq "aus") { $newState = $cmd; if($oldState ne $newState && (($SprinkleControl && SprinkleControl_DeallocateThread($SprinkleControl, $me)) || !$SprinkleControl)) { + Log3 $hash, 4, "$me: DoIt: Schalte Aktor $device aus"; fhem "set $device off"; $doit = 1; } } elsif(lc($cmd) eq "auto") { if($SensorTreshold >= $sensorvalue) { + Log3 $hash, 4, "$me: DoIt: Im Automodus wurde Schwellwert unterschritten erkannt. Soll: $SensorTreshold , Ist: $sensorvalue"; $newState = "Auto(An)"; if($oldState ne "on" && (($SprinkleControl && SprinkleControl_AllocateNewThread($SprinkleControl, $me, $cmd)) || !$SprinkleControl)) { + Log3 $hash, 4, "$me: DoIt: Schalte im AutoModus Device $device auf $OnCmd"; fhem "set $device $OnCmdAdd $OnCmd"; $doit = 1; } elsif($oldState ne $newState) { + Log3 $hash, 4, "$me: DoIt: Setze im Automodus auf: wait"; $newState = "Wait"; $doit = 2; } } else { + Log3 $hash, 4, "$me: DoIt: Im Automodus wurde Schwellwert noch nicht erreicht. Soll: $SensorTreshold , Ist: $sensorvalue"; $newState = "Auto"; if($oldState ne "off" && (($SprinkleControl && SprinkleControl_DeallocateThread($SprinkleControl, $me)) || !$SprinkleControl)) { + Log3 $hash, 4, "$me: DoIt: Schalte im Automodus Device $device aus"; fhem "set $device off"; $doit = 1; } @@ -412,6 +441,7 @@ sub Sprinkle_DoIt($$) { } readingsSingleUpdate($hash, "state", $newState, 1) if($doit >= 1); + Log3 $hash, 4, "$me: DoIt: Setze neuen Status auf: $newState" if($doit >= 1); return $newState; }