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

[Justin Otherguy]

…update:

> Am 05.05.2016 um 20:27 schrieb Justin Otherguy <justin at justinotherguy.org>:
> 
>> Am 05.05.2016 um 12:28 schrieb Andreas Goetz <cpuidle at gmail.com>:
>> 
>> 2016-05-05 12:12 GMT+02:00 Justin Otherguy <justin at justinotherguy.org>:
>> 
>>> 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>:
>>> 
>>>>> 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?
>>> 
>> M.E. ja!
> 
> done! s. [3] 
> 
> sieht besser aus…seither ist der Abstand zwischen den Übertragungen konstant und der höchste „value“ war 101.
> -> damit scheint mir bestätigt, dass die Verwendung von „interval“ hier reingespuckt hat - sehr schön, etwas Klarheit :)
> 
> Bleibt die Frage, wie aggtime sich hier auswirken sollte.
> - bei aggtime = 1 würde ich erwarten, dass die Impulse für 1 Sekunde gesammelt und dann in einem Request übertragen werden (value= (ca.) 100)
> - bei aggtime = 10 würde ich erwarten, dass die Impulse für 10 Sekunden gesammelt und dann in einem Request übertragen werden (value= (ca.) 1000)
> 
> Habe ich hier die falsche Vorstellung?

ja!

wenn ich schon grepe (greppe?), dann doch auch auf die richtige Zeile:


[May 05 20:48:38][s0]   Reading S0 - returning 2 readings (n=99 n_neg = 0)
[May 05 20:48:38][mtr0] Got 2 new readings from meter:
[May 05 20:48:38][mtr0] Reading: id=Power/StringItentifier: value=359274156.25 ts=1462474118547
[May 05 20:48:38][mtr0] Reading: id=Impulse/StringItentifier: value=99.00 ts=1462474118547
[May 05 20:48:39][s0]   Reading S0 - returning 2 readings (n=100 n_neg = 0)
[May 05 20:48:39][mtr0] Got 2 new readings from meter:
[May 05 20:48:39][mtr0] Reading: id=Power/StringItentifier: value=358923222.80 ts=1462474119550
[May 05 20:48:39][mtr0] Reading: id=Impulse/StringItentifier: value=100.00 ts=1462474119550

-> das sind 2 Blöcke; davon erscheint jede Sekunde einer (aus welchem Grund auch immer - anderes Thema)

Das hier ist der Block, den ich suche:
May 05 20:48:39][chn0] ==> number of tuples: 0
[May 05 20:48:39][chn0] JSON request body is null. Nothing to send now.
[May 05 20:48:39][chn0] Buffer dump (size=0): {}

Und der erscheint tatsächlich im Abstand von aggtime! :)


>>>> 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):
>> 
>> Das ist schon Fehlersuche aus dem Issue- noch wissen wir nicht obs bei Dir vorher einen anderen Fehler gibt der den überlagert. 
>> Könntest Du bitte erstmal testen ob aggtime wie erwartet funktioniert wenn Du aggfixedinterval ebenfalls setzt? Dann wissen wir ob das Logging wie erwartet läuft und können dann in send_zero aus dem Issue einsteigen.
> 
> jepp.
> 
> Habe aggfixedinterval aktiviert (s. [3]) und es werden weiterhin jede Sekunde die Werte geloggt:
> 
> [May 05 20:26:28][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462472788615
> [May 05 20:26:29][mtr0] Reading: id=Impulse/StringIdentifier: value=99.00 ts=1462472789607
> [May 05 20:26:30][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462472790610
> [May 05 20:26:31][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462472791612
> [May 05 20:26:32][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462472792615
> [May 05 20:26:33][mtr0] Reading: id=Impulse/StringIdentifier: value=99.00 ts=1462472793608
> [May 05 20:26:34][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462472794610
> [May 05 20:26:35][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462472795613
> [May 05 20:26:36][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462472796615
> [May 05 20:26:37][mtr0] Reading: id=Impulse/StringIdentifier: value=99.00 ts=1462472797608
> [May 05 20:26:38][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462472798611
> [May 05 20:26:39][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462472799613
> [May 05 20:26:40][mtr0] Reading: id=Impulse/StringIdentifier: value=100.00 ts=1462472800616
> [May 05 20:26:41][mtr0] Reading: id=Impulse/StringIdentifier: value=99.00 ts=1462472801608

das ist nicht das Logging der Werte, sondern die sekündlichen Zwischensummen.

Das Logging der Werte (grep „JSON“) passt genau zu aggtime (jetzt: 5):

[May 05 21:19:24][chn0] JSON request body: [ [ 1462475964073, 99.749499999999998 ] ]
[May 05 21:19:29][chn0] JSON request body: [ [ 1462475969076, 99.599040575654584 ] ]
[May 05 21:19:34][chn0] JSON request body: [ [ 1462475974079, 99.799720167899252 ] ]

Die Rätsel sind also auch gelöst:
- aggtime funktioniert, man muss aber an die richtige Stelle schauen ;-)
- der „Identifier“ ist wichtig - hier muss „Impulse“ stehen, sonst wird nix geloggt

neue Frage:
mir war das mit dem Identifier neu; wie ist das definiert? Haben wir da schon eine Übersicht in der Art "für Protocol a -> identifier b“ o.ä.?


Gruß, J.