[vz-users] Fehlermeldungen in vzlogger.log
Tilman Glötzner
tilman_1 at gloetzner.net
So Feb 20 14:14:59 CET 2022
Hallo Stefan
ich verstehe (und möglicher Weise ist das falsch), dass man mit
"duplicates" für den gegebenen Zeitraum den Eintrag von Datensätzen mit
gleichem Wert überspringt. Wenn sich also die Temperatur nicht ändert,
dann wird erst nach "duplicates" ein neuer Eintrag angelegt. Die Periode
der Messwerterfassung ist davon unabhängig. Die Intention des hohen Wert
ist hierbei, den Platz in der Datenbank nicht mit identischen Werten
vollzuschreiben.
60 Sekunden fände ich als Messintervall ebenfalls einen guten Wert --
ich habe als "interval" 60 eingetragen -- mal sehen, ob es was ändert.
>Der SOE ist ja in einem andern Channel, also nicht mit der id 20
Ja, das stimmt. Ich dachte, es sei auf dem Kanal 19 -- wo ich keinen Eintrag in der Datenbank gefunden habe. Jetzt habe ich aber gesehen, dass der Soe mit id 21 gespeichert wird.Hier gibt es ebenfalls nur einen Eintrag.
Gruß
Tilman
On 20.02.22 13:51, Stefan Bauer wrote:
> Der SOE ist ja in einem andern Channel, also nicht mit der id 20.
> Ich verstehe den Teil mit Deinem exercise script eh nicht. Warum hast du duplicates so hoch gewählt?
> Ich könnte mir gut vorstellen, dass das Script aufgrund der vielen Anfragen durcheinander kommt und daher der falsche Timestamp rauskommt. Sollte nicht ein interval hier die bessere Wahl sein, bzw. Eine sinnvolle Ergänzung? Aus meiner Sicht kann der Speicher auch nur alle 60Sekunden abgefragt werden.
>
> Stefan
>
> Von meinem iPad gesendet
>
>> Am 20.02.2022 um 13:21 schrieb Tilman Glötzner <tilman_1 at gloetzner.net>:
>>
>> Hallo Maik, Hallo Daniel
>>
>> 1) ich habe allen Benutzeraccounts Rechte zum Schreiben des Log-Files gegeben. Damit startet vzlogger, Danke für den Hinweis.
>>
>> 2) Ausserdem habe /etc/systemd/system/vzlogger.service angepasst, so dass vzlogger nun unter dem Benutzer "pi" läuft
>>
>> 3) Im Logfile finde ich nun folgendes:
>>
>> --------- snip ----------
>>
>> [Feb 20 13:03:10][main] log level is 3
>> [Feb 20 13:03:10][s0] failed to set policy to SCHED_FIFO for counter_thread
>> [Feb 20 13:03:10][s0] failed to set policy to SCHED_FIFO for counter_thread
>> [Feb 20 13:03:10][s0] failed to set policy to SCHED_FIFO for counter_thread
>> [Feb 20 13:03:10][s0] failed to set policy to SCHED_FIFO for counter_thread
>> [Feb 20 13:03:10][s0] failed to set policy to SCHED_FIFO for counter_thread
>> [Feb 20 13:03:16][chn9] Middleware says duplicated value. Removing first entry!
>> [Feb 20 13:03:16][chn9] CURL Error from middleware: 'UniqueConstraintViolationException': 'An exception occurred while executing 'INSERT INTO data (channel_id, timestamp, value) VALUES (20,?,?)' with params [2147483647000, 16.30000114440918]:
>>
>> SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate
>>
>> ------- end snip ----------------
>>
>> In der Datenbank gibt es einen Eintrag dazu:
>>
>> MariaDB [volkszaehler]> select * from data where channel_id = 20;
>> +---------------+------------+-----------------+
>> | timestamp | channel_id | value |
>> +---------------+------------+-----------------+
>> | 2147483647000 | 20 | 16.300001144409 |
>> +---------------+------------+-----------------+
>> 1 row in set (0.014 sec)
>>
>> Den Timestamp kann ich nicht wirklich nachvollziehen. Wenn ich das Python-Script starte, erhalte ich nachfolgendes. Temperatur ist plausibel, da zwischen Start von vzlogger bzw der Eintrag im Log und dem manuellen Aufruf des Scripts mehr als 10 Minuten vergangen sind:
>>
>> /usr/local/bin/solaredge.py
>> 1645359321779: Battery1_Temperature = 16.899999618530273
>> 1645359321779: Battery1_SOE = 9.0
>>
>> Bemerkenswert ist auch, das nur ein Eintrag drin ist und kein Eintrag für den State of Energie. Vielleicht hängt das mit einer aggressiven Wahl von dem Parameter "duplicates" zusammen.
>>
>> Danke und Gruß
>>
>> Tilman
>>
>>
>>
>>
>>
>>
>>> On 20.02.22 12:57, Tilman Glötzner wrote:
>>> Hallo Maik
>>>
>>> Klar kann ich die posten. Der Aufruf des Python-scripts mittels exec ist ganz unten und auskommentiert. Ich probiere jetzt gleich den Hinweis von Daniel bezüglich der Rechte von /var/log/vzlogger.log aus -- vielleicht hat das auch einen Einfluss auf den Aufruf des Python-Scripts.
>>>
>>>
>>> Gruß
>>>
>>> Tilman
>>>
>>> pi:~ $ cat /etc/vzlogger.conf
>>> {
>>> "retry" : 3,
>>> "daemon": true,
>>> "verbosity" : 3,
>>> "log" : "/var/log/vzlogger.log",
>>>
>>> "local" : {
>>> "enabled" : false,
>>> "port" : 8080,
>>> "index" : true,
>>> "timeout" : 30,
>>> "buffer" : 600
>>> },
>>>
>>> "meters" : [
>>> {
>>> "enabled" : true,
>>> "device" : "/dev/ttyUSB0",
>>> "protocol" : "sml",
>>> "parity" : "8N1",
>>> "baudrate" : 9600,
>>> "aggtime" : 60,
>>> "aggfixedinterval" : true,
>>> "channels": [{
>>> "uuid" : "aa7aa260-9d5f-11eb-9ee7-8354e1848012",
>>> "middleware" : "http://localhost/middleware.php",
>>> "identifier" : "1-0:2.8.0", /* energy provided to grid */
>>> "aggmode" : "MAX"
>>> }, {
>>> "uuid" : "e6981cd0-9d5d-11eb-ae08-3bff1417be58",
>>> "middleware" : "http://localhost/middleware.php",
>>> "identifier" : "1-0:1.8.0", /* energy taken from grid */
>>> "aggmode" : "MAX"
>>> }, {
>>> "uuid" : "8611bb00-ab89-11eb-a169-25b5fbc43e2c",
>>> "middleware" : "http://localhost/middleware.php",
>>> "identifier" : "1-0:16.7.0", /* Leistung */
>>> "aggmode" : "none"
>>> }]
>>> },
>>> {
>>> "enabled": true,
>>> "allowskip": false,
>>> "interval": -1,
>>> "aggtime": 60,
>>> "aggfixedinterval": false,
>>> "channels": [{
>>> "uuid": "4d1483b0-d75a-11eb-af5d-4d208cf02964",
>>> "identifier": "Impulse",
>>> "api": "volkszaehler",
>>> "middleware": "http://localhost/middleware.php",
>>> "aggmode": "sum",
>>> "duplicates": 0
>>> }],
>>> "protocol": "s0",
>>> "gpio": 4,
>>> "configureGPIO": true,
>>> "debounce_delay": 0,
>>> "resolution": 1000
>>> },
>>> {
>>> "enabled": true,
>>> "allowskip": false,
>>> "interval": -1,
>>> "aggtime": 60,
>>> "aggfixedinterval": false,
>>> "channels": [{
>>> "uuid": "418ddf40-d802-11eb-b35f-5da471488f6e",
>>> "identifier": "Impulse",
>>> "api": "volkszaehler",
>>> "middleware": "http://localhost/middleware.php",
>>> "aggmode": "sum",
>>> "duplicates": 0
>>> }],
>>> "protocol": "s0",
>>> "gpio": 14,
>>> "configureGPIO": true,
>>> "debounce_delay": 0,
>>> "resolution": 1000
>>> },
>>> {
>>> "enabled": true,
>>> "allowskip": false,
>>> "interval": -1,
>>> "aggtime": 60,
>>> "aggfixedinterval": false,
>>> "channels": [{
>>> "uuid": "1f87bb00-d7d7-11eb-9970-fb2bc024173c",
>>> "identifier": "Impulse",
>>> "api": "volkszaehler",
>>> "middleware": "http://localhost/middleware.php",
>>> "aggmode": "sum",
>>> "duplicates": 0
>>> }],
>>> "protocol": "s0",
>>> "gpio": 15,
>>> "configureGPIO": true,
>>> "debounce_delay": 0,
>>> "resolution": 2000
>>> },
>>> {
>>> "enabled": true,
>>> "allowskip": false,
>>> "interval": -1,
>>> "aggtime": 60,
>>> "aggfixedinterval": false,
>>> "channels": [{
>>> "uuid": "a5989d90-d828-11eb-b73f-9fcefccaa74b",
>>> "identifier": "Impulse",
>>> "api": "volkszaehler",
>>> "middleware": "http://localhost/middleware.php",
>>> "aggmode": "sum",
>>> "duplicates": 0
>>> }],
>>> "protocol": "s0",
>>> "gpio": 17,
>>> "configureGPIO": true,
>>> "debounce_delay": 0,
>>> "resolution": 1000
>>> },
>>> {
>>> "enabled": true,
>>> "allowskip": false,
>>> "interval": -1,
>>> "aggtime": 60,
>>> "aggfixedinterval": false,
>>> "channels": [{
>>> "uuid": "0a2ab800-dd2a-11eb-8cab-375d0acdab21",
>>> "identifier": "Impulse",
>>> "api": "volkszaehler",
>>> "middleware": "http://localhost/middleware.php",
>>> "aggmode": "sum",
>>> "duplicates": 0
>>> }],
>>> "protocol": "s0",
>>> "gpio": 18,
>>> "configureGPIO": true,
>>> "debounce_delay": 30,
>>> "resolution": 200,
>>> "nonblocking_delay": 100000
>>> }
>>> /*,
>>> {
>>> // pv inverter via modbus on tcp an python script
>>> "enabled": true,
>>> "allowskip": true,
>>> "protocol": "exec",
>>> "command": "solaredge.py",
>>> "format": "$t: $i = $v",
>>> "channels": [{
>>> "uuid": "0a2ab800-dd2a-11eb-8cab-375d0acdab22",
>>> "identifier": "Battery1_SOE",
>>> "api": "volkszaehler",
>>> "middleware": "http://localhost/middleware.php",
>>> "aggmode": "none",
>>> "duplicates": 14400
>>> },
>>> {
>>> "uuid": "d55f9f40-91e2-11ec-adc5-c55c95f1d814",
>>> "identifier": "Battery1_Temperature",
>>> "api": "volkszaehler",
>>> "middleware": "http://localhost/middleware.php",
>>> "aggmode": "none",
>>> "duplicates": 14400
>>> }]
>>> }
>>> */
>>> ]
>>> }
>>>
>>>> On 20.02.22 12:10, Maik Weidemann wrote:
>>>> Hi Tilmann,
>>>>
>>>>
>>>>> 'UniqueConstraintViolationException': 'An exception occurred while executing 'INSERT INTO data (channel_id, timestamp, value) VALUES (5,?,?)' with params [1645320720000, 2171064]:
>>>> Die Fehlermeldung sagt, dass du einen Wert oder Werte-Paar doppelt in die DB eintragen möchtest du das ist nicht erlaubt, da dieser Wert / Werte-Paar nur einmal in der Datenbank vorkommen darf.
>>>>
>>>> Kannst du mal deine ganze Konfig posten? Das Problem hängt ggf. damit zusammen, dass etwas im "neuen" und "alten" Bereich deiner Konfiguration nicht passt.
>>>>
>>>> Gruß
>>>> Maik
>>>>
>>>>
>>>>
>>>> Am 20.02.22 um 03:18 schrieb Tilman Glötzner:
>>>>> Hallo nochmal,
>>>>>
>>>>> ich habe herausgefunden, dass das erste Problem mit dem zweiten zusammenhängt. Wenn ich den Aufruf des Pythonscripts entferne, kömmen keine Fehlermeldungen "Middleware says duplicate value" mehr. Hier deswegen der Teil der Konfig, den ich auskommentiert habe und das Script:
>>>>>
>>>>> ========== /etc/vzlogger.conf ==========
>>>>>
>>>>> /*,
>>>>> {
>>>>> // pv inverter via modbus on tcp an python script
>>>>> "enabled": true,
>>>>> "allowskip": true,
>>>>> "protocol": "exec",
>>>>> "command": "solaredge.py",
>>>>> "format": "$t: $i = $v",
>>>>> "channels": [{
>>>>> "uuid": "0a2ab800-dd2a-11eb-8cab-375d0acdab22",
>>>>> "identifier": "Battery1_SOE",
>>>>> "api": "volkszaehler",
>>>>> "middleware": "http://localhost/middleware.php",
>>>>> "aggmode": "none",
>>>>> "duplicates": 14400
>>>>> },
>>>>> {
>>>>> "uuid": "d55f9f40-91e2-11ec-adc5-c55c95f1d814",
>>>>> "identifier": "Battery1_Temperature",
>>>>> "api": "volkszaehler",
>>>>> "middleware": "http://localhost/middleware.php",
>>>>> "aggmode": "none",
>>>>> "duplicates": 14400
>>>>> }]
>>>>> }
>>>>> */
>>>>> ========END /etc/vzlogger.conf ==========
>>>>>
>>>>> ======== /usr/local/bin/solaredge.py ========
>>>>>
>>>>> !/usr/bin/python3
>>>>> import solaredge_modbus
>>>>> import datetime
>>>>>
>>>>> inverter = solaredge_modbus.Inverter(host="se7rws.fritz.box", port=1502)
>>>>> battery1 = inverter.batteries()["Battery1"]
>>>>> meter1 = solaredge_modbus.Meter(parent=inverter, offset=0)
>>>>>
>>>>> inverter.connect()
>>>>> if inverter.connected():
>>>>> data0 = inverter.read_all()
>>>>> data1 = battery1.read_all()
>>>>>
>>>>> inverter.disconnect()
>>>>> now = str(int( datetime.datetime.now().timestamp() * 1000 ))
>>>>> soe = str(data1["soe"])
>>>>> temperature = str(data1["average_temperature"])
>>>>> print(now + ': Battery1_Temperature = ' + temperature)
>>>>> print(now + ': Battery1_SOE = ' + str(data1["soe"]))
>>>>>
>>>>> inverter.disconnect()
>>>>>
>>>>> ========END /usr/local/bin/solaredge.py ========
>>>>>
>>>>> Danke und viele Grüße
>>>>>
>>>>> Tilman
>>>>>
>>>>> On 20.02.22 02:45, Tilman Glötzner wrote:
>>>>>> Hallo
>>>>>>
>>>>>> 1) in /var/log/vzlogger.log finde ich nach einen restart des vzlogger viele Message mit unterschiedlichen ChannelIDs wie folgt. Was will mir das Log sagen?
>>>>>>
>>>>>> SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry '
>>>>>> [Feb 20 02:33:30][chn1] Middleware says duplicated value. Removing first entry!
>>>>>> [Feb 20 02:33:30][chn1] CURL Error from middleware: 'UniqueConstraintViolationException': 'An exception occurred while executing 'INSERT INTO data (channel_id, timestamp, value) VALUES (5,?,?)' with params [1645320720000, 2171064]:
>>>>>>
>>>>>>
>>>>>> 2) Ausserdem habe ich ein Mini-Pythonscript geschrieben, dass mir die Temperature und den Ladezustand der Battery von unserer Solaranlage ausgibt und durch vzlogger (exec) gestartet wird. Die folgende Fehlermeldung scheint sich darauf zu beziehen. Ich habe vzlogger über service logger start vom Benutzeraccount pi gestartet. Das Serviceprogram scheint aber automatisch einen sudo zu starten und fragt nach dem Benutzerpassword.
>>>>>>
>>>>>> Mir ist daher nicht klar, wie ich vzlogger nicht als root starten kann -- zumindest wenn "service" verwendet werden soll.
>>>>>>
>>>>>>
>>>>>> Feb 20 02:25:59][main] vzlogger v0.8.0 based on heads/master-0-gfe937770e4 from Sat, 3 Apr 2021 19:40:20 +0200 started.
>>>>>> [Feb 20 02:25:59][main] log level is 3
>>>>>> [Feb 20 02:25:59][exec] MeterExec::open: MeterExec protocol cannot be run with root privileges!
>>>>>> [Feb 20 02:25:59][exec] If you really want this, compile vzlogger with:
>>>>>> [Feb 20 02:25:59][exec] 'cmake -D METEREXEC_ROOTACCESS=true .'
>>>>>> [Feb 20 02:25:59][mtr6] Cannot open meter
>>>>>> [Feb 20 02:25:59] Skipping meter mtr6
>>>>>> [Feb 20 02:26:22][chn5] Middleware says duplicated value. Removing first entry!
>>>>>> [Feb 20 02:26:22][chn5] CURL Error from middleware: 'UniqueConstraintViolationException': 'An exception occurred while execu
>>>>>> ting 'INSERT INTO data (channel_id, timestamp, value) VALUES (13,?,?)' with params [1645320382057, 1]:
>>>>>>
>>>>>> Danke und Gruß
>>>>>>
>>>>>> Tilman
Mehr Informationen über die Mailingliste volkszaehler-users