diff --git a/fhem/FHEM/98_apptime.pm b/fhem/FHEM/98_apptime.pm index dc81d2f7c..cb1c85401 100644 --- a/fhem/FHEM/98_apptime.pm +++ b/fhem/FHEM/98_apptime.pm @@ -15,8 +15,10 @@ use vars qw(%intAt); use vars qw($nextat); sub apptime_Initialize($); - +my $apptimeStatus; sub apptime_Initialize($){ + $apptimeStatus = 1;#set active by default + $cmds{"apptime"}{Fn} = "apptime_CommandDispTiming"; $cmds{"apptime"}{Hlp} = "[clear|] [top|all] [],application function calls and duration"; } @@ -80,37 +82,42 @@ sub CallFn(@) { sub apptime_getTiming($$$@) { my ($e,$fnName,$fn,$tim,@arg) = @_; my $h; - if (!$defs{$e}{helper} || - !$defs{$e}{helper}{bm} || - !$defs{$e}{helper}{bm}{$fnName} ){ - - %{$defs{$e}{helper}{bm}{$fnName}} =(max =>0, mAr =>"", - cnt =>1, tot =>0, - dmx =>0); - - $h = $defs{$e}{helper}{bm}{$fnName}; - } - else{ - $h = $defs{$e}{helper}{bm}{$fnName}; - $h->{cnt}++; - } - my $ts1 = gettimeofday(); - if ($tim){ - my $td = int(($ts1-$tim)*1000); - $h->{dmx} = $td if ($h->{dmx} < $td); + my $ts1; + if ($apptimeStatus){ + if (!$defs{$e}{helper} || + !$defs{$e}{helper}{bm} || + !$defs{$e}{helper}{bm}{$fnName} ){ + + %{$defs{$e}{helper}{bm}{$fnName}} =(max =>0, mAr =>"", + cnt =>1, tot =>0, + dmx =>0); + + $h = $defs{$e}{helper}{bm}{$fnName}; + } + else{ + $h = $defs{$e}{helper}{bm}{$fnName}; + $h->{cnt}++; + } + $ts1 = gettimeofday(); + if ($tim){ + my $td = int(($ts1-$tim)*1000); + $h->{dmx} = $td if ($h->{dmx} < $td); + } } no strict "refs"; my @ret = &{$fn}(@arg); use strict "refs"; - $ts1 = int((gettimeofday()-$ts1)*1000); - if ($ts1 && $h->{max}<$ts1){ - $h->{max}=$ts1; - $h->{mAr}= \@arg; + if ($apptimeStatus){ + $ts1 = int((gettimeofday()-$ts1)*1000); + if ($ts1 && $h->{max} < $ts1){ + $h->{max} = $ts1; + $h->{mAr} = \@arg; + } + + $h->{tot} += $ts1; } - - $h->{tot}+=$ts1; return @ret; } @@ -120,51 +127,63 @@ sub apptime_CommandDispTiming($$@) { my ($sFld,$top,$filter) = split" ",$param; $sFld = "max" if (!$sFld); $top = "top" if (!$top); - my %fld = (name=>0,funktion=>1,max=>2,count=>3,total=>4,average=>5,maxDly=>6,clear=>99); + my %fld = (name=>0,funktion=>1,max=>2,count=>3,total=>4,average=>5,maxDly=>6,cont=>98,pause=>98,clear=>99); return "$sFld undefined field, use one of ".join(",",keys %fld) if(!defined $fld{$sFld}); my @bmArr; my @a = map{"$defs{$_}:$_"} keys (%defs); # prepare mapping hash 2 name $_ =~ s/[HASH\(\)]//g foreach(@a); + + if ($sFld eq "pause"){# no further collection of data, clear also + $apptimeStatus = 0;#stop collecting data + } + elsif ($sFld eq "cont"){# no further collection of data, clear also + $apptimeStatus = 1;#continue collecting data + } + foreach my $d (sort keys %defs) { next if(!$defs{$d}{helper}||!$defs{$d}{helper}{bm}); if ($sFld eq "clear"){ delete $defs{$d}{helper}{bm}; - next; } - foreach my $f (sort keys %{$defs{$d}{helper}{bm}}) { - next if(!defined $defs{$d}{helper}{bm}{$f}{cnt}); - next if($filter && $d !~ m/$filter/ && $f !~ m/$filter/); - my ($n,$t) = ($d,$f); - ($n,$t) = split(";",$f,2) if ($d eq "global"); - $t = "" if (!defined $t); - my $h = $defs{$d}{helper}{bm}{$f}; - - my $arg = ""; - if ($h->{mAr} && scalar(@{$h->{mAr}})){ - foreach my $i (0..scalar(@{$h->{mAr}})){ - if(ref(${$h->{mAr}}[$i]) eq 'HASH' and exists(${$h->{mAr}}[$i]->{NAME})){ - ${$h->{mAr}}[$i] = "HASH(".${$h->{mAr}}[$i]->{NAME}.")"; + elsif ($sFld =~ m/(pause|cont)/){ + } + else{ + foreach my $f (sort keys %{$defs{$d}{helper}{bm}}) { + next if(!defined $defs{$d}{helper}{bm}{$f}{cnt}); + next if($filter && $d !~ m/$filter/ && $f !~ m/$filter/); + my ($n,$t) = ($d,$f); + ($n,$t) = split(";",$f,2) if ($d eq "global"); + $t = "" if (!defined $t); + my $h = $defs{$d}{helper}{bm}{$f}; + + my $arg = ""; + if ($h->{mAr} && scalar(@{$h->{mAr}})){ + foreach my $i (0..scalar(@{$h->{mAr}})){ + if(ref(${$h->{mAr}}[$i]) eq 'HASH' and exists(${$h->{mAr}}[$i]->{NAME})){ + ${$h->{mAr}}[$i] = "HASH(".${$h->{mAr}}[$i]->{NAME}.")"; + } } + $arg = join ("; ",@{$h->{mAr}}); } - $arg = join ("; ",@{$h->{mAr}}); + + push @bmArr,[($n,$t + ,$h->{max} + ,$h->{cnt} + ,$h->{tot} + ,$h->{tot} /$h->{cnt} + ,$h->{dmx} + ,$arg + )]; } - - push @bmArr,[($n,$t - ,$h->{max} - ,$h->{cnt} - ,$h->{tot} - ,$h->{tot} /$h->{cnt} - ,$h->{dmx} - ,$arg - )]; } } my $field = $fld{$sFld}; if ($field>1){@bmArr = sort { $b->[$field] <=> $a->[$field] } @bmArr;} else {@bmArr = sort { $b->[$field] cmp $a->[$field] } @bmArr;} - my $ret = sprintf("\n %35s %20s %6s %6s %8s %8s %s", - "name","function","max","count","total","average","maxDly","param Max call"); + my $ret = ($apptimeStatus ? "" : "------ apptime PAUSED data collection ----------\n") + .sprintf("\n %35s %20s %6s %6s %8s %8s %s", + "name","function","max","count","total","average","maxDly","param Max call"); my $end = ($top && $top eq "top")?20:@bmArr-1; $end = @bmArr-1 if ($end>@bmArr-1); @@ -176,63 +195,129 @@ sub apptime_CommandDispTiming($$@) { =pod =item command =item summary support to analyse function performance -=item summary_DE unterstuetzung der analyse der Performance von Funktionen +=item summary_DE Unterstützung bei der Performanceanalyse von Funktionen =begin html

apptime

- +
+

apptime

+

+ apptime provides information about application procedure execution time. + It is designed to identify long running jobs causing latency as well as + general high CPU usage jobs. +

+

+ No information about FHEM kernel times and delays will be provided. +

+

+ Once started, apptime monitors tasks. User may reset counter during operation. + apptime adds about 1% CPU load in average to FHEM. +

+

+ In order to remove apptime, shutdown restart is necessary. +

+

+ Features +

+
+
apptime
+
+

+ apptime is started with the its first call and continously monitor operations.
+ To unload apptime, shutdown restart is necessary.
+

+
+
apptime clear
+
+

+ Reset all counter and start from zero. +

+
+
apptime pause
+
+

+ Suspend accumulation of data. Data is not cleared. +

+
+
apptime cont
+
+

+ Continue data collection after pause. +

+
+
apptime [count|funktion|average|clear|max|name|total] [all]
+
+

+ Display a table sorted by the field selected. +

+

+ all will display the complete table while by default only the top lines are printed.< +

+
+
+

+ Columns: +

+
+
name
+
+

+ Name of the entity executing the procedure. +

+

+ If it is a function called by InternalTimer the name starts with tmr-. + By then it gives the name of the function to be called. +

+
+
funktion
+
+

+ Procedure name which was executed. +

+

+ If it is an InternalTimer call it gives its calling parameter. +

+
+
max
+
+

+ Longest duration measured for this procedure in ms. +

+
+
count
+
+

+ Number of calls for this procedure. +

+ +
total
+
+

+ Accumulated duration of this procedure over all calls monitored. +

+
+
average
+
+

+ Average time a call of this procedure takes. +

+
+
maxDly
+
+

+ Maximum delay of a timer call to its schedules time. + This column is not relevant for non-timer calls. +

+
+
param Max call
+
+

+ Gives the parameter of the call with the longest duration. +

+
+
+
=end html =cut