From 2bc3f94753b9f34a6bbc7df6a1595dd4bc4fcfd9 Mon Sep 17 00:00:00 2001 From: StefanStrobel <> Date: Sat, 13 Jan 2018 16:22:34 +0000 Subject: [PATCH] 98_ArduCounter.pm: new features and bug fixes git-svn-id: https://svn.fhem.de/fhem/trunk@15869 2b470e98-0d58-463d-a4d8-8e2adae1ed80 --- fhem/FHEM/98_ArduCounter.pm | 230 +++++++++++++++++++++++------------- 1 file changed, 151 insertions(+), 79 deletions(-) diff --git a/fhem/FHEM/98_ArduCounter.pm b/fhem/FHEM/98_ArduCounter.pm index b63fcd872..07e46ff31 100755 --- a/fhem/FHEM/98_ArduCounter.pm +++ b/fhem/FHEM/98_ArduCounter.pm @@ -45,10 +45,23 @@ # 2017-02-18 fixed a bug that caused a missing open when the device is defined while fhem is already initialized # 2017-05-09 fixed character encoding for documentation text # 2017-09-24 interpolation of lost impulses during fhem restart / arduino reset +# 2017-10-03 bug fix +# 2017-10-06 more optimisations regarding longCount +# 2017-10-08 more little bug fixes (parsing debug messages) +# 2017-10-14 modifications for new sketch version 1.9 +# 2017-11-26 minor modifications of log levels +# 2017-12-02 fixed adding up reject count reading +# 2017-12-27 modified logging levels +# 2018-01-01 little fixes +# 2018-01-02 extend reporting line with history H.*, create new reading pinHistory if received from device and verboseReadings is set to 1 +# create long count readings always, not only if attr verboseReadings is set to 1 +# 2018-01-03 little docu fix +# 2018-01-13 little docu addon # # ideas / todo: -# - +# - parse error messages from sketch and show it in a message box? async output? +# - timeMissed +# package main; @@ -67,7 +80,7 @@ my %ArduCounter_gets = ( "info" => "" ); -my $ArduCounter_Version = '4.8 - 24.9.2017'; +my $ArduCounter_Version = '5.7 - 2.1.2018'; # # FHEM module intitialisation @@ -94,6 +107,7 @@ sub ArduCounter_Initialize($) "readingNameCount[0-9]+ " . "readingNamePower[0-9]+ " . "readingNameLongCount[0-9]+ " . + "readingNameInterpolatedCount[0-9]+ " . "readingFactor[0-9]+ " . "readingStartTime[0-9]+ " . "verboseReadings[0-9]+ " . @@ -135,8 +149,8 @@ sub ArduCounter_Define($$) delete $hash->{Initialized}; if(!defined($attr{$name}{'flashCommand'})) { - #$attr{$name}{'flashCommand'} = 'avrdude -p atmega328P -b 57600 -c arduino -P [PORT] -D -U flash:w:[HEXFILE] 2>[LOGFILE]'; - $attr{$name}{'flashCommand'} = 'avrdude -p atmega328P -c arduino -P [PORT] -D -U flash:w:[HEXFILE] 2>[LOGFILE]'; + #$attr{$name}{'flashCommand'} = 'avrdude -p atmega328P -b 57600 -c arduino -P [PORT] -D -U flash:w:[HEXFILE] 2>[LOGFILE]'; # for nano + $attr{$name}{'flashCommand'} = 'avrdude -p atmega328P -c arduino -P [PORT] -D -U flash:w:[HEXFILE] 2>[LOGFILE]'; # for uno } if ($init_done) { @@ -233,6 +247,7 @@ sub ArduCounter_Write ($$) Log3 $name, 4, "$name: Write called but device is disabled, dropping line to send"; return 0; } + Log3 $name, 4, "$name: Write: $line"; DevIo_SimpleWrite( $hash, "$line\n", 2); return 1; } @@ -550,7 +565,7 @@ sub ArduCounter_HandleVersion($$) my $name = $hash->{NAME}; if ($line =~ / V([\d\.]+)/) { my $version = $1; - if ($version < "1.7") { + if ($version < "1.9") { $version .= " - not compatible with this Module version - please flash new sketch"; Log3 $name, 3, "$name: device reported outdated Arducounter Firmware - please update!"; delete $hash->{Initialized}; @@ -574,23 +589,26 @@ sub ArduCounter_Parse($) my $now = gettimeofday(); foreach my $line (@lines) { - # Log3 $name, 5, "$name: Parse line: $line"; - if ($line =~ 'R([\d]+) C([\d]+) D([\d]+) T([\d]+)( N[\d]+)?( X[\d]+)?( F[\d]+)?(L [\d]+)?( A[\d]+)?') + #Log3 $name, 5, "$name: Parse line: $line"; + if ($line =~ 'R([\d]+) C([\d]+) D([\d]+) R([\d]+) T([\d]+)( N[\d]+)?( X[\d]+)?( F[\d]+)?( L[\d]+)?( A[\d]+)?( H.*)?') { # new count is beeing reported my $pin = $1; my $count = $2; my $diff = $3; - my $time = $4; - my $deTime = ($5 ? substr($5, 2) / 1000 : ""); - my $reject = ($6 ? substr($6, 2) : ""); - my $first = ($7 ? substr($7, 2) : ""); - my $last = ($8 ? substr($8, 2) : ""); - my $avgLen = ($9 ? substr($9, 2) : ""); + my $rDiff = $4; + my $time = $5; + my $deTime = ($6 ? substr($6, 2) / 1000 : ""); + my $reject = ($7 ? substr($7, 2) : ""); + my $first = ($8 ? substr($8, 2) : ""); + my $last = ($9 ? substr($9, 2) : ""); + my $avgLen = ($10 ? substr($10, 2) : ""); + my $hist = ($11 ? substr($11, 2) : ""); my $factor = AttrVal($name, "readingFactor$pin", AttrVal($name, "factor", 1000)); my $rcname = AttrVal($name, "readingNameCount$pin", "pin$pin"); # internal count reading name - my $rlname = AttrVal($name, "readingNameLongCount$pin", "long$pin"); # long count - continues after reset, interpolates + my $rlname = AttrVal($name, "readingNameLongCount$pin", "long$pin"); # long count - continues after reset + my $riname = AttrVal($name, "readingNameInterpolatedCount$pin", "interpolatedLong$pin"); # interpol. count - continues after reset, interpolates my $rpname = AttrVal($name, "readingNamePower$pin", "power$pin"); # power reading name my $lName = AttrVal($name, "readingNamePower$pin", AttrVal($name, "readingNameCount$pin", "pin$pin")); # for logging @@ -608,49 +626,56 @@ sub ArduCounter_Parse($) next; } my $power = sprintf ("%.3f", ($time ? $diff/$time/1000*3600*$factor : 0)); - my $longCount; - - - if (AttrVal($name, "verboseReadings$pin", 0)) { - $longCount = ReadingsVal($name, $rlname, 0); # alter long count Wert im Reading - if (!$hash->{CounterInterpolated}{$pin} && $hash->{CounterResetTime}) { - my $lastCountTime = ReadingsTimestamp ($name, $rlname, 0); # last time this reading was set - my $lastCountTNum = time_str2num($lastCountTime); - my $offlineTime = sprintf ("%.2f", $hash->{CounterResetTime} - $lastCountTNum); - - my $lastInterval = ReadingsVal ($name, "timeDiff$pin", 0); - my $lastCDiff = ReadingsVal ($name, "countDiff$pin", 0); - + my $intrCount = 0; + my $offlTime = 0; + my $longCount = ReadingsVal($name, $rlname, 0); # alter long count Wert im Reading + my $intpCount = ReadingsVal($name, $riname, 0); # alter interpolated count Wert im Reading + if (!$hash->{CounterInterpolated}{$pin} && $hash->{CounterResetTime}) { + # arduino reboot -> try to interpolate + my $lastCountTime = ReadingsTimestamp ($name, $rlname, 0); # last time long count reading was set as string + my $lastCountTNum = time_str2num($lastCountTime); # ... as number + + my $lastInterval = ReadingsVal ($name, "timeDiff$pin", 0); + my $lastCDiff = ReadingsVal ($name, "countDiff$pin", 0); + + Log3 $name, 4, "$name: arduino was restarted so some impulses might have got lost for $pin ($lName)"; + $offlTime = sprintf ("%.2f", $hash->{CounterResetTime} - $lastCountTNum); + if ($lastCountTime && $lastInterval && ($offlTime > 0) && ($offlTime < 1000*60*60*12)) { + # > 0 and < 12h my $lastRatio = $lastCDiff / $lastInterval; my $curRatio = $diff / $time; my $intRatio = 1000 * ($lastRatio + $curRatio) / 2; - my $interpolationCount = int($offlineTime * $intRatio) + 1; # add one that gets lost as start of new interval + $intrCount = int(($offlTime * $intRatio)+0.5); + + Log3 $name, 3, "$name: pin $pin ($lName): interpolation after counter reset, offline $offlTime secs, $intrCount estimated pulses (before $lastCDiff in $lastInterval ms, now $diff in $time ms, avg ratio $intRatio p/s)"; + Log3 $name, 5, "$name: pin $pin ($lName): adding interpolated $intrCount to interpolated count $intpCount"; + $intpCount += $intrCount; - if ($lastCountTime && $lastInterval && $lastCDiff) { - Log3 $name, 4, "$name: interpolation after counter reset for pin $pin ($lName): offline $offlineTime secs, $interpolationCount estimated pulses (before $lastCDiff in $lastInterval ms, now $diff in $time ms, avg ratio $intRatio p/s)"; - Log3 $name, 4, "$name: adding interpolated $interpolationCount and $diff to long count $longCount"; - $longCount += $interpolationCount; - } else { - Log3 $name, 4, "$name: interpolation for pin $pin ($lName) not possible - no historic data"; - } - $hash->{CounterInterpolated}{$pin} = 1; + } else { + Log3 $name, 4, "$name: interpolation of missed pulses for pin $pin ($lName) not possible - no valid historic data."; } - $longCount += $diff; + $hash->{CounterInterpolated}{$pin} = 1; } + Log3 $name, 5, "$name: Pin $pin debug: adding $rDiff to long count $longCount and interpolated count $intpCount"; + $intpCount += $rDiff; + $longCount += $rDiff; - Log3 $name, 4, "$name: Pin $pin ($lName) count $count longCount $longCount (diff $diff) in " . - sprintf("%.3f", $time/1000) . "s" . + Log3 $name, 4, "$name: Pin $pin ($lName) count $count " . + ($longCount ? "longCount $longCount " : "") . + ($intpCount ? "interpCount $intpCount " : "") . + "(diff $diff) in " . sprintf("%.3f", $time/1000) . "s" . ((defined($reject) && $reject ne "") ? ", reject $reject" : "") . - ($avgLen ? ", Avg Len ${avgLen}ms" : "") . + (defined($avgLen) ? ", Avg Len ${avgLen}ms" : "") . ", result $power"; - Log3 $name, 5, "$name: interval $fSdTim until $fEdTim" . - ($first ? ", First at $first" : "") . - ($last ? ", Last at $last" : ""); + Log3 $name, 4, "$name: interval $fSdTim until $fEdTim" . + (defined($first) ? ", First at $first" : "") . + (defined($last) ? ", Last at $last" : ""); readingsBeginUpdate($hash); if (AttrVal($name, "readingStartTime$pin", 0)) { + # special way to set readings: use time of interval start as reading time Log3 $name, 5, "$name: readingStartTime$pin specified: setting reading timestamp to $fSdTim"; Log3 $name, 5, "$name: set readings $rpname to $power, timeDiff$pin to $time and countDiff$pin to $diff"; @@ -664,33 +689,50 @@ sub ArduCounter_Parse($) readingsBulkUpdate($hash, $rcname, $count); $hash->{CHANGETIME}[$chIdx++] = $fETime; - if (AttrVal($name, "verboseReadings$pin", 0)) { - readingsBulkUpdate($hash, $rlname, $longCount); - $hash->{CHANGETIME}[$chIdx++] = $fETime; + readingsBulkUpdate($hash, $rlname, $longCount); + $hash->{CHANGETIME}[$chIdx++] = $fETime; + + readingsBulkUpdate($hash, $riname, $intpCount); + $hash->{CHANGETIME}[$chIdx++] = $fETime; + + if (defined($reject)) { + my $rejCount = ReadingsVal($name, "reject$pin", 0); # alter reject count Wert im Reading + readingsBulkUpdate($hash, "reject$pin", $reject + $rejCount); + $hash->{CHANGETIME}[$chIdx++] = $fETime; + } + if (AttrVal($name, "verboseReadings$pin", 0)) { + readingsBulkUpdate($hash, "timeDiff$pin", $time); $hash->{CHANGETIME}[$chIdx++] = $fETime; + readingsBulkUpdate($hash, "countDiff$pin", $diff); $hash->{CHANGETIME}[$chIdx++] = $fETime; + readingsBulkUpdate($hash, "lastMsg$pin", $line); - $hash->{CHANGETIME}[$chIdx++] = $fETime; - if (defined($reject)) { - readingsBulkUpdate($hash, "reject$pin", $reject); - $hash->{CHANGETIME}[$chIdx++] = $fETime; + $hash->{CHANGETIME}[$chIdx++] = $fETime; + + if ($hist) { + readingsBulkUpdate($hash, "pinHistory$pin", $hist); + $hash->{CHANGETIME}[$chIdx++] = $fETime; } } } else { + # normal way to set readings Log3 $name, 5, "$name: set readings $rpname to $power, timeDiff$pin to $time and countDiff$pin to $diff"; readingsBulkUpdate($hash, $rpname, $power) if ($time); #$eTime = time_str2num(ReadingsTimestamp ($name, $rpname, 0)); readingsBulkUpdate($hash, $rcname, $count); + readingsBulkUpdate($hash, $rlname, $longCount); + readingsBulkUpdate($hash, $riname, $intpCount); + if (defined($reject)) { + my $rejCount = ReadingsVal($name, "reject$pin", 0); # alter reject count Wert im Reading + readingsBulkUpdate($hash, "reject$pin", $reject + $rejCount); + } if (AttrVal($name, "verboseReadings$pin", 0)) { - readingsBulkUpdate($hash, $rlname, $longCount); readingsBulkUpdate($hash, "timeDiff$pin", $time); - readingsBulkUpdate($hash, "countDiff$pin", $diff); + readingsBulkUpdate($hash, "countDiff$pin", $diff); readingsBulkUpdate($hash, "lastMsg$pin", $line); - if (defined($reject)) { - readingsBulkUpdate($hash, "reject$pin", $reject); - } + readingsBulkUpdate($hash, "pinHistory$pin", $hist) if ($hist); } } readingsEndUpdate($hash, 1); @@ -701,7 +743,7 @@ sub ArduCounter_Parse($) $hash->{'.Drift2'} = ($now - $hash->{'.DeTOff'}) - $deTime; } else { $hash->{'.DeTOff'} = $now - $deTime; - Log3 $name, 5, "$name: device clock wrapped (now $deTime, before $hash->{'.LastDeT'}). New offset is $hash->{'.DeTOff'}"; + Log3 $name, 4, "$name: device clock wrapped or reset (now $deTime, before $hash->{'.LastDeT'}). New offset is $hash->{'.DeTOff'}"; } } else { $hash->{'.DeTOff'} = $now - $deTime; @@ -765,7 +807,11 @@ sub ArduCounter_Parse($) Log3 $name, 3, "$name: please use set $name flash to update"; ArduCounter_HandleVersion($hash, $line); - } elsif ($line =~ /^M (.*)/) { + } elsif ($line =~ /^D (.*)/) { # debug / info Message from device + $retStr .= "\n" if ($retStr); + $retStr .= $1; + Log3 $name, 4, "$name: device: $1"; + } elsif ($line =~ /^M (.*)/) { # other Message from device $retStr .= "\n" if ($retStr); $retStr .= $1; Log3 $name, 3, "$name: device: $1"; @@ -928,9 +974,11 @@ sub ArduCounter_Ready($)

ArduCounter

+
  • pinHistory.*
  • + shows detailed information of the last pulses. This is only available when a minimal pulse length is specified for this pin. Also the total number of impulses recorded here is limited to 20 for all pins together. The output looks like -36/7:0C, -29/7:1G, -22/8:0C, -14/7:1G, -7/7:0C, 0/7:1G
    + The first number is the relative time in milliseconds when the input level changed, followed by the length in milliseconds, the level and the internal action.
    + -36/7:0C for example means that 36 milliseconds before the reporting started, the input changed to 0V, stayed there for 7 milliseconds and this was counted.
    +