98_freezemon.pm: New feature: freeze statistics, counts occurences an cumulates time of freezes for devices that probably cause a freeze.

git-svn-id: https://svn.fhem.de/fhem/trunk@18364 2b470e98-0d58-463d-a4d8-8e2adae1ed80

fhem/FHEM/98_freezemon.pm

@@ -22,6 +22,11 @@
 #
 ##############################################################################
 # 	  Changelog:
+#		0.0.25:	Further improved statistics function and clear statistics
+#		0.0.24:	Optimized statistics function
+#				Added clear statistics command
+#		0.0.23:	Fixed few minor bugs
+#				Added experimental statistics function
 #		0.0.22: Fixed a weird bug when CatchFnCalls was enabled
 #		0.0.21: Added direct help for set, get and attr commands
 #		0.0.20: Internal changes
@@ -91,6 +96,7 @@ use strict;
 use warnings;
 
 #use Data::Dumper;
+
 use POSIX;
 use Time::HiRes qw(gettimeofday);
 use Time::HiRes qw(tv_interval);
@@ -98,7 +104,7 @@ use B qw(svref_2object);
 use Blocking;
 use vars qw($FW_CSRF);
 
-my $version = "0.0.22";
+my $version = "0.0.25";
 
 my @logqueue = ();
 my @fmCmd    = ();
@@ -115,7 +121,7 @@ sub freezemon_Initialize($) {
     # Module specific attributes
     my @freezemon_attr =
       (
-"fm_forceApptime:0,1 fm_freezeThreshold disable:0,1 fm_log fm_ignoreDev fm_ignoreMode:off,single,all fm_extDetail:0,1 fm_logExtraSeconds fm_logFile fm_logKeep fm_whitelistSub fm_CatchFnCalls:0,1,2,3,4,5 fm_CatchCmds:0,1,2,3,4,5"
+"fm_forceApptime:0,1 fm_freezeThreshold disable:0,1 fm_log fm_ignoreDev fm_ignoreMode:off,single,all fm_extDetail:0,1 fm_logExtraSeconds fm_logFile fm_logKeep fm_whitelistSub fm_CatchFnCalls:0,1,2,3,4,5 fm_CatchCmds:0,1,2,3,4,5 fm_statistics:0,1 fm_statistics_low"
       );
 
     $hash->{GetFn}             = "freezemon_Get";
@@ -264,6 +270,8 @@ sub freezemon_ProcessTimer($) {
         my $found     = 0;
         my $start     = strftime( "%H:%M:%S", localtime( $hash->{helper}{TIMER} ) );
         my $end       = strftime( "%H:%M:%S", localtime($now) );
+        my @rlist;
+
         $freeze = int( $freeze * 1000 ) / 1000;
 
         #Build a hash of devices to ignore
@@ -285,6 +293,7 @@ sub freezemon_ProcessTimer($) {
                 next;
             }
             $dev .= "cmd-" . @$entry[0] . "(" . @$entry[1] . ") ";
+            push @rlist, @$entry[1];
         }
 
         #Functions
@@ -300,6 +309,7 @@ sub freezemon_ProcessTimer($) {
                 next;
             }
             $dev .= "fn-" . @$entry[0] . "(" . @$entry[1] . ") ";
+            push @rlist, @$entry[1];
         }
 
         #get the timers that were executed in last cycle
@@ -319,6 +329,7 @@ sub freezemon_ProcessTimer($) {
                     next;
                 }
                 $dev .= "tmr-" . $d->{FN} . "(" . $devname . ") ";
+                push @rlist, $devname;
 
             }
         }
