[vz-users] Fehlermeldungen in vzlogger.log

Tilman Glötzner tilman_1 at gloetzner.net
So Feb 20 13:21:11 CET 2022


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