[vz-dev] Fragen zum Protokoll "s0" in vzlogger

Thu May 5 12:12:37 CEST 2016

Hi,

> Am 05.05.2016 um 11:57 schrieb Andreas Goetz <cpuidle at gmail.com>:
> 
> 2016-05-05 8:18 GMT+02:00 Justin Otherguy <justin at justinotherguy.org>:
> 
>> um die Menge verbrauchter Pellets zu bestimmen, verwende ich das Protokoll „s0“ in vzlogger zusammen mit dem „Betriebsstundensensor“ in der Middleware. Mir scheint, ich habe ein paar Dinge in vzlogger noch nicht verstanden - vielleicht könnt Ihr mir helfen, Licht drauf zu werfen.
>> 
> Sensor = Wert oder Zustand. Ist eigentlich per Definition mit S0 (=Impuls oder Änderung) nicht verdaulich und allenfalls ein Hack. Siehe https://github.com/volkszaehler/vzlogger/issues/252 wie wir das ändern wollen.

ok - ich habe (für den Moment) die Middleware absichtlich mal rausgelassen, damit wir das Stück für Stück einmal durchkauen können.

>> Hier ist meine vzlogger.conf:
>> http://pastie.org/10824437
>> 
>> Ich hatte das Thema als Github-Issue #249 eröffnet - dann zeigte sich aber, dass das auf der ML besser aufgehoben ist.
>> Hier schon mal ein paar Zwischenergebnisse und neue Fragen:
>> 
>> 1. bei der Verwendung von s0 in Kombination mit "interval": 1 werden lt. Matthias für 1 s keine Daten gezählt
>> das verstehe ich nicht; weder leuchtet mir ein, wieso oder wozu das so sein soll noch deckt es sich mit meiner Beobachtung - habe ich das falsch verstanden?
>> 
> Das soll gar nicht sein. S0 reagiert auf Impulse (!), interval pollt. Die beiden Settings schließen sich logisch eigentlich aus und sollten nicht zusammen verwendet werden.

ok - richtig wäre also, interval nicht zu setzen, wenn ich s0 nutze, korrekt?

Das probiere ich mal aus. Falls ich das richtig verstanden habe: haben wir eine Chance, das beim Parsen der Config entweder 
- als Fehler auszugeben -> vzlogger beendet sich oder 
- als Warning auf der Konsole und im Logfile?

