<html xmlns:v="urn:schemas-microsoft-com:vml" xmlns:o="urn:schemas-microsoft-com:office:office" xmlns:w="urn:schemas-microsoft-com:office:word" xmlns:m="http://schemas.microsoft.com/office/2004/12/omml" xmlns="http://www.w3.org/TR/REC-html40"><head><meta http-equiv=Content-Type content="text/html; charset=utf-8"><meta name=Generator content="Microsoft Word 15 (filtered medium)"><!--[if !mso]><style>v\:* {behavior:url(#default#VML);}
o\:* {behavior:url(#default#VML);}
w\:* {behavior:url(#default#VML);}
.shape {behavior:url(#default#VML);}
</style><![endif]--><style><!--
/* Font Definitions */
@font-face
{font-family:"Cambria Math";
panose-1:2 4 5 3 5 4 6 3 2 4;}
@font-face
{font-family:Calibri;
panose-1:2 15 5 2 2 2 4 3 2 4;}
/* Style Definitions */
p.MsoNormal, li.MsoNormal, div.MsoNormal
{margin:0cm;
margin-bottom:.0001pt;
font-size:11.0pt;
font-family:"Calibri",sans-serif;}
a:link, span.MsoHyperlink
{mso-style-priority:99;
color:blue;
text-decoration:underline;}
a:visited, span.MsoHyperlinkFollowed
{mso-style-priority:99;
color:#954F72;
text-decoration:underline;}
.MsoChpDefault
{mso-style-type:export-only;}
@page WordSection1
{size:612.0pt 792.0pt;
margin:70.85pt 70.85pt 2.0cm 70.85pt;}
div.WordSection1
{page:WordSection1;}
--></style></head><body lang=DE link=blue vlink="#954F72"><div class=WordSection1><p class=MsoNormal>Hallo Zusammen,<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>hier eine kurzer Auszug aus dem LogFile, der das Verhalten belegt und auch erklärt. Ich bin mir nur nicht sicher ob es ein Bug oder doch en Feature ist. Zur Erinnerung: aggtime ist auf 180 Sekunden konfiguriert.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>$ cat vzlogger.log | grep RESULT<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 16:18:18][SUM] RESULT 1.000000 @ 1482074297367<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 16:26:24][SUM] RESULT 1.000000 @ 1482074784160<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 16:34:30][SUM] RESULT 1.000000 @ 1482075269620<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 16:42:44][SUM] RESULT 1.000000 @ 1482075763855<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 16:50:54][SUM] RESULT 1.000000 @ 1482076253440<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 16:59:04][SUM] RESULT 1.000000 @ 1482076743708<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:07:11][SUM] RESULT 1.000000 @ 1482077230993<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:15:14][SUM] RESULT 1.000000 @ 1482077713184<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:23:16][SUM] RESULT 1.000000 @ 1482078195362<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:30:23][SUM] RESULT 1.000000 @ 1482078623062<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:31:23][SUM] RESULT 1.000000 @ 1482078682365<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:32:12][SUM] RESULT 1.000000 @ 1482078731995<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:33:38][SUM] RESULT 1.000000 @ 1482078817905<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:35:01][SUM] RESULT 1.000000 @ 1482078901141<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:35:57][SUM] RESULT 1.000000 @ 1482078957060<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:36:36][SUM] RESULT 1.000000 @ 1482078995379<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:37:07][SUM] RESULT 1.000000 @ 1482079026684<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:38:05][SUM] RESULT 1.000000 @ 1482079084316<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:38:55][SUM] RESULT 1.000000 @ 1482079134720<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:39:44][SUM] RESULT 1.000000 @ 1482079183307<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:40:27][SUM] RESULT 1.000000 @ 1482079226809<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:41:11][SUM] RESULT 1.000000 @ 1482079271028<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:41:53][SUM] RESULT 1.000000 @ 1482079312363<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:42:31][SUM] RESULT 1.000000 @ 1482079351137<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:43:10][SUM] RESULT 1.000000 @ 1482079389844<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:43:50][SUM] RESULT 1.000000 @ 1482079430045<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:44:30][SUM] RESULT 1.000000 @ 1482079470132<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:45:10][SUM] RESULT 1.000000 @ 1482079509486<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:45:49][SUM] RESULT 1.000000 @ 1482079548973<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:46:29][SUM] RESULT 1.000000 @ 1482079588680<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:47:09][SUM] RESULT 1.000000 @ 1482079628743<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:47:50][SUM] RESULT 1.000000 @ 1482079669334<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:48:34][SUM] RESULT 1.000000 @ 1482079713419<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:49:19][SUM] RESULT 1.000000 @ 1482079758291<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:50:02][SUM] RESULT 1.000000 @ 1482079801734<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:50:45][SUM] RESULT 1.000000 @ 1482079844569<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:51:28][SUM] RESULT 1.000000 @ 1482079887909<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:52:11][SUM] RESULT 1.000000 @ 1482079931165<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:52:54][SUM] RESULT 1.000000 @ 1482079973669<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:53:38][SUM] RESULT 1.000000 @ 1482080017676<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:56:18][SUM] RESULT 3.000000 @ 1482080177836<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 17:59:27][SUM] RESULT 3.000000 @ 1482080366835<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 18:02:54][SUM] RESULT 3.000000 @ 1482080573948<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 18:05:13][SUM] RESULT 2.000000 @ 1482080712362<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'>[Dec 18 18:08:41][SUM] RESULT 3.000000 @ 1482080920902</span><span style='font-size:9.0pt'><o:p></o:p></span></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Aus dem Log wird ersichtlich, dass die gehäuften Logeinträge immer dann Zustande kommen, wenn die Last von weniger als ein S0 Impuls innerhalb von 180 s auf mind. 1 S0 Impuls innerhalb von 180 s steigt.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Nach einem Blick in die Sourcen von vzlogger, insb. threads.cpp ist das Verhalten auch erklärbar. Ob das so gewollt ist, kann der Entwickler beurteilen. Für mich kam es erst einmal überraschend.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Die verantwortliche Stelle im Code stammt aus der Funktion <span style='font-family:"Courier New"'>reading_thread()</span>.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'> <b>aggIntEnd = time(NULL);<o:p></o:p></b></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'> do { /* start thread main loop */<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'> <b><span style='color:red'>aggIntEnd += mtr->aggtime();</span></b><span style='color:red'> </span>/* end of this aggregation period */<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'> do { /* aggregate loop */<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'> /* fetch readings from meter and calculate delta */<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'> n = mtr->read(rds, details->max_readings); <b><span style='color:red'>// blocking call bei S0 Protokol<o:p></o:p></span></b></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'><o:p> </o:p></span></p><p class=MsoNormal><b><span style='font-size:9.0pt;font-family:"Courier New"'> // nicht relevanter Code gelöscht<o:p></o:p></span></b></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'><o:p> </o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New"'> } while((mtr->aggtime() > 0) && (time(NULL) < aggIntEnd)); /* default aggtime is -1 */<o:p></o:p></span></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Ein Blick in mein angehängtes Logfile zeigt, dass <span style='font-family:"Courier New"'>mtr->read</span> in Situation mit sehr wenig Last deutlich länger als die konfigurierte aggtime blockiert (teilweise bis zu 15 Minuten).<o:p></o:p></p><p class=MsoNormal>Das führt nun dazu, dass <span style='font-family:"Courier New"'>aggIntEnd</span> sehr weit in der Vergangenheit liegt. Die nächste Berechnung von <span style='font-family:"Courier New"'>aggIntEnd += mtr->aggtime() </span>führt zu einem Wert, der immer noch weit in der Vergangenheit liegt, womit die Abbruchbedingung der Aggregation loop weiterhin erfüllt ist.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Ist dieses Verhalten absichtlich so implementiert? Immerhin hat man dadurch über den kompletten Messzeitraum durchschnittlich immer einen Wert innerhalt von aggtime.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal>Ich hätte jetzt ehrlich gesagt eher sowas in der Art erwartet:<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New";color:black'>do {<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New";color:black'> aggIntEnd += mtr->aggtime(); /* end of this aggregation period */<o:p></o:p></span></p><p class=MsoNormal><span style='font-size:9.0pt;font-family:"Courier New";color:black'>} while(aggIntEnd <= time(NULL)); /* aggIntEnd has to be in the future */<o:p></o:p></span></p><p class=MsoNormal><span style='font-family:"Courier New";color:black'><o:p> </o:p></span></p><p class=MsoNormal>Viele Grüße,<o:p></o:p></p><p class=MsoNormal>Claus<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal><o:p> </o:p></p><div style='mso-element:para-border-div;border:none;border-top:solid #E1E1E1 1.0pt;padding:3.0pt 0cm 0cm 0cm'><p class=MsoNormal style='border:none;padding:0cm'><b>Von: </b><a href="mailto:mail@claus-beckenbauer.de">Claus Beckenbauer</a><br><b>Gesendet: </b>Sonntag, 18. Dezember 2016 11:15<br><b>An: </b><a href="mailto:volkszaehler-users@demo.volkszaehler.org">volkszaehler.org - users</a>; <a href="mailto:panterglas@web.de">Jens</a>; <a href="mailto:volkszaehler-users@demo.volkszaehler.org">volkszaehler-users</a><br><b>Betreff: </b>Re: [vz-users] vzlogger s0 protocol + aggtime funktioniertsporadisch nicht wie erwartet</p></div><p class=MsoNormal><o:p> </o:p></p><p class=MsoNormal style='margin-bottom:12.0pt'>Das mit dem Lastwechsel würde ich eher auf kurze Lastspitzen reduzieren.<br>Bei mir läuft das ganze auf nem RaspberryPi.<br>Ich generiere jetzt mal ein Log File und poste es hier.<br><br><o:p></o:p></p><div><p class=MsoNormal>Am 18. Dezember 2016 10:40:10 MEZ, schrieb Jens <panterglas@web.de>:<o:p></o:p></p><blockquote style='border:none;border-left:solid #CCCCCC 1.0pt;padding:0cm 0cm 0cm 6.0pt;margin-left:4.8pt;margin-right:0cm'><p class=MsoNormal>Hallo Claus,<o:p></o:p></p><div><p class=MsoNormal><o:p> </o:p></p></div><div><p class=MsoNormal>das Problem habe ich auch. Es tritt bei mir nur bei S0 Zähler auf und am Anfang eines Lastwechsels, z.B. wenn die Wärmepumpe einschaltet. Nach eine weile arbeitet blogger dann wie er soll.<o:p></o:p></p></div><div><p class=MsoNormal><o:p> </o:p></p></div><div><p class=MsoNormal>Würde gerne helfen, das Problem zu lösen, weiß aber nicht so recht was ich machen soll um den Experten zu helfen.<o:p></o:p></p></div><div><p class=MsoNormal><o:p> </o:p></p></div><div><p class=MsoNormal>Viele Grüße Jens<o:p></o:p></p></div><div><p class=MsoNormal><o:p> </o:p></p></div><div><p class=MsoNormal><img border=0 id="_x0000_i1025" src="cid:177BC7A6-B7A6-4CFF-B429-A2E39C3314CC@fritz.box" alt="cid:177BC7A6-B7A6-4CFF-B429-A2E39C3314CC@fritz.box"><o:p></o:p></p><div><blockquote style='margin-top:5.0pt;margin-bottom:5.0pt'><div><p class=MsoNormal>Am 18.12.2016 um 09:38 schrieb Daniel Lauckner <<a href="mailto:vz@jahp.de">vz@jahp.de</a>>:<o:p></o:p></p></div><p class=MsoNormal><o:p> </o:p></p><div><div><p class=MsoNormal>Hallo Claus,<br><br><br>am Samstag, 17. Dezember 2016 um 19:39 hast du geschrieben:<br><br><o:p></o:p></p><blockquote style='margin-top:5.0pt;margin-bottom:5.0pt'><p class=MsoNormal>Ich hätte jetzt erwartet, dass vzlogger maximal alle 180 Sekunden<br>einen Wert in die DB einträgt. Meistens funktioniert das auch. <o:p></o:p></p></blockquote><p class=MsoNormal>[...]<br><br><o:p></o:p></p><blockquote style='margin-top:5.0pt;margin-bottom:5.0pt'><p class=MsoNormal>Sporadisch kommt es jedoch vor, dass Werte häufiger eingetragen<br>werden.<o:p></o:p></p></blockquote><p class=MsoNormal><br><br><o:p></o:p></p><blockquote style='margin-top:5.0pt;margin-bottom:5.0pt'><p class=MsoNormal>Kann sich das jemand erklären?<o:p></o:p></p></blockquote><p class=MsoNormal style='margin-bottom:12.0pt'><br>Erklärung hab ich keine. Ein Logfile mit verbosity 15 und eine grobe<br>Richtung wie oft das auftritt wäre hilfreich.<br><br><br>mfg Daniel<o:p></o:p></p></div></div></blockquote></div><p class=MsoNormal><o:p> </o:p></p></div></blockquote></div><p class=MsoNormal><br>-- <br>Diese Nachricht wurde von meinem Android-Mobiltelefon mit K-9 Mail gesendet.<o:p></o:p></p><p class=MsoNormal><o:p> </o:p></p></div></body></html>