[vz-users] Fwd: Re: Fehler "Too much data for obis_code" im vzlogger.log
Frank Richter
frank.richter83 at gmail.com
Mon Jun 1 12:41:22 CEST 2015
Hallo Andre,
du kannst doch die Zeit, zu der im Frontend der Peak angezeigt wird, in
einen Timestamp zurückrechnen und dann per phpmyadmin nach Datensätzen in
diesem Zeitbereich suchen.
Die hohe Auslastung habe ich damals mit vmstat 5 festgestellt. Dort wurden
sehr hohe Werte in der letzten Spalte (wa) ausgegeben. Aber bei 30s ist das
vermutlich bei dir kein Thema.
Gruß
Frank
Am 1. Juni 2015 um 12:32 schrieb Viper <viper at viper1.de>:
> Hallo Frank,
> die Vermutung mit dem falschen Timestamp hatte ich auch schon. Weiß nur
> nicht wie ich die Datenbank sinnvoll durchsuchen kann. Es sind fast 60.000
> Einträge was mir manuell etwas zu viel sind.
> Wenn ich so einen negativen Peak mal zeitnah mitbekomme ist dies sicher
> kein Thema.
> Zur Zeit schreibe ich alle 30s einen Zählerstand in die Datenbank und die
> CPU-Auslastung liegt deutlich unter 10%. Die I/O Auslastung kann natürlich
> trotzdem an der Grenze sein. Da weiß ich aber nicht wie ich diese
> Überprüfen kann.
>
> Ich habe Udo's Tipp beherzigt und das System gestern Abend auf dem neuen
> Immage aufgesetzt. Kurzes Überprüfen gestern hatte wieder ein fehlen von
> mehreren kWh gezeigt. Werde heute noch mal genauer nachsehen.
>
> Gruß Andre
>
> Am 1. Juni 2015 09:45:53 MESZ, schrieb Frank Richter <
> frank.richter83 at gmail.com>:
>>
>> Hallo Andre,
>>
>> hast du dir mal die Datenbankeinträge für den heftigen
>> positiv/negativ-Peak angeschaut? Wäre interessant, ob in der Datenbank
>> falsche Zählerstände stehen oder realistische Zählerstände mit falschen
>> Timestamps.
>> Ich hatte anfangs auch immer wieder ähnliche Peaks in meinen Diagrammen,
>> was wohl daran lag, dass das ständige Auslesen zeitweise die I/O-Leistung
>> meines Raspis überforderte und deshalb das System so lahm war, dass
>> manchmal ein Messwert seinen Zeitstempel deutlich zu spät zugeordnet bekam.
>> Dadurch war die Zeitdifferenz vor dem Messwert länger als real und die
>> danach kürzer als real. Das äußerte sich in den Diagrammen als Kombination
>> eines erst negativen und dann positiven Peaks, allerdings ging die Kurve
>> nie unter null, d.h. die Reihenfolge der Messwerte blieb intakt. Ich habe
>> das System dann dadurch entlastet, dass ich vzlogger nur noch alle 15s
>> einen Wert an die Middleware übertragen lasse. Seitdem ist die I/O-Last
>> erträglich und die Peaks sind weg.
>> Bei deinem Diagramm würde ich fast vermuten, dass ein eigentlich später
>> erfasster Messwert mit einem früheren Timestamp in der DB steht, warum auch
>> immer. Wenn dann zu einem späteren Zeitpunkt nochmal ein geringerer
>> Zählerstand kommt, würde das den Peak ins negative erklären.
>>
>> Viele Grüße
>> Frank
>> Hallo Andreas,
>>
>> habe schon mit der Positionierung gespielt. Glaube aber eher an ein
>> Einstellungs- Softwareproblem. Da wenn ich den Befehl cat /dev/ttyAMA0
>> aufrufe die Daten in Ordnung sind und auch dem aktuellen Zählerstand
>> entsprechen.
>> Wirk- und Scheinleistung gibt mein Zähler nicht aus, nur den Zählerstand.
>>
>> Gruß Andre
>>
>> Am 31.05.2015 um 13:36 schrieb Andreas Götz:
>>
>> Ich kenn mich mit dem Obis Zeugs leider nixht aus, aber was sind denn die
>> 96.x Obis Codes? Falls da Wirk- oder Scheinleistung dabei wäre könnte das
>> vielleicht besser funktionieren als Zählerstände?
>>
>> Was mich verwirrt ist Deine Grafik. Die sieht nämlich nicht nur so aus
>> als würde der Zählerstand nach oben springen (Überschwinger der Leistung)
>> sondern auch als würde er wieder zurück springen?
>>
>> Vllt wäre es auch noch einen Versuch Wert die Justierung des Kopfes
>> nochmal etwas zu verändern?
>>
>> Viele Grüße, Andreas
>>
>>
>>
>>
>> Am 31.05.2015 um 12:46 schrieb Viper <viper at viper1.de>:
>>
>> Ich bin leider immer noch nicht weiter wegen des Fehlers. Das Log
>> quillt immer noch vor Fehlern über. Ich habe mal einen Dump von den
>> Messwerten angelegt. Der sieht gut aus, leider scheint da kein Zeitstempel
>> bei zu sein. Auffällig ist das der letzte Wert im Dump 6kWh hinter dem
>> wahren Zählerstand hinterher hängt.
>> Wenn man vzlogger stoppt und neu startet stimmt der Zählerstand wieder
>> was zu einem enormen Peak in der Anzeige des Fontend führt.
>> Aber auch ohne Neustart kommen solche Peaks in dieser Woche wieder extrem
>> mit einem plus Ausschlag von *76,**5TW *mit einem anschließenden *minus *von
>> *78,1TW* obwohl ich gar keinen Strom einspeise.
>> Man beachte auch den von vzlogger errechneten Gesamtverbrauch. Da bei mir
>> eh nur der Zählerstand erfasst wird bräuchte dieser auch nur im Fontend
>> dargestellt und nicht errechnet zu werden.
>>
>> Hier noch ein Auszug aus dem Dump:
>>
>> ##### 75.449117000s ( -61 ms) read
>> >>>>> 75.449251000s ( 0 ms)
>> 0a 0a 2f 49 53 6b 35 4d 54 36 37 31 2d 30 30 30 /ISk5MT671-000
>> 31 0a 0a 0a 0a 31 2d 30 3a 30 2e 30 2e 30 2a 32 1 1-0:0.0.0*2
>> 35 35 28 33 33 31 33 30 30 2d 35 30 33 33 31 32 55(331300-503312
>> 34 29 0a 0a 31 2d 30 3a 31 2e 38 2e 31 2a 32 35 4) 1-0:1.8.1*25
>> 35 28 30 33 31 32 39 36 2e 34 31 30 34 29 0a 0a 5(031296.4104)
>> 31 2d 30 3a 39 36 2e 35 2e 35 2a 32 35 35 28 38 1-0:96.5.5*255(8
>> 30 29 0a 0a 30 2d 30 3a 39 36 2e 31 2e 32 35 35 0) 0-0:96.1.255
>> 2a 32 35 35 28 33 39 32 32 35 34 37 39 29 0a 0a *255(39225479)
>> 21 !
>>
>> ##### 5.452544000s ( -61 ms) read
>> >>>>> 5.452681000s ( 0 ms)
>> 2f 49 53 6b 35 4d 54 36 37 31 2d 30 30 30 31 0a /ISk5MT671-0001
>> 0a 0a 0a 31 2d 30 3a 30 2e 30 2e 30 2a 32 35 35 1-0:0.0.0*255
>> 28 33 33 31 33 30 30 2d 35 30 33 33 31 32 34 29 (331300-5033124)
>> 0a 0a 31 2d 30 3a 31 2e 38 2e 31 2a 32 35 35 28 1-0:1.8.1*255(
>> 30 33 31 32 39 36 2e 34 31 35 32 29 0a 0a 31 2d 031296.4152) 1-
>> 30 3a 39 36 2e 35 2e 35 2a 32 35 35 28 38 30 29 0:96.5.5*255(80)
>> 0a 0a 30 2d 30 3a 39 36 2e 31 2e 32 35 35 2a 32 0-0:96.1.255*2
>> 35 35 28 33 39 32 32 35 34 37 39 29 0a 0a 21 55(39225479) !
>>
>> ##### 35.455505000s ( -61 ms) read
>> >>>>> 35.455639000s ( 0 ms)
>> 0a 0a 2f 49 53 6b 35 4d 54 36 37 31 2d 30 30 30 /ISk5MT671-000
>> 31 0a 0a 0a 0a 31 2d 30 3a 30 2e 30 2e 30 2a 32 1 1-0:0.0.0*2
>> 35 35 28 33 33 31 33 30 30 2d 35 30 33 33 31 32 55(331300-503312
>> 34 29 0a 0a 31 2d 30 3a 31 2e 38 2e 31 2a 32 35 4) 1-0:1.8.1*25
>> 35 28 30 33 31 32 39 36 2e 34 31 35 34 29 0a 0a 5(031296.4154)
>> 31 2d 30 3a 39 36 2e 35 2e 35 2a 32 35 35 28 38 1-0:96.5.5*255(8
>> 30 29 0a 0a 30 2d 30 3a 39 36 2e 31 2e 32 35 35 0) 0-0:96.1.255
>> 2a 32 35 35 28 33 39 32 32 35 34 37 39 29 0a 0a *255(39225479)
>> 21 !
>>
>> ##### 65.458572000s ( -61 ms) read
>> >>>>> 65.458699000s ( 0 ms)
>> 2f 49 53 6b 35 4d 54 36 37 31 2d 30 30 30 31 0a /ISk5MT671-0001
>> 0a 0a 0a 31 2d 30 3a 30 2e 30 2e 30 2a 32 35 35 1-0:0.0.0*255
>> 28 33 33 31 33 30 30 2d 35 30 33 33 31 32 34 29 (331300-5033124)
>> 0a 0a 31 2d 30 3a 31 2e 38 2e 31 2a 32 35 35 28 1-0:1.8.1*255(
>> 30 33 31 32 39 36 2e 34 31 39 34 29 0a 0a 31 2d 031296.4194) 1-
>> 30 3a 39 36 2e 35 2e 35 2a 32 35 35 28 38 30 29 0:96.5.5*255(80)
>> 0a 0a 30 2d 30 3a 39 36 2e 31 2e 32 35 35 2a 32 0-0:96.1.255*2
>> 35 35 28 33 39 32 32 35 34 37 39 29 0a 0a 21 55(39225479) !
>>
>> ##### 95.461526000s ( -61 ms) read
>> >>>>> 95.461659000s ( 0 ms)
>> 0a 0a 2f 49 53 6b 35 4d 54 36 37 31 2d 30 30 30 /ISk5MT671-000
>> 31 0a 0a 0a 0a 31 2d 30 3a 30 2e 30 2e 30 2a 32 1 1-0:0.0.0*2
>> 35 35 28 33 33 31 33 30 30 2d 35 30 33 33 31 32 55(331300-503312
>> 34 29 0a 0a 31 2d 30 3a 31 2e 38 2e 31 2a 32 35 4) 1-0:1.8.1*25
>> 35 28 30 33 31 32 39 36 2e 34 31 39 36 29 0a 0a 5(031296.4196)
>> 31 2d 30 3a 39 36 2e 35 2e 35 2a 32 35 35 28 38 1-0:96.5.5*255(8
>> 30 29 0a 0a 30 2d 30 3a 39 36 2e 31 2e 32 35 35 0) 0-0:96.1.255
>> 2a 32 35 35 28 33 39 32 32 35 34 37 39 29 0a 0a *255(39225479)
>> 21 !
>>
>> ##### 25.464507000s ( -61 ms) read
>> >>>>> 25.464641000s ( 0 ms)
>> 2f 49 53 6b 35 4d 54 36 37 31 2d 30 30 30 31 0a /ISk5MT671-0001
>> 0a 0a 0a 31 2d 30 3a 30 2e 30 2e 30 2a 32 35 35 1-0:0.0.0*255
>> 28 33 33 31 33 30 30 2d 35 30 33 33 31 32 34 29 (331300-5033124)
>> 0a 0a 31 2d 30 3a 31 2e 38 2e 31 2a 32 35 35 28 1-0:1.8.1*255(
>> 30 33 31 32 39 36 2e 34 32 33 34 29 0a 0a 31 2d 031296.4234) 1-
>> 30 3a 39 36 2e 35 2e 35 2a 32 35 35 28 38 30 29 0:96.5.5*255(80)
>> 0a 0a 30 2d 30 3a 39 36 2e 31 2e 32 35 35 2a 32 0-0:96.1.255*2
>> 35 35 28 33 39 32 32 35 34 37 39 29 0a 0a 21 55(39225479) !
>>
>> ##### 55.471947000s ( -57 ms) read
>> >>>>> 55.472075000s ( 0 ms)
>> 0a 0a 2f 49 53 6b 35 4d 54 36 37 31 2d 30 30 30 /ISk5MT671-000
>> 31 0a 0a 0a 0a 31 2d 30 3a 30 2e 30 2e 30 2a 32 1 1-0:0.0.0*2
>> 35 35 28 33 33 31 33 30 30 2d 35 30 33 33 31 32 55(331300-503312
>> 34 29 0a 0a 31 2d 30 3a 31 2e 38 2e 31 2a 32 35 4) 1-0:1.8.1*25
>> 35 28 30 33 31 32 39 36 2e 34 32 33 36 29 0a 0a 5(031296.4236)
>> 31 2d 30 3a 39 36 2e 35 2e 35 2a 32 35 35 28 38 1-0:96.5.5*255(8
>> 30 29 0a 0a 30 2d 30 3a 39 36 2e 31 2e 32 35 35 0) 0-0:96.1.255
>> 2a 32 35 35 28 33 39 32 32 35 34 37 39 29 0a 0a *255(39225479)
>> 21 !
>>
>>
>> <ggdcjaeb.png>
>>
>>
>> -------- Weitergeleitete Nachricht -------- Betreff: Re: Fehler "Too
>> much data for obis_code" im vzlogger.logDatum: Thu, 21 May 2015 19:48:11
>> +0200Von: Viper <viper at viper1.de> <viper at viper1.de>Antwort an:
>> viper at viper1.deAn: volkszaehler.org - users
>> <volkszaehler-users at demo.volkszaehler.org>
>> <volkszaehler-users at demo.volkszaehler.org>
>>
>> Hat den keiner eine Idee woran dies liegen könnte. Im Log kommen jeden
>> Tag ca. 1000 neue Einträge mit "Too much data for obis_code" hinzu.
>>
>> Am 09.05.2015 um 13:52 schrieb Viper:
>>
>> Hallo,
>>
>> zuerst möchte ich mich noch mal bei Andreas und Matthias bedanken, welche
>> sich wirklich bemüht haben um meinen Fehler im Threat: "Stromdaten werden
>> mit 4 Stündiger Verspätung angezeigt" zu beheben.
>>
>> Ich bin mir zwischenzeitlich sicher, dass dieser mit dem Fehler welchen
>> ich hier beschreibe zusammenhängt. Und zwar habe ich ein sehr merkwürdiges
>> Phänomen...
>> Ich lese den Zählerstand aus meinen Iska MT671 mittels einer einfachen
>> Infarotdiode welcher an GPIO 15 hängt. Nach dem Neuaufsetzen meines
>> Raspberry Pi mit dem Immage: volkszaehler_2015_11_02.img von Udo von der
>> Volkszähler Seite kamen mittels des Befehls "cat /dev/ttyAMA0" solche
>> merkwürdigen Daten an:
>>
>> ��S�5M�6��-000��
>> �
>> �-0:0.0.0��55(33�300-5033�����
>> �-0:�.�.���55(030��3.9�03��
>> �-0:96.5.5��55(�0��
>> 0-0:96.�.�55��55(39��5��9��
>> !�
>>
>> Auf anraten von Udo habe ich minicom gestartet und die Daten waren in
>> Ordnung ohne das ich eine Einstellung in minicom gemacht hätte.
>>
>> Nun kann ich den Befehl "cat /dev/ttyAMA0" Stundenlang laufen lassen und
>> es kommen immer Daten in dieser Form:
>>
>> /ISk5MT671-0001
>>
>> 1-0:0.0.0*255(331300-5033124)
>> 1-0:1.8.1*255(030913.8795)
>> 1-0:96.5.5*255(80)
>> 0-0:96.1.255*255(39225479)
>> !
>>
>> Lass ich aber minicom laufen kommen Reproduzierbar nach einigen Sekunden
>> folgende Daten:
>>
>> /ISk5MT671-0001
>>
>>
>>
>> 1-0:0.0.0*255(331300-5033124)
>>
>> 1-0:1.8.1*255(030913.6591)
>>
>> 1-0:96.5.5*255(80)
>>
>> 0-0:96.1.255*255(39225479)
>>
>> !
>>
>> 255(80)1.255*25(3922579)
>>
>> /ISk5MT6
>>
>> 1-0:0331300-033124)
>>
>>
>> 1-0:1..1*255(30913.699)
>> 1-:96.5.5255(80)5(3922579)
>>
>> /ISk5MT6
>>
>> 1-0:00.0*255331300-033124)
>>
>>
>> 1-0:1..1*255(030913.6603)
>> 1-:96.5.5255(80)
>>
>>
>> 0-0:961.255*25(3922579)
>> /ISk5MT6
>>
>> 1-0:00.0*255331300-033124)
>>
>>
>> 1-0:1..1*255(30913.607)
>> 1-:96.5.5255(80)
>>
>> 0-0:961.255*25(3922579)
>>
>> Die Minicom 2.6.1 Einstellungen: 9600 Baud, 7E1, NOR, VT102
>>
>> Stoppe ich minicom und starte es neu sind die Daten für die ersten
>> Sekunden wieder in Ordnung bevor die Fehler wiederkommen. Öffne ich ein
>> zweites Terminal und starte dort "cat /dev/ttyAMA0" stoppen in minicom die
>> falschen Daten und nach dem beenden des cat Befehls laufen die Daten in
>> minicom ohne Fehler weiter.
>>
>> vzlogger scheint auch wie minicom ein Problem zu bekommen die Daten zu
>> lesen denn das Log (Loglevel 1) ist voll von folgenden Fehlern:
>>
>> [May 07 19:39:59][d0] Failed to parse obis code (1-0/ISk5MT671-00)
>> [May 07 20:56:59][d0] Too much data for value (byte=0x31)
>> [May 07 20:56:59][d0] Too much data for value (byte=0x2D)
>> [May 07 20:56:59][d0] Too much data for value (byte=0x30)
>> [May 07 20:56:59][d0] Too much data for value (byte=0x3A)
>> [May 07 20:56:59][d0] Too much data for value (byte=0x30)
>> [May 07 20:56:59][d0] Too much data for value (byte=0x2E)
>>
>> Und:
>>
>> May 07 21:02:59][d0] Too much data for identification (byte=0x36)
>> [May 07 21:02:59][d0] Too much data for identification (byte=0x37)
>> [May 07 21:02:59][d0] Too much data for identification (byte=0x31)
>> [May 07 21:02:59][d0] Too much data for identification (byte=0x2D)
>> [May 07 21:02:59][d0] Too much data for identification (byte=0x30)
>> [May 07 21:02:59][d0] Too much data for identification (byte=0x30)
>> [May 07 21:02:59][d0] Too much data for identification (byte=0x30)
>> [May 07 21:02:59][d0] Too much data for identification (byte=0x31)
>>
>> Dies zeigt sich in der Datenbank dann damit das der Zählerstand mehrere
>> kWh hinterherläuft wahrscheinlich zählt vzlogger nur den mindesumsatz dazu.
>>
>> Starte ich nun minicom oder "cat /dev/ttyAMA0" bekommt vzlogger den
>> aktuellen Zählerstand welches sich dann im Webfontend mit einem Peak von
>> mehreren kW bis GW bemerkbar macht, siehe Bild.
>>
>> Hier noch meine vzlogger.conf:
>>
>> {
>> "retry": 30, // how long to sleep between failed requests,
>> in seconds
>> "daemon": true, // run periodically
>> "verbosity": 1, // between 0 and 15
>> "log": "/var/log/vzlogger.log", // path to logfile, optional
>>
>> "local": {
>> "enabled": false, // should we start the local HTTPd for
>> serving live readings?
>> "port": 8080, // the TCP port for the local HTTPd
>> "index": true, // should we provide a index listing of
>> available channels if no UUID was requested?
>> "timeout": 30, // timeout for long polling comet requests, 0
>> disables comet, in seconds
>> "buffer": 600 // how long to buffer readings for the local
>> interface, in seconds
>> },
>>
>> "meters": [
>> {
>> "enabled": true, // disabled meters will be
>> ignored (default)
>> "skip": false, // if enabled, errors when
>> opening meter will lead to meter being ignored
>> "protocol": "d0", // see 'vzlogger -h' for list
>> of available protocols
>> "device": "/dev/ttyAMA0",
>> // "dump_file": "/var/log/dumpD0.txt", // optional, if set logs
>> all received/transmitted data to this file
>> // "read_timeout": 10, // optional, default 10s. Timeout value
>> in secs between single bytes received from device
>> // "baudrate_change_delay": 400, // optional, default none.
>> Delay value in ms after ACKSEQ send before baudrate change
>> "parity": "7E1", // 7E1 oder 8N1
>> "baudrate": 9600, // 9600moder 300
>> // "pullseq": "2F3F210D0A", // Pullsequenz in 'hex'
>> // "ackseq": "063030300d0a", // optional (default: keine
>> Antwortsequenz auf Zaehlerantwort) kann entweder feste hex-Sequenz sein
>> (z.B. 063035300d0a für mode C mit 9600bd oder 063030300d0a = 300bd) oder
>> kann auf "auto" gesetzt werden, damit die Sequenz autom. berechnet wird und
>> autom. auf die max. Baudrate umgeschaltet wird (baudrate_read wird dann
>> ignoriert)
>> // "baudrate_read": 300, // Baudratenumschaltung auf
>> gewünschte Baudrate, abhängig von Zählerantwort
>> "aggtime": 30, // in Sekunden
>> "aggmode": "SUM", // AVG Mittelwert für
>> Leistung, "MAX" für Zähler, "SUM" für Counter
>> "interval": 30, // Wartezeit in Sekunden bis
>> neue Werte in die middleware übertragen werden
>> "channel": { // Beispiel-channel
>> "uuid": "c2cafa00-c502-11e4-9b6d-xxxxxx",
>> "middleware": "http://vzxxxx/middleware.php"
>> <http://vzxxxx/middleware.php>,
>> "identifier": "1-0:1.8.1*255" // alias for '1-0:1.8.1',
>> see 'vzlogger -h' for list of available aliases
>> },
>> }
>> ]
>> }
>>
>>
>> Ich hoffe jemand hat eine Idee.
>>
>> Gruß Andre
>>
>> <mime-attachment.png>
>>
>>
>>
>>
>>
>>
> --
> Diese Nachricht wurde von meinem Android-Mobiltelefon mit K-9 Mail
> gesendet.
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://demo.volkszaehler.org/pipermail/volkszaehler-users/attachments/20150601/a3ae3274/attachment-0001.html>
More information about the volkszaehler-users
mailing list