@@ -330,10 +341,10 @@ sub freezemon_ProcessTimer($) {
 
             my %nd = map { $_ => 1 } @newdev;
             foreach my $d (@olddev) {
-                if (!exists( $nd{$d} ) ) {
+                if ( !exists( $nd{$d} ) ) {
 
                     my @a = split( ":", $d );
-                    if ( exists( $id{ $a[1] } ) ) 	{
+                    if ( exists( $id{ $a[1] } ) ) {
                         $idevFlag = $a[1];
                     }
                     else {
@@ -344,6 +355,7 @@ sub freezemon_ProcessTimer($) {
                         next;
                     }
                     $dev .= "prio-" . $a[0] . "(" . $a[1] . ") ";
+                    push @rlist, $a[1];
                 }
             }
         }
@@ -445,6 +457,28 @@ sub freezemon_ProcessTimer($) {
             readingsBulkUpdate( $hash, "fcDay",       $fcDay );
             readingsBulkUpdate( $hash, "ftDay",       $ftDay );
             readingsBulkUpdate( $hash, "freezeDevice", $dev );
+
+            #update statistics
+            if ( AttrVal( $name, "fm_statistics", 0 ) == 1 ) {
+
+                #some substitution
+                s/(_\d{1,3}\.\d{1,3}\.\d{1,3}\.\d{1,3}.*)// for @rlist;
+
+                #make unique
+                my %hash = map { $_, 1 } @rlist;
+                my @unique = keys %hash;
+                foreach my $r (@unique) {
+                    next if $r eq "";
+
+                    my $rname  = makeReadingName( "fs_" . $r . "_c" );
+                    my $rtname = makeReadingName( "fs_" . $r . "_t" );
+                    my $rval   = ReadingsNum( $name, $rname, 0 ) + 1;
+                    readingsBulkUpdate( $hash, $rname, $rval );
+                    my $rtime = ReadingsNum( $name, $rtname, 0 ) + $freeze;
+                    readingsBulkUpdate( $hash, $rtname, $rtime );
+                }
+
+            }
             readingsEndUpdate( $hash, 1 );
         }
         else {
@@ -543,10 +577,11 @@ sub freezemon_ProcessTimer($) {
 ###################################
 sub freezemon_Set($@) {
     my ( $hash, $name, $cmd, @args ) = @_;
-    my $usage = "Unknown argument $cmd, choose one of active:noArg inactive:noArg clear:noArg";
+    my $usage =
+      "Unknown argument $cmd, choose one of active:noArg inactive:noArg clear:statistics_all,statistics_low,all";
 
     return "\"set $name\" needs at least one argument" unless ( defined($cmd) );
-    Log3 $name, 5, "$name Coming with command $cmd";
+
     if ( $cmd eq "inactive" ) {
         RemoveInternalTimer($hash);
         readingsSingleUpdate( $hash, "state", "inactive", 1 );
@@ -562,22 +597,43 @@ sub freezemon_Set($@) {
         }
     }
     elsif ( $cmd eq "clear" ) {
-        readingsBeginUpdate($hash);
+        if ( $args[0] eq "all" ) {
-        readingsBulkUpdate( $hash, "fcDayLast",   0,  1 );
+            readingsBeginUpdate($hash);
-        readingsBulkUpdate( $hash, "ftDayLast",   0,  1 );
+            readingsBulkUpdate( $hash, "fcDayLast",   0,  1 );
-        readingsBulkUpdate( $hash, "fcDay",       0,  1 );
+            readingsBulkUpdate( $hash, "ftDayLast",   0,  1 );
-        readingsBulkUpdate( $hash, "ftDay",       0,  1 );
+            readingsBulkUpdate( $hash, "fcDay",       0,  1 );
-        readingsBulkUpdate( $hash, ".lastDay",    "", 1 );
+            readingsBulkUpdate( $hash, "ftDay",       0,  1 );
-        readingsBulkUpdate( $hash, ".fm_freezes", "", 1 );
+            readingsBulkUpdate( $hash, ".lastDay",    "", 1 );
-        if ( !IsDisabled($name) ) {
+            readingsBulkUpdate( $hash, ".fm_freezes", "", 1 );
-            readingsBulkUpdate( $hash, "state", "initialized", 1 );
+            if ( !IsDisabled($name) ) {
+                readingsBulkUpdate( $hash, "state", "initialized", 1 );
+            }
+            readingsBulkUpdate( $hash, "freezeTime",   0,  1 );
+            readingsBulkUpdate( $hash, "freezeDevice", "", 1 );
+            readingsEndUpdate( $hash, 1 );
+        }
+        elsif ( $args[0] eq "statistics_all" ) {
+            CommandDeleteReading( undef, "$name fs_.*" );
+        }
+        elsif ( $args[0] eq "statistics_low" ) {
+            my ( $lowc, $lowt ) = split( ":", AttrVal( $name, "fm_statistics_low", "0:0" ) );
+            foreach my $r ( keys %{ $hash->{READINGS} } ) {
+                next unless ( $r =~ /fs_.*_c/ );
+                my $rc = ReadingsNum( $name, $r, 0 );
+                my $t  = $r =~ s/_c/_t/r;
+                my $rt = ReadingsNum( $name, $t, 0 );
+                if ( $rc <= $lowc && $rt <= $lowt ) {
+                    Log3 $name, 4, "[Freezemon] $name: Deleting readings $r, $t: $rc < $lowc && $rt < $lowt";
+                    CommandDeleteReading( undef, "$name " . $r );
+                    CommandDeleteReading( undef, "$name " . $t );
+                }
+            }
+        }
+        else {
+            return "unknown argument $args[0]";
         }
-        readingsBulkUpdate( $hash, "freezeTime",   0,  1 );
-        readingsBulkUpdate( $hash, "freezeDevice", "", 1 );
-        readingsEndUpdate( $hash, 1 );
     }
     else {
-        Log3 $name, 5, "$name leaving with $usage";
         return $usage;
     }
     return undef;
@@ -592,7 +648,6 @@ sub freezemon_Get($@) {
     my $usage = 'Unknown argument $a[1], choose one of freeze:noArg log:';
 
     return "\"get $name\" needs at least one argument" unless ( defined( $a[1] ) );
-    Log3 $name, 5, "$name GET Coming with command $a[1]";
 
     #get the logfiles
     my @fl = freezemon_getLogFiles($name);
@@ -656,7 +711,7 @@ sub freezemon_Get($@) {
 
     # return usage hint
     else {
-        Log3 $name, 5, "GET $name leaving with $usage";
+
         return $usage;
     }
     return undef;
@@ -714,7 +769,6 @@ sub freezemon_Attr($) {
                 freezemon_install_callFn_wrapper($hash);
                 $fmFnLog = $aVal;
                 $fmName  = $name;
-                $fmFnLog = AttrVal( $name, "fm_CatchFnCalls", 0 );
 
             }
             elsif ( defined( $hash->{helper}{mycallFn} ) ) {
@@ -735,7 +789,6 @@ sub freezemon_Attr($) {
                 freezemon_install_AnalyzeCommand_wrapper($hash);
                 $fmCmdLog = $aVal;
                 $fmName   = $name;
-                $fmCmdLog = AttrVal( $name, "fm_CatchCmds", 0 );
             }
             elsif ( defined( $hash->{helper}{AnalyzeCommand} ) ) {
                 Log3( "", 0, "[Freezemon] $name: Unwrapping AnalyzeCommand" );
@@ -760,6 +813,20 @@ sub freezemon_Attr($) {
             elsif ( $aVal == 0 ) {
                 freezemon_start($hash);
             }
+            elsif ( $aName eq "fm_statistics" ) {
+                if ( $aVal == 1 ) {
+                    $hash->{helper}{statistics} = 1;
+                }
+                elsif ( $aVal == 0 ) {
+                    $hash->{helper}{statistics} = 0;
+                }
+            }
+
+        }
+        elsif ( $aName eq "fm_statistics_low" ) {
+            if ( !( $aVal =~ /\d+\:\d+/ ) ) {
+                return "Attribute " . $aName . " has to be in the format 1:2 (meaning count 1:seconds 2)";
+            }
 
         }
     }
@@ -789,6 +856,9 @@ sub freezemon_Attr($) {
                 $hash->{helper}{AnalyzeCommand} = undef;
             }
         }
+        elsif ( $aName eq "fm_statistics" ) {
+            $hash->{helper}{statistics} = 0;
+        }
 
     }
 
@@ -1006,7 +1076,7 @@ sub freezemon_AnalyzeCommand($$$;$) {
         $d = $cl->{SNAME};
     }
     else {
-        $d = "Command";
+        $d = "N/A";
     }
 
     if ( $ms >= 0.5 ) {
@@ -1323,7 +1393,11 @@ sub freezemon_getLogPath($) {
 	<ul>
 		<li><a name="inactive">inactive</a>: disables the device (similar to attribute "disable", however without the need to save</li>
 		<li><a name="active">active</a>: reactivates the device after it was set inactive</li>
-		<li><a name="clear">clear</a>: clears all readings (including the list of the last 20 freezes.)</li>
+		<li><a name="clear">clear</a>: 
+			<ul><li>statistics_all: clears the statistics (i.e. deletes all the readings created for statistics)</li>
+			<li>statistics_low: clears the statistics with low significance (see attribute fm_statistics_low)</li>
+			<li>all: clears all readings (including the list of the last 20 freezes.)</li>
+			</ul></li>
 	</ul>
   </ul>	
 <a name="freezemonGet"></a>
@@ -1345,7 +1419,10 @@ sub freezemon_getLogPath($) {
 				<li>ftDay: cumulated duration of freezes per day</li>
 				<li>fcDayLast: stores cumulated no. of freezes of the last day (for daily plots)</li>
 				<li>fcDayLast: stores cumulated duration of freezes of the last day (for daily plots)</li>
+				<li>fs_.*_c: freeze statistics - count of freezes where the device was probably involved</li>
+				<li>fs_.*_t: freeze statistics - cumulated time of freezes where the device was probably involved</li>
 				<li>state: s:&lt;startTime&gt; e:&lt;endTime&gt; f:&lt;Duration&gt; d:&lt;Devices&gt;</li>;
+				
 			</ul>
 		</ul>
 
@@ -1370,7 +1447,11 @@ sub freezemon_getLogPath($) {
 				<li><a name="fm_logFile">fm_logFile</a>: takes a valid file name (like e.g. ./log/freeze-%Y%m%d-%H%M%S.log). If set, logs messages of loglevel 5 (even if global loglevel is < 5) before a freeze in separate file.</li>
 				<li><a name="fm_logExtraSeconds">fm_logExtraSeconds</a>: obsolete attribute, not used anymore and should be deleted.</li>
 				<li><a name="fm_logKeep">fm_logKeep</a>: A number that defines how many logFiles should be kept. If set all logfiles except the latest n freezemon logfiles will be deleted regularly.</li>
+				<li><a name="fm_statistics">fm_statistics</a>: EXPERIMENTAL! Creates a reading for each device probably causing a freeze and counts how often it probably caused a freeze. </li>
 				<li><a name="fm_whitelistSub">fm_whitelistSub</a>: Comma-separated list of subroutines that you're sure that don't cause a freeze. Whitelisted Subs do not appear in the  "possibly caused by" list. Typically you would list subroutines here that frequently appear in the "possibly caused by" list, but you're really sure they are NOT the issue. Note: The subroutine is the initial part (before the devicename in brackets) in freezemon log messages.  </li>
+				<li><a name="fm_statistics">fm_statistics</a>: activate/deactivate freeze statistics. Creates readings for each device that possibly caused a freeze and sums up occurences and duration of those freezes</li>
+				<li><a name="fm_statistics_low">fm_statistics_low</a>: Parametrization of clear statistics_low set command, format is c:t. With clear statistics_low all statistics-readings will be deleted where count is less or equal "c" AND cumulated duration is less or equal "t"</li>
+
 				<li><a name="disable">disable</a>: activate/deactivate freeze detection</li>
 			</ul>
 		</ul>
@@ -1412,7 +1493,11 @@ sub freezemon_getLogPath($) {
 		<ul>
 		<li><a name="inactive">inactive</a>: deaktiviert das Device (identisch zum Attribut "disable", aber ohne die Notwendigkeit su "saven".</li>
 		<li><a name="active">active</a>: reaktiviert das Device nachdem es auf inactive gesetzt wurde</li>
-		<li><a name="clear">clear</a>: Löscht alle readings (inklusive der Liste der letzten 20 Freezes).</li>
+		<li><a name="clear">clear</a>: 
+					<ul><li>statistics_all: löscht die Statistik (d.h. löscht alle readings die für die statistics erzeugt wurden)</li>
+					<li>statistics_low: löscht Statistiken mit geringer Bedeutung (siehe Attribut fm_statistics_low)</li>
+					<li>all: Löscht alle readings (inklusive der Liste der letzten 20 Freezes).</li>
+			</ul></li>
 	</ul>
 
   </ul>	
@@ -1435,6 +1520,9 @@ sub freezemon_getLogPath($) {
 			<li>ftDay: kumulierte Dauer der Freezes pro Tag </li>
 			<li>fcDayLast: speichert die kumulierte Anzahl der Freezes des vergangenen Tages (um tageweise plots zu erstellen)</li>
 			<li>fcDayLast: speichert die kumulierte Dauer der Freezes des vergangenen Tages (um tageweise plots zu erstellen)</li>
+			<li>fs_.*_c: freeze Statistik - Anzahl der freezes bei denen das Device möglicherweise beteiligt war</li>
+			<li>fs_.*_t: freeze Statistik - kumulierte Dauer der freezes bei denen das Device möglicherweise beteiligt war</li>
+
 			<li>state: s:&lt;StartZeit&gt; e:&lt;EndeZeit&gt; f:&lt;Dauer&gt; d:&lt;Devices&gt;</li>
 		</ul>
   </ul>
@@ -1458,7 +1546,10 @@ sub freezemon_getLogPath($) {
 			<li><a name="fm_logFile">fm_logFile</a>: ist ein gültiger Filename (wie z.B. ./log/freeze-%Y%m%d-%H%M%S.log). Wenn gesetzt, werdn Meldungen auf Loglevel 5 (auch wenn global Loglevel < 5 ist) vor einem Freeze in einem seperaten File geloggt.</li>
 			<li><a name="fm_logExtraSeconds">fm_logExtraSeconds</a>: dobsoletes Attribut, wird nicht mehr genutzt und sollte gelöscht werden</li>
 			<li><a name="fm_logKeep">fm_logKeep</a>: Eine Zahl, die angibt wieviele Logfiles behalten werden sollen. Wenn gesetzt, werden alle Logfiles ausser den letzten n Freezemon Logfiles regelmäßig gelöscht.</li>
+			<li><a name="fm_statistics">fm_statistics</a>: EXPERIMENTELL! Erstellt ein reading für jedes Device, das "probably" einen Freeze verursacht hat und zählt, wie oft es möglicherweise an einem Freeze beteiligt war.</li>
 			<li><a name="fm_whitelistSub">fm_whitelistSub</a>: Komma-getrennte Liste von Subroutinen wo du sicher bist, dass sie keinen Freeze verursachen. Whitelisted Subs erscheinen nicht in der "possibly caused by" Liste. Typischerweise listet man hier Subroutinen,  die regelmäßig in der "possibly caused by" Liste auftauchen, wo du aber wirklich sicher bist, dass sie nicht die Ursache sind. Anmerkung: Die Subroutine ist der initiale Teil (vor dem devicename in Klammern) in Freezemon Logmeldungen.</li>
+			<li><a name="fm_statistics">fm_statistics</a>: aktivieren/deaktivieren der Freeze Statistik. Erzeugt Readings für jedes Device, das möglicherweise an einem Freeze beteiligt war und Summiert die Häufigkeit und Dauer dieser Freezes</li>
+			<li><a name="fm_statistics_low">fm_statistics_low</a>: Parametrisierung des clear statistics_low set Kommandos, im Format c:t. Bei clear statistics_low werden alle Statistics-Readings gelöscht deren Count kleiner oder gleich "c" ist UND deren kumulierte Dauer kleiner oder gleich "t" ist</li>
 			<li><a name="disable">disable</a>: aktivieren/deaktivieren der Freeze-Erkennung</li>
 		</ul>
   </ul>