Moin in die Runde!
Ich hoffe, ich bin in diesem Unterforum richtig, sonst gern einen Hinweis.
Gefühlt seit der Umstellung von dblog auf Subprozess (das war Anfang Dezember?) brauchen meine SVGs rund 20 Sekunden zum Anzeigen. Sie kommen dann korrekt und zeigen richtige Werte an.
Dabei ist es egal, ob 1 SVG mit 2 Diagrammen oder 3 mit 12 Werte-Linien aufgerufen werden. :-\
attr WEB plotembed steht auf 2. Änderungen bringen keine Verbesserungen.
FHEM läuft im Docker Container auf einem Synology NAS.
dblog sichert in eine Maria DB auf demselben NAS.
Das NAS sollte mit 20 MB und Intel CPU reichlich Performance haben und zeigt an keiner anderen Stelle Auffälligkeiten.
FHEM ist aktuell ... Container ist aktuell (fhem/fhem latest)
Im Log sehe ich keine Einträge rund um das Aufrufen der SVGs. Rund um dbLog sehr sporadisch:
2023.01.06 01:00:00 3: DbLog logdb - addLog created - TS: 2023-01-06 01:00:00, Device: rr_Emilia, Type: ROOMMATE, Event: addLog, Reading: state, Value: home, Unit:
2023.01.06 01:07:47 2: DbLog logdb - Error: Can't call method "prepare" on unblessed reference at ./FHEM/93_DbLog.pm line 4240.
2023.01.06 01:07:47 2: SubProcess: onRun returned error: Can't call method "disconnect" on unblessed reference at ./FHEM/93_DbLog.pm line 2937.
2023.01.06 01:07:47 1: DbLog logdb - SubProcess EXITED!
2023.01.06 01:07:57 2: DbLog logdb - Subprocess >25978< initialized ... ready for non-blocking operation
2023.01.06 01:07:57 3: DbLog logdb - requested DB connection parameters are transmitted
2023.01.06 01:07:57 3: DbLog logdb - DB connection parameters are stored in SubProcess
2023.01.06 01:09:17 3: DbLog logdb - SubProcess connected to fhem
2023.01.06 02:00:00 3: DbLog logdb - addLog created - TS: 2023-01-06 02:00:00, Device: rr_Stefan, Type: ROOMMATE, Event: addLog, Reading: state, Value: home, Unit:
Irgendwelche Ideen?
Danke :)
ZitatGefühlt seit der Umstellung von dblog auf Subprozess (das war Anfang Dezember?) brauchen meine SVGs rund 20 Sekunden zum Anzeigen.
Das spricht dafuer, dass dieses Unterforum der Falsche ist.
Wie lange dauert es, wenn man in der Detailansicht "Show Preprocessed Input" anklickt?
Hallo Rudolf,
das Verhalten mit ,,Show preprocessed ..." ist identisch.
Ich denke nicht dass es an den SVG oder DbLog Modulen liegt, sondern tiefer. Die Fehler bzgl. Unblessed referenz habe ich bisher in dem Kontext noch nicht erlebt.
Setzt mal verbose 4 im dblog und rufe ein svg auf.
Dann poste den logausschnitt.
Und auch das attr showproctime wäre hilfreich um die performance deiner db einschätzen zu können.
... und poste doch mal den Output von
set logdb configCheck
set logdb configCheck rödelt ewig und bricht ab.
Log vom Aufruf eines einzelnen SVGs (Editor-Seite).
Auffällig ist, dass es nach dem Klick 20 Sekunden dauert, bis die Seite angezeigt wird und dann noch mal 20 Sekunden, bis das Diagramm angezeigt wird.
Alle anderen Seiten ohne SVG verhalten sich normal / sind sehr schnell.
2023.01.06 13:38:20 4: DbLog logdb - ################################################################
2023.01.06 13:38:20 4: DbLog logdb - ### new get data for SVG ###
2023.01.06 13:38:20 4: DbLog logdb - ################################################################
2023.01.06 13:38:20 4: DbLog logdb - main PID: 7424, secondary PID: 3335
2023.01.06 13:38:40 4: logdb - PID: 3335, Processing Statement:
SELECT
DATE_FORMAT(TIMESTAMP, '%Y-%m-%d %H:%i:%s'),
DEVICE,
READING,
VALUE
FROM history WHERE 1=1 AND DEVICE = 'gTagKerstin' AND READING = 'state' AND TIMESTAMP >= STR_TO_DATE('2023-01-06 00:00:00', '%Y-%m-%d %H:%i:%s') AND TIMESTAMP <= STR_TO_DATE('2023-01-07 00:00:00', '%Y-%m-%d %H:%i:%s') ORDER BY TIMESTAMP
2023.01.06 13:38:40 4: logdb - PID: 3335, rows count: 3
2023.01.06 13:38:40 4: logdb - PID: 3335, Processing Statement:
SELECT
DATE_FORMAT(TIMESTAMP, '%Y-%m-%d %H:%i:%s'),
DEVICE,
READING,
VALUE
FROM history WHERE 1=1 AND DEVICE = 'rr_Kerstin' AND READING = 'state' AND TIMESTAMP >= STR_TO_DATE('2023-01-06 00:00:00', '%Y-%m-%d %H:%i:%s') AND TIMESTAMP <= STR_TO_DATE('2023-01-07 00:00:00', '%Y-%m-%d %H:%i:%s') ORDER BY TIMESTAMP
2023.01.06 13:38:40 4: logdb - PID: 3335, rows count: 14
2023.01.06 13:38:40 4: logdb - PID: 3335, Processing Statement:
SELECT
DATE_FORMAT(TIMESTAMP, '%Y-%m-%d %H:%i:%s'),
DEVICE,
READING,
VALUE
FROM history WHERE 1=1 AND DEVICE = 'gTagEmilia' AND READING = 'state' AND TIMESTAMP >= STR_TO_DATE('2023-01-06 00:00:00', '%Y-%m-%d %H:%i:%s') AND TIMESTAMP <= STR_TO_DATE('2023-01-07 00:00:00', '%Y-%m-%d %H:%i:%s') ORDER BY TIMESTAMP
2023.01.06 13:38:40 4: logdb - PID: 3335, rows count: 4
2023.01.06 13:38:40 4: logdb - PID: 3335, Processing Statement:
SELECT
DATE_FORMAT(TIMESTAMP, '%Y-%m-%d %H:%i:%s'),
DEVICE,
READING,
VALUE
FROM history WHERE 1=1 AND DEVICE = 'rr_Emilia' AND READING = 'state' AND TIMESTAMP >= STR_TO_DATE('2023-01-06 00:00:00', '%Y-%m-%d %H:%i:%s') AND TIMESTAMP <= STR_TO_DATE('2023-01-07 00:00:00', '%Y-%m-%d %H:%i:%s') ORDER BY TIMESTAMP
2023.01.06 13:38:40 4: logdb - PID: 3335, rows count: 14
Ist das alles was nach dem select kommt ?
Wenn schon configcheck ewig braucht, stimmt mit deiner db grundsätzlich etwas nicht.
Was sagen denn die readings sql_processing_time und background_processing_time ?
Ich gehe blind davon aus dass deine db grottenlangsam ist.
Das muss erstmal gerichtet werden und hat nichts mit SVG oder DbLog an sich zu tun.
Wahrscheinlich muss man hier ein break machen und das Thema in einem Serverthread behandeln.
Evtl. Verbose 5 noch einstellen, aber ich ahne das Ergebnis.
Dass die DB grundsätzlich "grottenlahm" ist, kann ich ausschließen. Da liegen noch andere, viel größere Datenbanken (u.a. digikam mit >100.000 Fotos) drauf und arbeitet mehr als angemessen schnell. Liegt auf dem NAS auf einer SSD.
Für mich sieht das nach irgendeinem Timeout aus. Ist ja auffällig, dass es sehr konstant 20 Sekunden sind, egal wieviele Daten abgerufen werden.
dblog hat bei mir nicht die genannten readings:
Internals:
COLUMNS field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32
CONFIGURATION ./db.conf
DEF ./db.conf .*:(1.ACTUAL_TEMPERATURE|1.HUMIDITY).*
FD 5
FUUID 5ff78651-f33f-d7f8-4c3f-689a9e08ff48d5d8
FVERSION 93_DbLog.pm:v5.5.9-s26923/2022-12-29
MODE asynchronous
MODEL MYSQL
NAME logdb
NR 2
NTFY_ORDER 50-logdb
PID 7424
REGEXP .*:(1.ACTUAL_TEMPERATURE|1.HUMIDITY).*
SBP_PID 7425
SBP_STATE running
STATE connected
TYPE DbLog
UTF8 1
dbconn mysql:database=fhem;host=192.168.178.2;port=3306
dbuser fhem
eventCount 147
HELPER:
COLSET 1
DEVICECOL 64
EVENTCOL 512
OLDSTATE connected
PACKAGE main
READINGCOL 64
TC current
TH history
TYPECOL 64
UNITCOL 32
VALUECOL 128
VERSION 5.5.9
OLDREADINGS:
READINGS:
2023-01-06 17:43:11 CacheOverflowLastNum 0
2022-01-28 09:41:23 CacheOverflowLastState normal
2023-01-06 17:43:56 CacheUsage 3
2023-01-06 17:43:41 NextSync 2023-01-06 17:44:11 or when CacheUsage 500 is reached
2023-01-06 17:43:41 state connected
hmccu:
Attributes:
DbLogSelectionMode Include
asyncMode 1
room Zentral->Zentral
verbose 4
Wo finde ich sie?
Verbose 5 liefert (Klick auf SVG-Seite um 17:48:00 / Editor um 17:48:20 da / Diagramm um 17:48:41:
2023.01.06 17:47:56 4: DbLog logdb - check Device: d_Msg_HeizungStatusOn , Event: state: on
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: d_Msg_HeizungStatusOn , Event: state: on
2023.01.06 17:47:56 4: DbLog logdb - ################################################################
2023.01.06 17:47:56 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:47:56 4: DbLog logdb - ################################################################
2023.01.06 17:47:56 4: DbLog logdb - number of events received: 20 of device: arbeitszimmer_Heizung_HMIP
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: 1.ACTUAL_TEMPERATURE_STATUS: NORMAL
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: 1.ACTUAL_TEMPERATURE_STATUS: NORMAL
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: valve_position: 15
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: valve_position: 15
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: 1.BOOST_MODE: false
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: 1.BOOST_MODE: false
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: 1.WINDOW_STATE: Closed
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: 1.WINDOW_STATE: Closed
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: 1.ACTIVE_PROFILE: 1
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: 1.ACTIVE_PROFILE: 1
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: control: 20
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: control: 20
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: temperature_soll: 20
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: temperature_soll: 20
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: 1.SET_POINT_TEMPERATURE: 20
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: 1.SET_POINT_TEMPERATURE: 20
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: desired-temp: 20
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: desired-temp: 20
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: 1.SET_POINT_MODE: auto
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: 1.SET_POINT_MODE: auto
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: 1.LEVEL_STATUS: NORMAL
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: 1.LEVEL_STATUS: NORMAL
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: state: 21
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: state: 21
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: temperature_ist: 21
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: temperature_ist: 21
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: 1.ACTUAL_TEMPERATURE: 21
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: 1.ACTUAL_TEMPERATURE: 21
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: measured-temp: 21
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: measured-temp: 21
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: devstate: ok
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: devstate: ok
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: hmstate: 21
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: hmstate: 21
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: Ist: 20
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: Ist: 20
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: Soll: 20.0
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: Soll: 20.0
2023.01.06 17:47:56 4: DbLog logdb - check Device: arbeitszimmer_Heizung_HMIP , Event: DisplayTemp: 20.0
2023.01.06 17:47:56 5: DbLog logdb - parsed Event: arbeitszimmer_Heizung_HMIP , Event: DisplayTemp: 20.0
2023.01.06 17:48:20 5: DbLog logdb: Table current present : 0 (0 = not present or no content)
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - number of events received: 4 of device: HUESensor11
2023.01.06 17:48:20 4: DbLog logdb - check Device: HUESensor11 , Event: reachable: 1
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: HUESensor11 , Event: reachable: 1
2023.01.06 17:48:20 4: DbLog logdb - check Device: HUESensor11 , Event: temperature: 19.87
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: HUESensor11 , Event: temperature: 19.87
2023.01.06 17:48:20 4: DbLog logdb - check Device: HUESensor11 , Event: batteryPercent: 26
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: HUESensor11 , Event: batteryPercent: 26
2023.01.06 17:48:20 4: DbLog logdb - check Device: HUESensor11 , Event: battery: 26
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: HUESensor11 , Event: battery: 26
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - number of events received: 3 of device: hueBewegungKueche2
2023.01.06 17:48:20 4: DbLog logdb - check Device: hueBewegungKueche2 , Event: reachable: 1
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: hueBewegungKueche2 , Event: reachable: 1
2023.01.06 17:48:20 5: DbLog logdb - DbLogInclude of "hueBewegungKueche2": state
2023.01.06 17:48:20 4: DbLog logdb - check Device: hueBewegungKueche2 , Event: battery: 26
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: hueBewegungKueche2 , Event: battery: 26
2023.01.06 17:48:20 5: DbLog logdb - DbLogInclude of "hueBewegungKueche2": state
2023.01.06 17:48:20 4: DbLog logdb - check Device: hueBewegungKueche2 , Event: batteryPercent: 26
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: hueBewegungKueche2 , Event: batteryPercent: 26
2023.01.06 17:48:20 5: DbLog logdb - DbLogInclude of "hueBewegungKueche2": state
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - number of events received: 1 of device: aussenfuehler_hum_dummy
2023.01.06 17:48:20 4: DbLog logdb - check Device: aussenfuehler_hum_dummy , Event: state: 1
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: aussenfuehler_hum_dummy , Event: state: 1
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - number of events received: 1 of device: aktualisiere_dummy_hum
2023.01.06 17:48:20 4: DbLog logdb - check Device: aktualisiere_dummy_hum , Event: state: Next: 17:49:15
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: aktualisiere_dummy_hum , Event: state: Next: 17:49:15
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - number of events received: 1 of device: Sonos
2023.01.06 17:48:20 4: DbLog logdb - check Device: Sonos , Event: LastProcessAnswer: 1673023700.36291
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: Sonos , Event: LastProcessAnswer: 1673023700.36291
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - number of events received: 4 of device: d_Heizung_Kueche_Status
2023.01.06 17:48:20 4: DbLog logdb - check Device: d_Heizung_Kueche_Status , Event: cmd_nr: 1
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: d_Heizung_Kueche_Status , Event: cmd_nr: 1
2023.01.06 17:48:20 4: DbLog logdb - check Device: d_Heizung_Kueche_Status , Event: cmd: 1
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: d_Heizung_Kueche_Status , Event: cmd: 1
2023.01.06 17:48:20 4: DbLog logdb - check Device: d_Heizung_Kueche_Status , Event: cmd_event: kueche_Heizung_HMIP
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: d_Heizung_Kueche_Status , Event: cmd_event: kueche_Heizung_HMIP
2023.01.06 17:48:20 4: DbLog logdb - check Device: d_Heizung_Kueche_Status , Event: state: cmd_1
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: d_Heizung_Kueche_Status , Event: state: cmd_1
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - number of events received: 23 of device: kueche_Heizung_HMIP
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: rssidevice: -79
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: rssidevice: -79
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: voltage: 2.5
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: voltage: 2.5
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: battery: ok
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: battery: ok
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: activity: alive
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: activity: alive
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: state: 22.3
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: state: 22.3
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: temperature_ist: 22.3
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: temperature_ist: 22.3
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: 1.ACTUAL_TEMPERATURE: 22.3
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: 1.ACTUAL_TEMPERATURE: 22.3
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: measured-temp: 22.3
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: measured-temp: 22.3
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: 1.LEVEL_STATUS: NORMAL
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: 1.LEVEL_STATUS: NORMAL
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: 1.SET_POINT_MODE: auto
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: 1.SET_POINT_MODE: auto
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: control: 20
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: control: 20
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: temperature_soll: 20
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: temperature_soll: 20
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: 1.SET_POINT_TEMPERATURE: 20
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: 1.SET_POINT_TEMPERATURE: 20
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: desired-temp: 20
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: desired-temp: 20
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: 1.WINDOW_STATE: Closed
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: 1.WINDOW_STATE: Closed
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: 1.BOOST_MODE: false
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: 1.BOOST_MODE: false
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: 1.ACTUAL_TEMPERATURE_STATUS: NORMAL
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: 1.ACTUAL_TEMPERATURE_STATUS: NORMAL
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: valve_position: 0
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: valve_position: 0
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: devstate: ok
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: devstate: ok
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: hmstate: 22.3
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: hmstate: 22.3
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: Ist: 21.3
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: Ist: 21.3
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: Soll: 20.0
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: Soll: 20.0
2023.01.06 17:48:20 4: DbLog logdb - check Device: kueche_Heizung_HMIP , Event: DisplayTemp: 21.3
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: kueche_Heizung_HMIP , Event: DisplayTemp: 21.3
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - number of events received: 1 of device: deC_Rollo_Arbeitszimmer
2023.01.06 17:48:20 4: DbLog logdb - check Device: deC_Rollo_Arbeitszimmer , Event: state: off
2023.01.06 17:48:20 5: DbLog logdb - parsed Event: deC_Rollo_Arbeitszimmer , Event: state: off
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - ### new get data for SVG ###
2023.01.06 17:48:20 4: DbLog logdb - ################################################################
2023.01.06 17:48:20 4: DbLog logdb - main PID: 7424, secondary PID: 5720
2023.01.06 17:48:22 4: DbLog logdb - ################################################################
2023.01.06 17:48:22 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:22 4: DbLog logdb - ################################################################
2023.01.06 17:48:22 4: DbLog logdb - number of events received: 1 of device: hueBewegungKueche2
2023.01.06 17:48:22 4: DbLog logdb - check Device: hueBewegungKueche2 , Event: state: motion
2023.01.06 17:48:22 5: DbLog logdb - parsed Event: hueBewegungKueche2 , Event: state: motion
2023.01.06 17:48:22 5: DbLog logdb - DbLogInclude of "hueBewegungKueche2": state
2023.01.06 17:48:22 4: DbLog logdb - added event - Timestamp: 2023-01-06 17:48:22, Device: hueBewegungKueche2, Type: HUEDEVICE, Event: state: motion, Reading: state, Value: motion, Unit:
2023.01.06 17:48:29 4: DbLog logdb - ################################################################
2023.01.06 17:48:29 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:29 4: DbLog logdb - ################################################################
2023.01.06 17:48:29 4: DbLog logdb - number of events received: 4 of device: bad_Sensor
2023.01.06 17:48:29 4: DbLog logdb - check Device: bad_Sensor , Event: activity: alive
2023.01.06 17:48:29 5: DbLog logdb - parsed Event: bad_Sensor , Event: activity: alive
2023.01.06 17:48:29 4: DbLog logdb - check Device: bad_Sensor , Event: rssidevice: -66
2023.01.06 17:48:29 5: DbLog logdb - parsed Event: bad_Sensor , Event: rssidevice: -66
2023.01.06 17:48:29 4: DbLog logdb - check Device: bad_Sensor , Event: devstate: updPending
2023.01.06 17:48:29 5: DbLog logdb - parsed Event: bad_Sensor , Event: devstate: updPending
2023.01.06 17:48:29 4: DbLog logdb - check Device: bad_Sensor , Event: hmstate: 20.9
2023.01.06 17:48:29 5: DbLog logdb - parsed Event: bad_Sensor , Event: hmstate: 20.9
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - number of events received: 1 of device: deC_Gruppe_SchreibtischStefan
2023.01.06 17:48:30 4: DbLog logdb - check Device: deC_Gruppe_SchreibtischStefan , Event: state: on
2023.01.06 17:48:30 5: DbLog logdb - parsed Event: deC_Gruppe_SchreibtischStefan , Event: state: on
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - number of events received: 1 of device: deconz_HUEDevice6
2023.01.06 17:48:30 4: DbLog logdb - check Device: deconz_HUEDevice6 , Event: lastseen: 2023-01-06T16:47Z
2023.01.06 17:48:30 5: DbLog logdb - parsed Event: deconz_HUEDevice6 , Event: lastseen: 2023-01-06T16:47Z
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - number of events received: 2 of device: deC_Rollo_Schlafzimmer
2023.01.06 17:48:30 4: DbLog logdb - check Device: deC_Rollo_Schlafzimmer , Event: lastseen: 2023-01-06T16:45Z
2023.01.06 17:48:30 5: DbLog logdb - parsed Event: deC_Rollo_Schlafzimmer , Event: lastseen: 2023-01-06T16:45Z
2023.01.06 17:48:30 4: DbLog logdb - check Device: deC_Rollo_Schlafzimmer , Event: state: off
2023.01.06 17:48:30 5: DbLog logdb - parsed Event: deC_Rollo_Schlafzimmer , Event: state: off
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - number of events received: 1 of device: deconz_HUEDevice9
2023.01.06 17:48:30 4: DbLog logdb - check Device: deconz_HUEDevice9 , Event: lastseen: 2023-01-06T16:48Z
2023.01.06 17:48:30 5: DbLog logdb - parsed Event: deconz_HUEDevice9 , Event: lastseen: 2023-01-06T16:48Z
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - number of events received: 1 of device: deC_ScannerStefan
2023.01.06 17:48:30 4: DbLog logdb - check Device: deC_ScannerStefan , Event: lastseen: 2023-01-06T16:48Z
2023.01.06 17:48:30 5: DbLog logdb - parsed Event: deC_ScannerStefan , Event: lastseen: 2023-01-06T16:48Z
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - number of events received: 2 of device: deC_Rollo_Kueche
2023.01.06 17:48:30 4: DbLog logdb - check Device: deC_Rollo_Kueche , Event: lastseen: 2023-01-06T16:45Z
2023.01.06 17:48:30 5: DbLog logdb - parsed Event: deC_Rollo_Kueche , Event: lastseen: 2023-01-06T16:45Z
2023.01.06 17:48:30 4: DbLog logdb - check Device: deC_Rollo_Kueche , Event: state: dim06%
2023.01.06 17:48:30 5: DbLog logdb - parsed Event: deC_Rollo_Kueche , Event: state: dim06%
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - number of events received: 1 of device: deconz_HUEDevice4
2023.01.06 17:48:30 4: DbLog logdb - check Device: deconz_HUEDevice4 , Event: lastseen: 2023-01-06T16:47Z
2023.01.06 17:48:30 5: DbLog logdb - parsed Event: deconz_HUEDevice4 , Event: lastseen: 2023-01-06T16:47Z
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - number of events received: 2 of device: deC_Rollo_Arbeitszimmer
2023.01.06 17:48:30 4: DbLog logdb - check Device: deC_Rollo_Arbeitszimmer , Event: lastseen: 2023-01-06T16:48Z
2023.01.06 17:48:30 5: DbLog logdb - parsed Event: deC_Rollo_Arbeitszimmer , Event: lastseen: 2023-01-06T16:48Z
2023.01.06 17:48:30 4: DbLog logdb - check Device: deC_Rollo_Arbeitszimmer , Event: state: off
2023.01.06 17:48:30 5: DbLog logdb - parsed Event: deC_Rollo_Arbeitszimmer , Event: state: off
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:30 4: DbLog logdb - ################################################################
2023.01.06 17:48:30 4: DbLog logdb - number of events received: 1 of device: deC_LautsprecherStefan
2023.01.06 17:48:30 4: DbLog logdb - check Device: deC_LautsprecherStefan , Event: lastseen: 2023-01-06T16:48Z
2023.01.06 17:48:30 5: DbLog logdb - parsed Event: deC_LautsprecherStefan , Event: lastseen: 2023-01-06T16:48Z
2023.01.06 17:48:36 4: DbLog logdb - ################################################################
2023.01.06 17:48:36 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:36 4: DbLog logdb - ################################################################
2023.01.06 17:48:36 4: DbLog logdb - number of events received: 1 of device: hueBewegungKueche2
2023.01.06 17:48:36 4: DbLog logdb - check Device: hueBewegungKueche2 , Event: state: nomotion
2023.01.06 17:48:36 5: DbLog logdb - parsed Event: hueBewegungKueche2 , Event: state: nomotion
2023.01.06 17:48:36 5: DbLog logdb - DbLogInclude of "hueBewegungKueche2": state
2023.01.06 17:48:36 4: DbLog logdb - added event - Timestamp: 2023-01-06 17:48:36, Device: hueBewegungKueche2, Type: HUEDEVICE, Event: state: nomotion, Reading: state, Value: nomotion, Unit:
2023.01.06 17:48:40 4: logdb - PID: 5720, Processing Statement:
SELECT
DATE_FORMAT(TIMESTAMP, '%Y-%m-%d %H:%i:%s'),
DEVICE,
READING,
VALUE
FROM history WHERE 1=1 AND DEVICE = 'aussenfuehler_HMIP' AND READING = '1.ACTUAL_TEMPERATURE' AND TIMESTAMP >= STR_TO_DATE('2023-01-06 00:00:00', '%Y-%m-%d %H:%i:%s') AND TIMESTAMP <= STR_TO_DATE('2023-01-07 00:00:00', '%Y-%m-%d %H:%i:%s') ORDER BY TIMESTAMP
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 00:01:43, DEV: aussenfuehler_HMIP, RD: 1.ACTUAL_TEMPERATURE, VAL: 8.7
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 00:04:25, DEV: aussenfuehler_HMIP, RD: 1.ACTUAL_TEMPERATURE, VAL: 8.7
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 00:06:52, DEV: aussenfuehler_HMIP, RD: 1.ACTUAL_TEMPERATURE, VAL: 8.7
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 00:09:05, DEV: aussenfuehler_HMIP, RD: 1.ACTUAL_TEMPERATURE, VAL: 8.7
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 00:12:07, DEV: aussenfuehler_HMIP, RD: 1.ACTUAL_TEMPERATURE, VAL: 8.7
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 00:14:55, DEV: aussenfuehler_HMIP, RD: 1.ACTUAL_TEMPERATURE, VAL: 8.7
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 00:17:28, DEV: aussenfuehler_HMIP, RD: 1.ACTUAL_TEMPERATURE, VAL: 8.7
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 00:19:47, DEV: aussenfuehler_HMIP, RD: 1.ACTUAL_TEMPERATURE, VAL: 8.7
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 00:21:52, DEV: aussenfuehler_HMIP, RD: 1.ACTUAL_TEMPERATURE, VAL: 8.7
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 00:27:26, DEV: aussenfuehler_HMIP, RD: 1.ACTUAL_TEMPERATURE, VAL: 8.7
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 00:29:52, DEV: aussenfuehler_HMIP, RD: 1.ACTUAL_TEMPERATURE, VAL: 8.7
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 00:32:03, DEV: aussenfuehler_HMIP, RD: 1.ACTUAL_TEMPERATURE, VAL: 8.7
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 00:35:03, DEV: aussenfuehler_HMIP, RD: 1.ACTUAL_TEMPERATURE, VAL: 8.7
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 00:37:49, DEV: aussenfuehler_HMIP, RD: 1.ACTUAL_TEMPERATURE, VAL: 8.7
2
/////gekürzt////
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 17:32:01, DEV: aussenfuehler_HMIP, RD: 1.HUMIDITY, VAL: 96
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 17:34:34, DEV: aussenfuehler_HMIP, RD: 1.HUMIDITY, VAL: 96
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 17:36:52, DEV: aussenfuehler_HMIP, RD: 1.HUMIDITY, VAL: 96
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 17:38:56, DEV: aussenfuehler_HMIP, RD: 1.HUMIDITY, VAL: 96
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 17:41:49, DEV: aussenfuehler_HMIP, RD: 1.HUMIDITY, VAL: 96
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 17:44:28, DEV: aussenfuehler_HMIP, RD: 1.HUMIDITY, VAL: 96
2023.01.06 17:48:40 5: logdb - SQL-result -> PID: 5720, TS: 2023-01-06 17:46:53, DEV: aussenfuehler_HMIP, RD: 1.HUMIDITY, VAL: 95
2023.01.06 17:48:40 4: logdb - PID: 5720, rows count: 407
2023.01.06 17:48:41 4: DbLog logdb - ################################################################
2023.01.06 17:48:41 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:41 4: DbLog logdb - ################################################################
2023.01.06 17:48:41 4: DbLog logdb - number of events received: 1 of device: hueBewegungKueche2
2023.01.06 17:48:41 4: DbLog logdb - check Device: hueBewegungKueche2 , Event: state: motion
2023.01.06 17:48:41 5: DbLog logdb - parsed Event: hueBewegungKueche2 , Event: state: motion
2023.01.06 17:48:41 5: DbLog logdb - DbLogInclude of "hueBewegungKueche2": state
2023.01.06 17:48:41 4: DbLog logdb - added event - Timestamp: 2023-01-06 17:48:41, Device: hueBewegungKueche2, Type: HUEDEVICE, Event: state: motion, Reading: state, Value: motion, Unit:
2023.01.06 17:48:45 4: DbLog logdb - ################################################################
2023.01.06 17:48:45 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:45 4: DbLog logdb - ################################################################
2023.01.06 17:48:45 4: DbLog logdb - number of events received: 1 of device: gTagKerstin
2023.01.06 17:48:45 4: DbLog logdb - check Device: gTagKerstin , Event: rssi: -51
2023.01.06 17:48:45 5: DbLog logdb - parsed Event: gTagKerstin , Event: rssi: -51
2023.01.06 17:48:45 5: DbLog logdb - DbLogInclude of "gTagKerstin": state
2023.01.06 17:48:50 4: DbLog logdb - ################################################################
2023.01.06 17:48:50 4: DbLog logdb - ### New database processing cycle - SBP asynchronous ###
2023.01.06 17:48:50 4: DbLog logdb - ################################################################
2023.01.06 17:48:50 4: DbLog logdb - MemCache contains 3 entries to process
2023.01.06 17:48:50 4: DbLog logdb - DbLogType is: History
2023.01.06 17:48:50 4: DbLog logdb - ################################################################
2023.01.06 17:48:50 4: DbLog logdb - ### start of new Logcycle ###
2023.01.06 17:48:50 4: DbLog logdb - ################################################################
2023.01.06 17:48:50 4: DbLog logdb - number of events received: 1 of device: logdb
2023.01.06 17:48:50 4: DbLog logdb - check Device: logdb , Event: CacheOverflowLastNum: 0
2023.01.06 17:48:50 5: DbLog logdb - parsed Event: logdb , Event: CacheOverflowLastNum: 0
2023.01.06 17:48:50 5: DbLog logdb - MemCache contains: 437 -> 2023-01-06 17:48:22|hueBewegungKueche2|HUEDEVICE|state: motion|state|motion|
2023.01.06 17:48:50 5: DbLog logdb - MemCache contains: 438 -> 2023-01-06 17:48:36|hueBewegungKueche2|HUEDEVICE|state: nomotion|state|nomotion|
2023.01.06 17:48:50 5: DbLog logdb - MemCache contains: 439 -> 2023-01-06 17:48:41|hueBewegungKueche2|HUEDEVICE|state: motion|state|motion|
2023.01.06 17:48:50 4: DbLog logdb - Operation: log_asynch
2023.01.06 17:48:50 5: DbLog logdb - DbLogType: History
2023.01.06 17:48:50 4: DbLog logdb - AutoCommit: ON, Transaction: ON
2023.01.06 17:48:50 4: DbLog logdb - Insert mode: Array
2023.01.06 17:48:50 4: DbLog logdb - Primary Key used in history: TIMESTAMP,DEVICE,READING
2023.01.06 17:48:50 4: DbLog logdb - Primary Key used in current: DEVICE,READING
2023.01.06 17:48:50 5: DbLog logdb - processing 437 -> TS: 2023-01-06 17:48:22, Dev: hueBewegungKueche2, Type: HUEDEVICE, Event: state: motion, Reading: state, Val: motion, Unit:
2023.01.06 17:48:50 5: DbLog logdb - processing 438 -> TS: 2023-01-06 17:48:36, Dev: hueBewegungKueche2, Type: HUEDEVICE, Event: state: nomotion, Reading: state, Val: nomotion, Unit:
2023.01.06 17:48:50 5: DbLog logdb - processing 439 -> TS: 2023-01-06 17:48:41, Dev: hueBewegungKueche2, Type: HUEDEVICE, Event: state: motion, Reading: state, Val: motion, Unit:
2023.01.06 17:48:50 4: DbLog logdb - begin Transaction
2023.01.06 17:48:50 4: DbLog logdb - commit inserted data table history
2023.01.06 17:48:50 4: DbLog logdb - 3 of 3 events inserted into table history using PK on columns TIMESTAMP,DEVICE,READING
Ich habe den Log-Auszug in der Mitte gekürzt, da der Post sonst zu lang wurde.
Für mich sieht das aus, als wenn die Daten in derselben Sekunde kommen, in der sie angefragt werden.
Kann die Verzögerung irgendwo im Zugriff auf die SVG-Dateien liegen? Wo kann ich nach dem Problem suchen? Sorry, bin absolut ratlos.
Danke für Eure Geduld.
Viele Grüße Stefan
Du hast die Attribute nicht gesetzt die dir oben genannt hatte. ;)
Vielleicht hast du den Search Index nicht angelegt ?
Leider kann ich auf dem Handy deinen Logauszug nicht lesen.
Der configcheck rennt normal in 0,0x durch, irgenwas ist nicht i.o.
Ah, jetzt konnte ich es lesen. Ja, die Daten kommen zügig. Zumindest zu diesem Zeitpunkt was man sieht.
Setze dir
verbose4Devs = ddddd
Dann wird es übersichtlicher zeigt nur den lesefluss vom svg.
Habe die beiden Attribute gesetzt. Sorry hatte ich übersehen.
2023.01.06 21:49:56 4: DbLog logdb - ################################################################
2023.01.06 21:49:56 4: DbLog logdb - ### New database processing cycle - SBP asynchronous ###
2023.01.06 21:49:56 4: DbLog logdb - ################################################################
2023.01.06 21:49:56 4: DbLog logdb - MemCache contains 3 entries to process
2023.01.06 21:49:56 4: DbLog logdb - DbLogType is: History
2023.01.06 21:49:56 4: DbLog logdb - Operation: log_asynch
2023.01.06 21:49:56 4: DbLog logdb - AutoCommit: ON, Transaction: ON
2023.01.06 21:49:56 4: DbLog logdb - Insert mode: Array
2023.01.06 21:49:56 4: DbLog logdb - Primary Key used in history: TIMESTAMP,DEVICE,READING
2023.01.06 21:49:56 4: DbLog logdb - Primary Key used in current: DEVICE,READING
2023.01.06 21:49:56 4: DbLog logdb - begin Transaction
2023.01.06 21:49:56 4: DbLog logdb - commit inserted data table history
2023.01.06 21:49:56 4: DbLog logdb - 3 of 3 events inserted into table history using PK on columns TIMESTAMP,DEVICE,READING
2023.01.06 21:52:30 4: DbLog logdb - ################################################################
2023.01.06 21:52:30 4: DbLog logdb - ### new get data for SVG ###
2023.01.06 21:52:30 4: DbLog logdb - ################################################################
2023.01.06 21:52:30 4: DbLog logdb - main PID: 7424, secondary PID: 2180
2023.01.06 21:52:50 4: logdb - PID: 2180, Processing Statement:
SELECT
DATE_FORMAT(TIMESTAMP, '%Y-%m-%d %H:%i:%s'),
DEVICE,
READING,
VALUE
FROM history WHERE 1=1 AND DEVICE = 'aussenfuehler_HMIP' AND READING = '1.ACTUAL_TEMPERATURE' AND TIMESTAMP >= STR_TO_DATE('2023-01-06 00:00:00', '%Y-%m-%d %H:%i:%s') AND TIMESTAMP <= STR_TO_DATE('2023-01-07 00:00:00', '%Y-%m-%d %H:%i:%s') ORDER BY TIMESTAMP
2023.01.06 21:52:50 4: logdb - PID: 2180, rows count: 498
2023.01.06 21:52:50 4: logdb - PID: 2180, Processing Statement:
SELECT
DATE_FORMAT(TIMESTAMP, '%Y-%m-%d %H:%i:%s'),
DEVICE,
READING,
VALUE
FROM history WHERE 1=1 AND DEVICE = 'aussenfuehler_HMIP' AND READING = '1.HUMIDITY' AND TIMESTAMP >= STR_TO_DATE('2023-01-06 00:00:00', '%Y-%m-%d %H:%i:%s') AND TIMESTAMP <= STR_TO_DATE('2023-01-07 00:00:00', '%Y-%m-%d %H:%i:%s') ORDER BY TIMESTAMP
2023.01.06 21:52:50 4: logdb - PID: 2180, rows count: 498
2023.01.06 21:53:00 4: DbLog logdb - ################################################################
2023.01.06 21:53:00 4: DbLog logdb - ### New database processing cycle - SBP asynchronous ###
2023.01.06 21:53:00 4: DbLog logdb - ################################################################
2023.01.06 21:53:00 4: DbLog logdb - MemCache contains 3 entries to process
2023.01.06 21:53:00 4: DbLog logdb - DbLogType is: History
2023.01.06 21:53:00 4: DbLog logdb - Operation: log_asynch
2023.01.06 21:53:00 4: DbLog logdb - AutoCommit: ON, Transaction: ON
2023.01.06 21:53:00 4: DbLog logdb - Insert mode: Array
2023.01.06 21:53:00 4: DbLog logdb - Primary Key used in history: TIMESTAMP,DEVICE,READING
2023.01.06 21:53:00 4: DbLog logdb - Primary Key used in current: DEVICE,READING
2023.01.06 21:53:00 4: DbLog logdb - begin Transaction
2023.01.06 21:53:00 4: DbLog logdb - commit inserted data table history
2023.01.06 21:53:00 4: DbLog logdb - 3 of 3 events inserted into table history using PK on columns TIMESTAMP,DEVICE,READING
2023.01.06 22:00:00 4: DbLog logdb - ################################################################
2023.01.06 22:00:00 4: DbLog logdb - ### New database processing cycle - SBP asynchronous ###
2023.01.06 22:00:00 4: DbLog logdb - ################################################################
2023.01.06 22:00:00 4: DbLog logdb - MemCache contains 4 entries to process
2023.01.06 22:00:00 4: DbLog logdb - DbLogType is: History
2023.01.06 22:00:00 4: DbLog logdb - Operation: log_asynch
2023.01.06 22:00:00 4: DbLog logdb - AutoCommit: ON, Transaction: ON
2023.01.06 22:00:00 4: DbLog logdb - Insert mode: Array
2023.01.06 22:00:00 4: DbLog logdb - Primary Key used in history: TIMESTAMP,DEVICE,READING
2023.01.06 22:00:00 4: DbLog logdb - Primary Key used in current: DEVICE,READING
2023.01.06 22:00:00 4: DbLog logdb - begin Transaction
2023.01.06 22:00:00 4: DbLog logdb - commit inserted data table history
2023.01.06 22:00:00 4: DbLog logdb - 4 of 4 events inserted into table history using PK on columns TIMESTAMP,DEVICE,READING
2023.01.06 22:00:50 4: DbLog logdb - ################################################################
2023.01.06 22:00:50 4: DbLog logdb - ### new get data for SVG ###
2023.01.06 22:00:50 4: DbLog logdb - ################################################################
2023.01.06 22:00:50 4: DbLog logdb - main PID: 7424, secondary PID: 11942
2023.01.06 22:01:10 4: logdb - PID: 11942, Processing Statement:
SELECT
DATE_FORMAT(TIMESTAMP, '%Y-%m-%d %H:%i:%s'),
DEVICE,
READING,
VALUE
FROM history WHERE 1=1 AND DEVICE = 'aussenfuehler_HMIP' AND READING = '1.ACTUAL_TEMPERATURE' AND TIMESTAMP >= STR_TO_DATE('2023-01-06 00:00:00', '%Y-%m-%d %H:%i:%s') AND TIMESTAMP <= STR_TO_DATE('2023-01-07 00:00:00', '%Y-%m-%d %H:%i:%s') ORDER BY TIMESTAMP
2023.01.06 22:01:10 4: logdb - PID: 11942, rows count: 503
2023.01.06 22:01:10 4: logdb - PID: 11942, Processing Statement:
SELECT
DATE_FORMAT(TIMESTAMP, '%Y-%m-%d %H:%i:%s'),
DEVICE,
READING,
VALUE
FROM history WHERE 1=1 AND DEVICE = 'aussenfuehler_HMIP' AND READING = '1.HUMIDITY' AND TIMESTAMP >= STR_TO_DATE('2023-01-06 00:00:00', '%Y-%m-%d %H:%i:%s') AND TIMESTAMP <= STR_TO_DATE('2023-01-07 00:00:00', '%Y-%m-%d %H:%i:%s') ORDER BY TIMESTAMP
2023.01.06 22:01:10 4: logdb - PID: 11942, rows count: 503
Ich habe verbose4devs im ersten Anlauf auf "ddddd" gesetzt (hat das irgendeine Spezialbedeutung oder war ich nur zu doof?) im zweiten Anlauf "SVG_aussenfuehler", das ist das SVG mit dem ich außer im allerersten Log immer getestet habe.
background_processing_time 0.0122 2023-01-06 21:57:00
sql_processing_time 0.0100 2023-01-06 21:57:00
DANKE!!!
Zitat
Ich habe verbose4devs im ersten Anlauf auf "ddddd" gesetzt (hat das irgendeine Spezialbedeutung oder war ich nur zu doof?)
Nein, ist einfach nur ein Trick die Logcycle-Ausgaben auf ein nicht vorhandes Device (kann auch "blabla" sein) zu filtern. Daduch bleiben nur ein paar Daten und vor allem die "new get data for SVG" -Ausgaben sichtbar.
Deine Readings zeigen Schreibzeiten von ca. 10 ms was ok ist. Das ist die Zeit welche die DB zum Loggen von Daten braucht, nicht für das Lesen (SVG).
Jetzt müsstest du wieder verbose 5 setzen und ein SVG aufrufen, dann sehen wir genauer wieviel Zeit nach dem Aufruf des SVG und der Datenlieferung bzw. dessen Abschluß vergeht weil die Daten im Log jetzt besser gefiltert sind.
Was mir noch durch den Kopf gegangen ist .... das checkConfig läuft nicht bei dir und bricht irgendwann ab.
Gibt es eine Fehlermitteilung ?
Beim Aufruf des Kommandos geht das Modul online und ruft vom FHEM Updateserver evtl. neu vorhandene Versionen ab.
Hast du Probleme mit dem Internetzugriff?
Hast du das globale Attribut dnsServer gesetzt?
Danke für Deine Geduld. Bin jetzt auch noch die nächste Stunde durchgängig am Rechner ;-)
checkConfig blockiert nach meinem Eindruck FHEM komplett. Auch in anderen Browser-Sessions geht nichts mehr mit FHEM. bzgl. Fehlermeldung bin ich mir nicht sicher. Habe nie mehr als 10 Minuten gewartet. :-[
Habe dnsServer jetzt gesetzt. War vorher nicht da. Hat leider nach erstem Eindruck nix geändert. Starte FHEM gleich noch mal neu.
dns hatte ich auch schon im Blick. Update funktioniert immer reibungslos. Ich habe sehr sporadisch unten in der Statusleiste, wenn ich was mit FHEM versuche einen cloudflare-Aufruf stehen, ebenso sehr sporadisch wird mein lokaler Aufruf vom NAS nicht korrekt aufgelöst. Alle DB-Anfragen gehen aber m.E. über feste IP im lokalen Netz.
Logfile rund um configcheck von gerade eben:
2023.01.06 22:48:54 4: DbLog logdb - ################################################################
2023.01.06 22:48:54 4: DbLog logdb - ### New database processing cycle - SBP asynchronous ###
2023.01.06 22:48:54 4: DbLog logdb - ################################################################
2023.01.06 22:48:54 4: DbLog logdb - MemCache contains 1 entries to process
2023.01.06 22:48:54 4: DbLog logdb - DbLogType is: History
2023.01.06 22:48:54 5: DbLog logdb - MemCache contains: 985 -> 2023-01-06 22:48:53|jonathan_Heizung_HMIP|HMCCUDEV|temperature_soll: 5|temperature_soll|5|
2023.01.06 22:48:54 4: DbLog logdb - Operation: log_asynch
2023.01.06 22:48:54 5: DbLog logdb - DbLogType: History
2023.01.06 22:48:54 4: DbLog logdb - AutoCommit: ON, Transaction: ON
2023.01.06 22:48:54 4: DbLog logdb - Insert mode: Array
2023.01.06 22:48:54 4: DbLog logdb - Primary Key used in history: TIMESTAMP,DEVICE,READING
2023.01.06 22:48:54 4: DbLog logdb - Primary Key used in current: DEVICE,READING
2023.01.06 22:48:54 5: DbLog logdb - processing 985 -> TS: 2023-01-06 22:48:53, Dev: jonathan_Heizung_HMIP, Type: HMCCUDEV, Event: temperature_soll: 5, Reading: temperature_soll, Val: 5, Unit:
2023.01.06 22:48:54 4: DbLog logdb - begin Transaction
2023.01.06 22:48:54 4: DbLog logdb - commit inserted data table history
2023.01.06 22:48:54 4: DbLog logdb - 1 of 1 events inserted into table history using PK on columns TIMESTAMP,DEVICE,READING
2023.01.06 22:49:03 4: DbLog logdb - configCheck: Got remote controls_fhem.txt with 2495 entries.
2023.01.06 22:49:03 4: DbLog logdb - configCheck: Got local controls_fhem.txt with 2495 entries.
2023.01.06 22:49:03 4: DbLog logdb - configCheck: local version from last update - creation time: 2022-12-30_07:45:03 - bytes: 469411
2023.01.06 22:49:03 4: DbLog logdb - Executing SQL: SHOW VARIABLES LIKE 'character_set_connection'
2023.01.06 22:49:23 4: DbLog logdb - SQL result: character_set_connection utf8
2023.01.06 22:49:23 4: DbLog logdb - Executing SQL: SHOW VARIABLES LIKE 'character_set_database'
2023.01.06 22:49:43 4: DbLog logdb - SQL result: character_set_database utf8
2023.01.06 22:49:43 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM history where FIELD='DEVICE'
2023.01.06 22:50:03 4: DbLog logdb - SQL result: DEVICE varchar(64) NO PRI
2023.01.06 22:50:03 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM history where FIELD='TYPE'
2023.01.06 22:50:23 4: DbLog logdb - SQL result: TYPE varchar(64) YES
2023.01.06 22:50:23 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM history where FIELD='EVENT'
2023.01.06 22:50:43 4: DbLog logdb - SQL result: EVENT varchar(512) YES
2023.01.06 22:50:43 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM history where FIELD='READING'
2023.01.06 22:51:03 4: DbLog logdb - SQL result: READING varchar(64) NO PRI
2023.01.06 22:51:03 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM history where FIELD='VALUE'
2023.01.06 22:51:23 4: DbLog logdb - SQL result: VALUE varchar(128) YES
2023.01.06 22:51:23 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM history where FIELD='UNIT'
2023.01.06 22:51:43 4: DbLog logdb - SQL result: UNIT varchar(32) YES
2023.01.06 22:51:43 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM current where FIELD='DEVICE'
2023.01.06 22:52:03 4: DbLog logdb - SQL result: DEVICE varchar(64) NO PRI
2023.01.06 22:52:03 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM current where FIELD='TYPE'
2023.01.06 22:52:23 4: DbLog logdb - SQL result: TYPE varchar(64) YES
2023.01.06 22:52:23 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM current where FIELD='EVENT'
2023.01.06 22:52:43 4: DbLog logdb - SQL result: EVENT varchar(512) YES
2023.01.06 22:52:43 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM current where FIELD='READING'
2023.01.06 22:53:03 4: DbLog logdb - SQL result: READING varchar(64) NO PRI
2023.01.06 22:53:03 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM current where FIELD='VALUE'
2023.01.06 22:53:23 4: DbLog logdb - SQL result: VALUE varchar(128) YES
2023.01.06 22:53:23 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM current where FIELD='UNIT'
2023.01.06 22:53:43 4: DbLog logdb - SQL result: UNIT varchar(32) YES
2023.01.06 22:53:43 4: DbLog logdb - Executing SQL: SHOW INDEX FROM history where Key_name='Search_Idx'
2023.01.06 22:54:03 4: DbLog logdb - SQL result: history 1 Search_Idx 1 DEVICE A 12 BTREE
2023.01.06 22:54:03 4: DbLog logdb - Executing SQL: SHOW INDEX FROM history where Key_name='Search_Idx' and Column_name='DEVICE'
2023.01.06 22:54:23 4: DbLog logdb - SQL result: history 1 Search_Idx 1 DEVICE A 12 BTREE
2023.01.06 22:54:23 4: DbLog logdb - Executing SQL: SHOW INDEX FROM history where Key_name='Search_Idx' and Column_name='READING'
2023.01.06 22:54:43 4: DbLog logdb - SQL result: history 1 Search_Idx 2 READING A 12 BTREE
2023.01.06 22:54:43 4: DbLog logdb - Executing SQL: SHOW INDEX FROM history where Key_name='Search_Idx' and Column_name='TIMESTAMP'
2023.01.06 22:55:03 4: DbLog logdb - SQL result: history 1 Search_Idx 3 TIMESTAMP A 368832 BTREE
2023.01.06 22:55:03 5: DbLog logdb - DbRep-Device 'dbrep' uses logdb.
2023.01.06 22:55:03 4: DbLog logdb - Executing SQL: SHOW INDEX FROM history where Key_name='Report_Idx'
2023.01.06 22:55:23 4: DbLog logdb - SQL result:
2023.01.06 22:55:44 5: DbLog logdb: Table current present : 0 (0 = not present or no content)
2023.01.06 22:55:44 3: abfahrt_st_heinrich: Read callback: Error: reiseauskunft.bahn.de: Connection reset by peer (104)
2023.01.06 22:55:44 2: deconz: http request failed: read from http://192.168.178.10:80 timed out
2023.01.06 22:55:53 4: DbLog logdb - ################################################################
2023.01.06 22:55:53 4: DbLog logdb - ### New database processing cycle - SBP asynchronous ###
2023.01.06 22:55:53 4: DbLog logdb - ################################################################
2023.01.06 22:55:53 4: DbLog logdb - MemCache contains 11 entries to process
2023.01.06 22:55:53 4: DbLog logdb - DbLogType is: History
2023.01.06 22:55:53 5: DbLog logdb - MemCache contains: 986 -> 2023-01-06 22:55:24|aussenfuehler_HMIP|HMCCUDEV|1.HUMIDITY: 99|1.HUMIDITY|99|
2023.01.06 22:55:53 5: DbLog logdb - MemCache contains: 987 -> 2023-01-06 22:55:24|aussenfuehler_HMIP|HMCCUDEV|state: 6.9|state|6.9|
2023.01.06 22:55:53 5: DbLog logdb - MemCache contains: 988 -> 2023-01-06 22:55:24|aussenfuehler_HMIP|HMCCUDEV|1.ACTUAL_TEMPERATURE: 6.9|1.ACTUAL_TEMPERATURE|6.9|
2023.01.06 22:55:53 5: DbLog logdb - MemCache contains: 989 -> 2023-01-06 22:55:24|jonathan_Heizung_HMIP|HMCCUDEV|temperature_soll: 5|temperature_soll|5|
2023.01.06 22:55:53 5: DbLog logdb - MemCache contains: 990 -> 2023-01-06 22:55:44|aussenfuehler_HMIP|HMCCUDEV|1.HUMIDITY: 99|1.HUMIDITY|99|
2023.01.06 22:55:53 5: DbLog logdb - MemCache contains: 991 -> 2023-01-06 22:55:44|aussenfuehler_HMIP|HMCCUDEV|state: 6.8|state|6.8|
2023.01.06 22:55:53 5: DbLog logdb - MemCache contains: 992 -> 2023-01-06 22:55:44|aussenfuehler_HMIP|HMCCUDEV|1.ACTUAL_TEMPERATURE: 6.8|1.ACTUAL_TEMPERATURE|6.8|
2023.01.06 22:55:53 5: DbLog logdb - MemCache contains: 993 -> 2023-01-06 22:55:44|jonathan_Heizung_HMIP|HMCCUDEV|temperature_soll: 5|temperature_soll|5|
2023.01.06 22:55:53 5: DbLog logdb - MemCache contains: 994 -> 2023-01-06 22:55:44|aussenfuehler_HMIP|HMCCUDEV|state: 6.8|state|6.8|
2023.01.06 22:55:53 5: DbLog logdb - MemCache contains: 995 -> 2023-01-06 22:55:44|aussenfuehler_HMIP|HMCCUDEV|1.ACTUAL_TEMPERATURE: 6.8|1.ACTUAL_TEMPERATURE|6.8|
2023.01.06 22:55:53 5: DbLog logdb - MemCache contains: 996 -> 2023-01-06 22:55:44|aussenfuehler_HMIP|HMCCUDEV|1.HUMIDITY: 99|1.HUMIDITY|99|
Nach dem Klick auf den Aufruf für das SVG erscheint in der Statuszeile
"Warten auf d36m9g8osz0lpw.cloudfront.net..."
Das macht mich massiv stutzig...
Zitat
checkConfig blockiert nach meinem Eindruck FHEM komplett.
Wenn das passiert ist es eine heiße Spur das etwas nicht stimmt. Frage ist nur was.
Neben dem angesprochenen Versions-check werden Verbindungen zur DB aufgerufen die grundlegende Dinge abrufen, Spaltenbreiten, Indizes usw.
Deine Ausgaben ...
Zitat
...
2023.01.06 22:55:03 4: DbLog logdb - Executing SQL: SHOW INDEX FROM history where Key_name='Report_Idx'
2023.01.06 22:55:23 4: DbLog logdb - SQL result:
2023.01.06 22:55:44 5: DbLog logdb: Table current present : 0 (0 = not present or no content)
2023.01.06 22:55:44 3: abfahrt_st_heinrich: Read callback: Error: reiseauskunft.bahn.de: Connection reset by peer (104)
2023.01.06 22:55:44 2: deconz: http request failed: read from http://192.168.178.10:80 timed out
Der configCheck läuft bis zum Ende durch. SHOW INDEX FROM history where Key_name='Report_Idx' ist der letzte Check, danach kommt nur noch die Browserausgabe.
Nun fallen mir gleich die Timeouts von deconz bzw. abfahrt_st_heinrich ins Auge. Man sieht auch ziemlich genau 20 Sekunden zwischen 2023.01.06 22:55:23 4: DbLog logdb - SQL result: und 2023.01.06 22:55:44 3: abfahrt_st_heinrich: Read callback: Error: reiseauskunft.bahn.de: Connection reset by peer (104).
Ich würde mal abfahrt_st_heinrich disablen.
Zitat
Nach dem Klick auf den Aufruf für das SVG erscheint in der Statuszeile
"Warten auf d36m9g8osz0lpw.cloudfront.net..."
Das macht mich massiv stutzig...
Da bin ich 100%ig bei dir. :o
Schau mal hier -> https://dieviren.de/d2ucfwpxlh3zh3-cloudfront-net/
Und ...
Zitat
Ich habe sehr sporadisch unten in der Statusleiste, wenn ich was mit FHEM versuche einen cloudflare-Aufruf stehen, ebenso sehr sporadisch wird mein lokaler Aufruf vom NAS nicht korrekt aufgelöst.
Es verdichten sich m.M. nach die Zeichen die auf ein Virenproblem hindeuten ...
Danke. Das cloudflare-Thema schaue ich mir separat mal an. Könnte auch sein, dass das mit installierten Erweiterungen in Chrome zu tun hat.
Scheint aber mit dem SVG-Thema nichts zu tun zu haben. Das Phänomen tritt identisch in Chrome on MacOS, Safari on MacOS und Safari on iPadOS auf.
Das httpmod abfahrt_ ... habe ich disabled. Leider ohne Erfolg. Ich tippe darauf, dass das eher Folgefehler des Problems vorher sind? Allerdings neigt die Abfahrtstafel tatsächlich dazu, ein paar mal am Tag auf einen timeout zu laufen, aber auf keinen Fall so regelmäßig.
:-\
Edit:
Sonst müsste das Virenproblem ja im docker-Container stecken ...
Naja, wenn der Browser blockiert bekommst du keine Ausgaben von FHEM(WEB), keine Return-Ausgabe des configCheck , der SVG über Javascript ....
Ist jetzt ein bisschen schwierig für mich mir eine eindeutige Meinung zu bilden. Aber ich denke all das was du bisher beschrieben hast, sind Folgeerscheinungen eines noch versteckten Verursachers der wahrscheinlich nicht im FHEM selbst steckt.
Vllt. gibt es Mitleser (Rudi?) die noch Ideen dazu haben ?
Noch zur Ergänzung ... Timeouts bei FHEM-Modulen sind per se nicht problematisch, nur dann wenn das entsprechende Modul nicht non-blocking gebaut wurde, was der Anwender wiederum nicht unbedingt erkennen kann. Das nur damit du die Timeouts richtig einordnest.
Auf alle Fälle erstmal ein riesiges Dankeschön für heute!! :) :) :) Und eine gute Nacht!
Danke, dir auch :)
ZitatVllt. gibt es Mitleser (Rudi?) die noch Ideen dazu haben ?
Da die 20 Sekunden nach sowas wie
Executing SQL: SHOW VARIABLES LIKE 'character_set_connection'auftreten, also bei einer Operation, was keinen Plattenzugriff oder Rechnzeit benoetigt, habe ich die DB in Verdacht, die 20 Sekunden lang versucht einen Rechnernamen fuer den Client (d.h. FHEM) zu finden, um den Zugriff protokollieren zu koennen.
Zitat
Da die 20 Sekunden nach sowas wie
Code: [Auswählen]
Executing SQL: SHOW VARIABLES LIKE 'character_set_connection'
auftreten, also bei einer Operation, was keinen Plattenzugriff oder Rechnzeit benoetigt, habe ich die DB in Verdacht, die 20 Sekunden lang versucht einen Rechnernamen fuer den Client (d.h. FHEM) zu finden, um den Zugriff protokollieren zu koennen.
Ja, könnte der TE mal prüfen ob die Namensauflösung auf der Synology funktioniert. Allerdings verwendet er IP-Adressen soweit ich gesehen habe.
Die Zeit zwischen Anfrage und Ergebnis ist schon verdächtig:
2023.01.06 22:54:43 4: DbLog logdb - Executing SQL: SHOW INDEX FROM history where Key_name='Search_Idx' and Column_name='TIMESTAMP'
2023.01.06 22:55:03 4: DbLog logdb - SQL result: history 1 Search_Idx 3 TIMESTAMP A 368832 BTREE
2023.01.06 22:55:03 5: DbLog logdb - DbRep-Device 'dbrep' uses logdb.
2023.01.06 22:55:03 4: DbLog logdb - Executing SQL: SHOW INDEX FROM history where Key_name='Report_Idx'
2023.01.06 22:55:23 4: DbLog logdb - SQL result:
Es gibt zwei Anfragen bzgl. evtl. Indizes. In beiden Fällen vergehen genau 20 Sekunden bis zu einer Antwort der DB.
Auch bei anderen Abfragen wie hier
2023.01.06 22:49:03 4: DbLog logdb - Executing SQL: SHOW VARIABLES LIKE 'character_set_connection'
2023.01.06 22:49:23 4: DbLog logdb - SQL result: character_set_connection utf8
2023.01.06 22:49:23 4: DbLog logdb - Executing SQL: SHOW VARIABLES LIKE 'character_set_database'
2023.01.06 22:49:43 4: DbLog logdb - SQL result: character_set_database utf8
2023.01.06 22:49:43 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM history where FIELD='DEVICE'
2023.01.06 22:50:03 4: DbLog logdb - SQL result: DEVICE varchar(64) NO PRI
2023.01.06 22:50:03 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM history where FIELD='TYPE'
2023.01.06 22:50:23 4: DbLog logdb - SQL result: TYPE varchar(64) YES
2023.01.06 22:50:23 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM history where FIELD='EVENT'
2023.01.06 22:50:43 4: DbLog logdb - SQL result: EVENT varchar(512) YES
2023.01.06 22:50:43 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM history where FIELD='READING'
2023.01.06 22:51:03 4: DbLog logdb - SQL result: READING varchar(64) NO PRI
2023.01.06 22:51:03 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM history where FIELD='VALUE'
2023.01.06 22:51:23 4: DbLog logdb - SQL result: VALUE varchar(128) YES
2023.01.06 22:51:23 4: DbLog logdb - Executing SQL: SHOW FIELDS FROM history where FIELD='UNIT'vergehen zwischen "Executing" und "SQL result" immer genau 20 Sekunden.
Ich bin relativ ratlos was eine DB dazu bringen könnte derart genau und regelmäßig zu verzögern.
Ich ahne etwas.
Die Abfragen im configCheck sind Einzelabfragen, d.h. es wird vor dem Exec jeweils die Datenverbindung aufgebaut und danach wieder abgebaut.
Das gleiche findet statt wenn Daten für die SVG Erstellung abgerufen werden.
Ich könnte das Verfahren abändern und die Datenverbindung offen lassen. Dann würde der TE wahrscheinlich beim ersten Abruf eine Verzögerung feststellen und sich wundern. Dem aber keine Bedeutung beimessen weil die nächsten Abrufe dann zügig ablaufen.
Wenn die Vermutung stimmt, ist nur der Verbindungsaufbau zur DB lahm und wird durch Connecting Verfahren offensichtlich.
Mit dem Attr plotfork = 1 im FHEMWEB wird auf jeden Fall für den nebenläufigen Prozess jeweils eine neue DB-Verbindung aufgebaut.
Ich werde eine V erstellen um diese Theorie prüfen zu lassen.
Dennoch sollte RockThisParty m.M. nach die DB prüfen.
Guten Morgen :)
Ich habe heute Vormittag nur noch eine halbe Stunde, um was auszuprobieren.
Schaue mir gerade MariaDB - Konfig an, bin aber ziemlich ratlos.
Wenn es etwas gibt, wo ich direkt prüfen könnte, wäre ich für einen Hinweis dankbar.
Was mir rund um DNS noch eingefallen ist: Ich habe in der letzten Zeit meine Fritz!Box tauschen müssen, die neue aber aus dem Backup der alten aufgesetzt. Vielleicht hängen da noch irgendwelche falschen internen DNS-Einträge?
Ich habe heute Vormittag nur noch eine halbe Stunde, um was auszuprobieren.
So schnell bin ich nicht. Ggf. heute Abend.
Zitat
Was mir rund um DNS noch eingefallen ist: Ich habe in der letzten Zeit meine Fritz!Box tauschen müssen, die neue aber aus dem Backup der alten aufgesetzt. Vielleicht hängen da noch irgendwelche falschen internen DNS-Einträge?
Das solltest du auf jeden Fall überprüfen.
Supi! Ich schaue auf alle Fälle heute Abend rein.
Ich habe dir eine Version im contrib zur Verfügung gestellt.
Umgestellt ist die configCheck Funktion.
Für alle Checks wird die DB-Verbindung nur einmal zu Beginn aufgebaut.
Es wird jetzt auch die benötigte Zeit für den Verbindungsaufbau gemessen und ausgegeben:
Available Drivers in your system
DBD::DBM, DBD::ExampleP, DBD::File, DBD::Gofer, DBD::Mem, DBD::Pg, DBD::Proxy, DBD::SQLite, DBD::Sponge, DBD::mysql
Result of version check
Used Perl version: 5.28.1
Used DBI (Database independent interface) version: 1.642
Used DBD (Database driver) version mysql: 4.050
Used DbLog version: 5.5.10.
Your local DbLog module is modified.
Recommendation: You should update FHEM to get the recent DbLog version from repository ! Your DBD version fulfills UTF8 support, no need to update DBD.
Result of configuration read check
Connection parameter store type: file
Connection parameter: Connection -> mysql:database=fhemtest;host=192.168.2.44;port=3306, User -> fhemtest, Password -> read o.k.
Result of connection check
Connection to database fhemtest successfully done.
The time required to establish the connection was 0.0017 seconds
Recommendation: settings o.k.
......
Zum Download in der FHEMWEB Kommandozeile inklusive der Anführungszeichen angeben und danach FHEM restarten:
"wget -qO ./FHEM/93_DbLog.pm https://svn.fhem.de/fhem/trunk/fhem/contrib/DS_Starter/93_DbLog.pm"
Wenn meine Therie stimmt, wirst du eine 20 s Verzögerung feststellen (die auch ausgegeben wird), aber nach dieser Zeit ein Ergebnis angezeigt bekommen.
Du siehst im Vergleich dazu braucht meine MariaDB 0.0017 Sekunden für den Verbindungsaufbau.
Hi!
Vielen Dank!!
Du hast recht. configCheck sagt
Available Drivers in your system
DBD::DBM, DBD::ExampleP, DBD::File, DBD::Gofer, DBD::MariaDB, DBD::Mem, DBD::Pg, DBD::Proxy, DBD::SQLite, DBD::Sponge, DBD::mysql
Result of version check
Used Perl version: 5.28.1
Used DBI (Database independent interface) version: 1.642
Used DBD (Database driver) version Undefined
Used DbLog version: 5.5.10.
Your local DbLog module is modified.
Recommendation: You should update FHEM to get the recent DbLog version from repository !
Result of configuration read check
Connection parameter store type: file
Connection parameter: Connection -> mysql:database=fhem;host=192.168.178.2;port=3306, User -> fhem, Password -> read o.k.
Result of connection check
Connection to database fhem successfully done.
The time required to establish the connection was 20.0187 seconds
Recommendation: The time to establish a connection is much too long. There are performance problems that hinder operation.
Result of encoding check
Encoding used by Client (connection): UTF8
Encoding used by DB fhem: UTF8
Recommendation: settings o.k.
Result of insert mode check
Insert mode of DbLog-device logdb is: Array
Recommendation: Setting attribute "bulkInsert" to "1" may result a higher write performance in most cases. Feel free to try this mode.
Result of plot generation method check
WARNING - at least one of your FHEMWEB devices has attribute "plotfork = 1" and/or attribute "plotEmbed = 2" not set.
WEB: plotfork=1 / plotEmbed=2
WEB_refresh: plotfork=1 / plotEmbed=2
WEBapi: plotfork=0 / plotEmbed=0
WEBhook: plotfork=0 / plotEmbed=0
Recommendation: You should set attribute "plotfork = 1" and "plotEmbed = 2" in relevant devices. If these attributes are not set, blocking situations may occure when creating plots. Note: Your system must have sufficient memory to handle parallel running Perl processes. See also global attribute "blockingCallMax".
Result of table 'history' check
Column width set in table history: 'DEVICE' = 64, 'TYPE' = 64, 'EVENT' = 512, 'READING' = 64, 'VALUE' = 128, 'UNIT' = 32
Column width used by device logdb: 'DEVICE' = 64, 'TYPE' = 64, 'EVENT' = 512, 'READING' = 64, 'VALUE' = 128, 'UNIT' = 32
Recommendation: settings o.k.
Result of table 'current' check
Column width set in table current: 'DEVICE' = 64, 'TYPE' = 64, 'EVENT' = 512, 'READING' = 64, 'VALUE' = 128, 'UNIT' = 32
Column width used by device logdb: 'DEVICE' = 64, 'TYPE' = 64, 'EVENT' = 512, 'READING' = 64, 'VALUE' = 128, 'UNIT' = 32
Recommendation: settings o.k.
Result of check 'Search_Idx' availability
Index 'Search_Idx' exists and contains recommended fields 'DEVICE', 'TIMESTAMP', 'READING'.
Recommendation: settings o.k.
Result of check 'Report_Idx' availability for DbRep-devices
At least one DbRep-device assigned to logdb is used, but the recommended index 'Report_Idx' is missing.
Recommendation: You can create the index by executing statement 'CREATE INDEX Report_Idx ON `history` (TIMESTAMP,READING) USING BTREE;'
Depending on your database size this command may running a long time.
Please make sure the device 'logdb' is operating in asynchronous mode to avoid FHEM from blocking when creating the index.
Note: If you have just created another index which covers the same fields and order as suggested (e.g. a primary key) you don't need to create the 'Report_Idx' as well !
Ich mache mich mal dran, die Empfehlungen durchzuarbeiten.
Hi,
die Empfehlungen durchzuarbeiten wäre der 2. Schritt.
Das Hauptproblem ist die Zeit um einen Connect herzustellen. Hier würde ich dir empfehlen im Synology Forum zu recherchieren bzw. evtl. an den Support zu schreiben.
Was hast du für eine Syno ?
Ich glaube mich zu erinnern, dass ich selbst mal Probleme mit Syno hatte bzgl. der Login-Daten Prüfung die ewig dauerte.
Vllt. finde ich ich noch wie ich das damals gelöst hatte.
Ich bin jetzt dabei die Datenlieferung an SVG umzustellen.
Das funktioniert aber nur mit plotfork = 0. Wenn plotfork = 1 gesetzt ist, brauche ich immer einen neuen Connect zur DB und du hast dann diese Verzögerung bei dir.
Hi!
Ich habe gerade mal in einem frischen Container ein zweites frisches FHEM aufgesetzt und nur DBLog mit Zugriff auf dieselbe Datenbank definiert.
ConfigCheck und SVG völlig problemlos.
Ich denke, im nächsten Step übernehme ich mal die komplette Konfig ins neue FHEM.
Mal sehen ...
Nachtrag: Damit ist ja die DB an sich erstmal raus, DNS-Probleme nicht unbedingt ...
Ich habe jetzt gerade eine Version in mein contrib geladen, welche die Datenlieferung bei dem Attr plotfork = 0 optimiert.
Mit dieser Version und plotfork = 0 wirst du nur beim ersten SVG Aufruf die Verzögerung spüren, dann nicht mehr.
Trotzdem solltest du versuchen dein Problem zu lösen. -> Sorry, dein Post kam gerade zuvor :D
Auf jeden Fall ist mit dieser V die Connect Verwaltung für SVG's mit plotfork = 0 optimaler, wobei User mit schnellem DB Verbindungsaufbau keinen Unterschied merken werden.
Super, vielen Dank!
Die Verbesserung mit plotfork=0 kann ich wie von Dir erwartet bestätigen.
Ich werde berichten, wie meine Tests weitergehen und Dir zeitnah mehr als einen Kaffee ausgeben! ;)
:)
:D viel Erfolg !
Bis später ....
So, nun sage ich mal wieder gute Nacht für heute ::)
Wenn reichlich irritiert. Habe meine komplette Konfig in den neuen Container kopiert und der Fehler tritt nicht mehr auf.
Habe noch nicht ganz alle Details durch, aber
a) Port ist anders. Aber: Änderung des Ports am "Original" verscheucht den Fehler nicht.
b) Fehler tritt mit alter dblog-Version und neuer in der neuen Umgebung nicht auf. Ebenso haben alle sonstigen Updates nichts verändert.
Zwei drei kleinere Änderungen fehlen noch zwischen den Containern. Morgen mal sehen ...
Was mir auf die schnelle Einfällt ...
in was für ein Netzwerkmodus betreibst Du die Docker-Container?
Moin!
Ich bin gestern nicht mehr dazu gekommen, da weiter zu machen und heute wird es wohl auch nicht viel.
Aber über die Frage Netzwerk-Modus habe ich auch schon nachgedacht.
Mein "Originaler"-FHEM-Container mit dem Problem läuft im Host-Mode, da ich bei der Einrichtung das für irgendeinen Dienst brauchte. Mir ist nur noch nicht wieder eingefallen, was das mit ?Multicast? war.
Die Test-Kopie ohne Probleme läuft im Bridge-Mode. Das will ich noch testen.
Jetzt weiß ich wieder wo ich schonmal über ewig lange login-Zeiten gestolpert bin. ->
https://forum.fhem.de/index.php/topic,105714.msg1194447.html#msg1194447
Lösche doch mal die Datei
/tmp/login_fail.list
Sofern vorhanden (auf der Syno).
Aaaalso:
- login_fail.list gibt es nicht. Das kann es also schon mal nicht sein.
- NAS Neustart hat nichts geändert.
- Test Bridge Mode folgt.
So, ich kann jetzt bestätigen, dass das Problem eindeutig nur auftritt, wenn der Container im HOST-Mode läuft.
Nun habe ich aber leider tatsächlich keine Idee mehr, wie ich es verscheuchen kann.
Wenn nicht noch jemand von Euch einen besseren Vorschlag hat, schaue ich mal, dass ich mein produktives FHEM in den Bridge-Mode überführe (was ja nicht so schwer ist ... ich bin nur noch unsicher welche neuen Probleme oder Einschränkungen ich mir einhandele ... brauche ich für HUE, Deconz, HMIP Multicast? Ich glaube eigentlich nicht?)
Ich schulde Euch noch eine Auflösung ... sorry, dass das so lange gedauert hat. War wenig Zeit.
Total blöd: Das ganze Problem / Fehlerbild war nach einem Neustart der Fritz!Box verschwunden. Es lang offenbar an irgendwelchen DNS-Hängern/-Altlasten in der Box.
Drauf gekommen bin ich irgendwann bei der Testerei, weil an einer Stelle systematisch URLs zu FHEM nicht aufgelöst wurden, mit IP statt Name ging es dann.
Ärgerlich. Tut mir leid, dass ich damit so viel Aufruhr erzeugt habe. Danke für alle Unterstützung!! ... Für mich kann ich festhalten, dass ich mal wieder viel über FHEM gelernt habe und nebenbei einige Dinge aufgeräumt / verbessert habe.
Tip: Setze einen DNS-Server außerhalb der Friotte ein ... DNS und Fritte bin ich kein Freund von .. habe deshalb sogar dhcp extern gelöst ..