>> Ausschnitt aus vzlogger.conf:
>> [May 05 08:11:31][S0]   MeterS0:HWIF_GPIO:first poll returned 1
>> [May 05 08:11:31][S0]   MeterS0:HWIF_GPIO:first poll returned 1
>> [May 05 08:11:31][S0]   MeterS0:HWIF_GPIO:first poll returned 1
>> [May 05 08:11:31][S0]   MeterS0:HWIF_GPIO:first poll returned 1
>> [May 05 08:11:31][S0]   MeterS0:HWIF_GPIO:first poll returned 1
>> [May 05 08:11:31][S0]   MeterS0:HWIF_GPIO:first poll returned 1
>> [May 05 08:11:31][S0]   MeterS0:HWIF_GPIO:first poll returned 1
>> [May 05 08:11:31][s0]   Reading S0 - returning 4 readings (n=100 n_neg = 0)
>> [May 05 08:11:31][mtr0] Got 4 new readings from meter:
>> [May 05 08:11:31][mtr0] Reading: id=Power/StringIdentifier: value=359281.40 ts=1462428691862
>> [May 05 08:11:31][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462428691862
>> [May 05 08:11:31][mtr0] Reading: id=Power_neg/StringIdentifier: value=0.00 ts=1462428691862
>> [May 05 08:11:31][mtr0] Reading: id=Impulse_neg/StringIdentifier: value=0.00 ts=1462428691862
>> [May 05 08:11:31][S0]   MeterS0:HWIF_GPIO:first poll returned 1
>> [May 05 08:11:31][S0]   MeterS0:HWIF_GPIO:first poll returned 1
>> [May 05 08:11:31][S0]   MeterS0:HWIF_GPIO:first poll returned 1
>> [May 05 08:11:31][S0]   MeterS0:HWIF_GPIO:first poll returned 1
>> [May 05 08:11:31][S0]   MeterS0:HWIF_GPIO:first poll returned 1
>> [May 05 08:11:31][S0]   MeterS0:HWIF_GPIO:first poll returned 1
>> [May 05 08:11:31][S0]   MeterS0:HWIF_GPIO:first poll returned 1
>> 
>> Ich gebe 50 Hz auf den Eingang - und das sieht so aus, als würden die auch (zum Grossteil) verarbeitet.
>> 
>> 
>> 2. aggtime ist die Zeit, über die aggregiert wird
>> 
>> das scheint mir nicht immer zu funktionieren - noch ein Auszug, jetzt gegrept nach "Impulse/StringIdentifier“:
>> 
>> [May 05 08:12:36][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462428756878
>> [May 05 08:12:37][mtr0] Reading: id=Impulse/StringIdentifier: value=99.00 ts=1462428757871
>> [May 05 08:12:38][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462428758874
>> [May 05 08:12:48][mtr0] Reading: id=Impulse/StringIdentifier: value=998.00 ts=1462428768879
>> [May 05 08:12:49][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462428769882
>> [May 05 08:12:50][mtr0] Reading: id=Impulse/StringIdentifier: value=99.00 ts=1462428770874
>> [May 05 08:12:51][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462428771877
>> 
>> -> in der Liste hat’s ein Mal geklappt: „value=998“, sonst immer ca. 100.
>> 
>> Wie kann ich das genauer eingrenzen?
>> 
> Ich kann nicht erkennen wo/was da nicht  funktioniert insofern schwer zu beantworten.

bei 1. ging’s mir um „Interval=1 bewirkt, dass jeweils 1 Sekunde keine Impulse verarbeitet werden
der Auszug zeigt mehrere Einträge innerhalb einer Sekunde - direkt vor und nach dem Loggen eines Wertes
Damit wollte ich zeigen, weshalb ich hier einen Widerspruch erkenne
-> ich verstehe jetzt: Interval und s0 gehören nicht zusammen

bei 2. ging’s mir darum zu zeigen, dass aggtime in meinem konkreten Fall nicht immer funktioniert:
die ersten drei Einträge sind im Abstand von 1 Sekunde mit einem value von ca. 100
der vierte Eintrag kommt dann nach 10 s mit einem value von ca. 1000

Sind die Fragen jetzt klarer?

> Wir haben seit ewigen Zeiten aber vmtl. diesen Fehler offen: https://github.com/volkszaehler/vzlogger/issues/231 Könnte das die Ursache sein?

das ist ein guter Punkt - vielleicht können wir das nun gleich mit klären.

Ich habe send_zero nun auskommentiert [1] - Auszug aus dem Log (wieder gegrept nach Impulse/StringItentifier):

[May 05 12:09:54][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462442994364
[May 05 12:09:55][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462442995367
[May 05 12:09:56][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462442996369
[May 05 12:09:57][mtr0] Reading: id=Impulse/StringIdentifier: value=99.00 ts=1462442997362
[May 05 12:09:58][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462442998364
[May 05 12:10:08][mtr0] Reading: id=Impulse/StringIdentifier: value=998.00 ts=1462443008370
[May 05 12:10:09][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462443009373
[May 05 12:10:10][mtr0] Reading: id=Impulse/StringIdentifier: value=99.00 ts=1462443010365
[May 05 12:10:11][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462443011368

-> das scheint zumindest das Verhalten nicht zu ändern.

> Bevor wir weiter an Symptomen rumdoktorn würde mich aber eigentlich interessieren wie konkret Deine Meßeinrichtung aussieht- dann finden wir auch die richtige Konfiguration dazu.

ich verwende Udos whm [2] „produktiv“ und im Test hier gerade einen Arduino, der 50 Hz auf den GPIO17 des RPi ausgibt.
Brauchst Du weitere Details?

Weitere Ideen, was ich testen kann?

Gruß, J.

[1] http://pastie.org/10825317
[2] http://wiki.volkszaehler.org/hardware/channels/meters/working_hours