[vz-users] Fehlermeldungen in vzlogger.log
Tilman Glötzner
tilman_1 at gloetzner.net
So Feb 20 14:40:30 CET 2022
Hallo Maik
Ich habe die beiden Einträge für Channel 20 und 21 aus der Datenbank
entfernt, das Logfile gelöscht und den Loglevel erhöht.
>Du lieferst ja mit $t den Timestamp aus dem Pyhton-Script mit. Und der
Timestamp ist auch immer unterschiedlich? Im Logfile müssten bei >höhrem
Loglevel die Ausgaben des Python-Scriptes zu sehen sein. Passt das?
Ich denke:
[Feb 20 14:34:11][exec] MeterExec::read: Calling 'solaredge.py'
[Feb 20 14:34:14][exec] MeterExec::read: Reading line: '1645364054138:
Battery1_Temperature = 16.399999618530273'
[Feb 20 14:34:14][exec] MeterExec::read: string: Battery1_Temperature,
value: 16.400000, timestamp: 1645364054138.000000
[Feb 20 14:34:14][exec] MeterExec::read: Reading line: '1645364054138:
Battery1_SOE = 15.0'
[Feb 20 14:34:14][exec] MeterExec::read: string: Battery1_SOE, value:
15.000000, timestamp: 1645364054138.000000
[Feb 20 14:34:14][exec] MeterExec::read: Closing process 'solaredge.py'
[Feb 20 14:34:29][exec] MeterExec::read: Calling 'solaredge.py'
[Feb 20 14:34:31][exec] MeterExec::read: Reading line: '1645364071822:
Battery1_Temperature = 16.399999618530273'
[Feb 20 14:34:31][exec] MeterExec::read: string: Battery1_Temperature,
value: 16.400000, timestamp: 1645364071822.000000
[Feb 20 14:34:31][exec] MeterExec::read: Reading line: '1645364071822:
Battery1_SOE = 15.0'
[Feb 20 14:34:31][exec] MeterExec::read: string: Battery1_SOE, value:
15.000000, timestamp: 1645364071822.000000
[Feb 20 14:34:32][exec] MeterExec::read: Closing process 'solaredge.py'
[Feb 20 14:34:47][exec] MeterExec::read: Calling 'solaredge.py'
[Feb 20 14:34:51][exec] MeterExec::read: Reading line: '1645364091269:
Battery1_Temperature = 16.399999618530273'
[Feb 20 14:34:51][exec] MeterExec::read: string: Battery1_Temperature,
value: 16.400000, timestamp: 1645364091269.000000
[Feb 20 14:34:51][exec] MeterExec::read: Reading line: '1645364091269:
Battery1_SOE = 15.0'
[Feb 20 14:34:51][exec] MeterExec::read: string: Battery1_SOE, value:
15.000000, timestamp: 1645364091269.000000
[Feb 20 14:34:51][exec] MeterExec::read: Closing process 'solaredge.py'
[Feb 20 14:35:06][exec] MeterExec::read: Calling 'solaredge.py'
[Feb 20 14:35:09][exec] MeterExec::read: Reading line: '1645364109509:
Battery1_Temperature = 16.399999618530273'
[Feb 20 14:35:09][exec] MeterExec::read: string: Battery1_Temperature,
value: 16.400000, timestamp: 1645364109509.000000
[Feb 20 14:35:09][exec] MeterExec::read: Reading line: '1645364109509:
Battery1_SOE = 15.0'
[Feb 20 14:35:09][exec] MeterExec::read: string: Battery1_SOE, value:
15.000000, timestamp: 1645364109509.000000
[Feb 20 14:35:09][exec] MeterExec::read: Closing process 'solaredge.py'
[Feb 20 14:35:24][exec] MeterExec::read: Calling 'solaredge.py'
[Feb 20 14:35:27][exec] MeterExec::read: Reading line: '1645364127057:
Battery1_Temperature = 16.399999618530273'
[Feb 20 14:35:27][exec] MeterExec::read: string: Battery1_Temperature,
value: 16.400000, timestamp: 1645364127057.000000
[Feb 20 14:35:27][exec] MeterExec::read: Reading line: '1645364127057:
Battery1_SOE = 15.0'
[Feb 20 14:35:27][exec] MeterExec::read: string: Battery1_SOE, value:
15.000000, timestamp: 1645364127057.000000
[Feb 20 14:35:27][exec] MeterExec::read: Closing process 'solaredge.py'
[Feb 20 14:35:42][exec] MeterExec::read: Calling 'solaredge.py'
> Interessant ist, dass die beiden Einträge nun wieder in der Datenbank
sind. Das legt nahe, dass es beim Interpretieren der übergebenen Werte
aus dem Python-Script schief geht
MariaDB [volkszaehler]> select * from data where channel_id = 20;
+---------------+------------+----------------+
| timestamp | channel_id | value |
+---------------+------------+----------------+
| 2147483647000 | 20 | 16.39999961853 |
+---------------+------------+----------------+
1 row in set (0.012 sec)
MariaDB [volkszaehler]> select * from data where channel_id = 21;
+---------------+------------+-------+
| timestamp | channel_id | value |
+---------------+------------+-------+
| 2147483647000 | 21 | 15 |
+---------------+------------+-------+
1 row in set (0.013 sec)
>Überigens benutzt VZ nicht den Standard-Unix-Timestamp, der in
Sekunden ist, sondern einen Timestamp in Milisekunden.
Das berücksichtige ich durch die Multiplication des Timestamps mit 1000:
now = str(int( datetime.datetime.now().timestamp() * 1000 ))
> "enabled": true,
>Statt den JSON-Teil auszukommentieren, kannst du einfach enable auf
false setzten. Das JSON ist ja wohl nicht das Problem.
Stimmt, mache ich das nächste Mal. Danke für den Hinweis.
Gruß
Tilman
On 20.02.22 14:22, Maik Weidemann wrote:
> Hallo Tilman,
>
>> "protocol": "exec",
>> "command": "solaredge.py",
>> "format": "$t: $i = $v",
> Du lieferst ja mit $t den Timestamp aus dem Pyhton-Script mit. Und der
> Timestamp ist auch immer unterschiedlich? Im Logfile müssten bei
> höhrem Loglevel die Ausgaben des Python-Scriptes zu sehen sein. Passt
> das?
>
> In der Datenbank hat die Daten-Tabelle nämlich die Regel, dass es nur
> einen Eintrag je (Zeitstempel und Kanal) geben darf. Wenn du nun für
> einen Kanal einen neuen Datenpunkt hinzufügen möchtest und dabei einen
> schon verwendeten Zeitstempel verwendet, kommt deine Fehlermeldung:
> 'UniqueConstraintViolationException'
>
>
> Überigens benutzt VZ nicht den Standard-Unix-Timestamp, der in
> Sekunden ist, sondern einen Timestamp in Milisekunden.
>
>
>> "enabled": true,
> Statt den JSON-Teil auszukommentieren, kannst du einfach enable auf
> false setzten. Das JSON ist ja wohl nicht das Problem.
>
>
> Gruß
> Maik
>
>
>
> Am 20.02.22 um 12:57 schrieb Tilman Glötzner:
>> 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