SVG mit dblog extrem langsam

RockThisParty · 06 Januar 2023, 10:07:54

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:

Code Auswählen

 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

rudolfkoenig · 06 Januar 2023, 11:04:08

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?

RockThisParty · 06 Januar 2023, 11:38:42

Hallo Rudolf,
das Verhalten mit ,,Show preprocessed ..." ist identisch.

DS_Starter · 06 Januar 2023, 11:40:16

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.

Ralli · 06 Januar 2023, 11:43:57

... und poste doch mal den Output von

Code Auswählen


set logdb configCheck

RockThisParty · 06 Januar 2023, 13:43:51

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.

Code Auswählen

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

DS_Starter · 06 Januar 2023, 16:48:13

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.

DS_Starter · 06 Januar 2023, 16:58:22

Evtl. Verbose 5 noch einstellen, aber ich ahne das Ergebnis.

RockThisParty · 06 Januar 2023, 17:54:32

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:

Code Auswählen

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:

Code Auswählen

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

DS_Starter · 06 Januar 2023, 18:10:23

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.

DS_Starter · 06 Januar 2023, 18:14:22

Ah, jetzt konnte ich es lesen. Ja, die Daten kommen zügig. Zumindest zu diesem Zeitpunkt was man sieht.

DS_Starter · 06 Januar 2023, 18:23:32

Setze dir

verbose4Devs = ddddd
Dann wird es übersichtlicher zeigt nur den lesefluss vom svg.

RockThisParty · 06 Januar 2023, 22:05:55

Habe die beiden Attribute gesetzt. Sorry hatte ich übersehen.

Code Auswählen

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

Code Auswählen

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.

Code Auswählen

background_processing_time 0.0122 2023-01-06 21:57:00
sql_processing_time 0.0100 2023-01-06 21:57:00

DANKE!!!

DS_Starter · 06 Januar 2023, 22:19:10

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.

DS_Starter · 06 Januar 2023, 22:34:51

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?

RockThisParty · 06 Januar 2023, 22:54:31

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.

RockThisParty · 06 Januar 2023, 22:59:10

Logfile rund um configcheck von gerade eben:

Code Auswählen

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|

RockThisParty · 06 Januar 2023, 23:05:22

Nach dem Klick auf den Aufruf für das SVG erscheint in der Statuszeile

"Warten auf d36m9g8osz0lpw.cloudfront.net..."

Das macht mich massiv stutzig...

DS_Starter · 06 Januar 2023, 23:16:31

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.

DS_Starter · 06 Januar 2023, 23:19:28

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 ...

RockThisParty · 06 Januar 2023, 23:35:48

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 ...

DS_Starter · 06 Januar 2023, 23:46:04

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.

RockThisParty · 06 Januar 2023, 23:50:36

Auf alle Fälle erstmal ein riesiges Dankeschön für heute!!

Und eine gute Nacht!

DS_Starter · 06 Januar 2023, 23:51:22

Danke, dir auch

rudolfkoenig · 07 Januar 2023, 10:42:30

ZitatVllt. gibt es Mitleser (Rudi?) die noch Ideen dazu haben ?

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.

DS_Starter · 07 Januar 2023, 11:16:08

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

Code Auswählen

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.

DS_Starter · 07 Januar 2023, 11:37:21

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.

RockThisParty · 07 Januar 2023, 12:01:34

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?

DS_Starter · 07 Januar 2023, 12:06:08

Code Auswählen


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.

RockThisParty · 07 Januar 2023, 12:10:19

Supi! Ich schaue auf alle Fälle heute Abend rein.

DS_Starter · 07 Januar 2023, 18:28:13

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:

Code Auswählen


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:

Code Auswählen


"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.

RockThisParty · 07 Januar 2023, 21:09:24

Hi!
Vielen Dank!!
Du hast recht. configCheck sagt

Code Auswählen

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.

DS_Starter · 07 Januar 2023, 21:28:17

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.

RockThisParty · 07 Januar 2023, 21:33:47

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 ...

RockThisParty · 07 Januar 2023, 21:34:41

Nachtrag: Damit ist ja die DB an sich erstmal raus, DNS-Probleme nicht unbedingt ...

DS_Starter · 07 Januar 2023, 21:37:01

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

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.

RockThisParty · 07 Januar 2023, 21:44:09

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!

DS_Starter · 07 Januar 2023, 21:46:40

viel Erfolg !

Bis später ....

RockThisParty · 07 Januar 2023, 23:07:38

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 ...

Wernieman · 09 Januar 2023, 09:16:44

Was mir auf die schnelle Einfällt ...
in was für ein Netzwerkmodus betreibst Du die Docker-Container?

RockThisParty · 09 Januar 2023, 10:50:50

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.

DS_Starter · 09 Januar 2023, 11:43:41

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).

RockThisParty · 09 Januar 2023, 18:41:28

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.

RockThisParty · 10 Januar 2023, 08:35:52

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?)

RockThisParty · 21 Januar 2023, 17:31:39

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.

Wernieman · 21 Januar 2023, 17:42:04

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 ..