[gelöst] Text2Speech müllt meine SQLite Datenbank mit zerstückelten Eintr. voll

[1907]

Hallo liebe Forengemeinde,
ich habe ein Problem, mit dem ich jetzt bereits seit mehreren Wochen kämpfe und ich es einfach nicht in den Griff bekomme.

Mein Problem ist, dass immer wenn mein text2speech-Modul irgend einen Text vorliest, in meiner SQLite Datenbank (über das DbLog-Modul) Datenbankeinträge angelegt werden. Es ist nicht nur so, dass ich diese Datenbankeinträge nicht gebrauchen kann, sie sind zusätzlich total vermurkst und in verschiedenen Feldern verteilt.
Zuerst habe ich mein Logging komplett über DbLogInclude Einträge am jeweiligen Device aufgebaut. Anschließend habe ich alles auf die Regexp-Definition im dblog-Device umgestellt in der Hoffnung, dass dies vielleicht mein Problem behebt.
Hab auch schon versucht das Device myTTS (mein text2speech Modul) vom Logging explizit auszunehmen, ohne Erfolg.
Es werden auch nicht irgendwelche Events von myTTS geloggt, sondern irgend etwas im Hintergrund läuft hier schief.
Man sieht auch im Log, dass hier irgendwie die Einträge ausgelöst werden. Ich kann aber den die Logs nicht richtig deuten.

Im Anhang habe ich einen Screenshot der komischen Datenbankeinträge angehängt.

Diese Logs werden vom dblog erzeugt:

Code Auswählen Erweitern

2017.02.03 18:54:35 4: DbLog logdb -> ################################################################
2017.02.03 18:54:35 4: DbLog logdb -> ###              start of new Logcycle                       ###
2017.02.03 18:54:35 4: DbLog logdb -> ################################################################
2017.02.03 18:54:35 4: DbLog logdb -> amount of events received: 24 for device: mympd
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: presence: present
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: volume: 85
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: repeat: 0
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: random: 0
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: single: 0
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: consume: 0
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: playlist: 2
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: playlistlength: 1
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: mixrampdb: 0.000000
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: stop
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: song: 0
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: songid: 1
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: uptime: 14377
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: playtime: 0
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: artists: 3
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: albums: 4
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: songs: 17
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: db_playtime: 102
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: db_update: 1484995837
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: file: fury.mp3
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: Last-Modified: 2016-12-01T22:03:38Z
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: Time: 2
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: Pos: 0
2017.02.03 18:54:35 4: DbLog logdb -> check Device: mympd , Event: Id: 1
2017.02.03 18:54:35 4: DbLog logdb -> Device: myTTS excluded from database logging due to attribute "excludeDevs" restrictions
2017.02.03 18:54:35 4: DbLog logdb -> Device: myTTS excluded from database logging due to attribute "excludeDevs" restrictions
2017.02.03 18:54:40 4: Processing Statement: SELECT
                  TIMESTAMP,
                  DEVICE,
                  READING,
                  VALUE
                  ,TYPE,EVENT,UNIT FROM current WHERE 1=1 AND DEVICE  = 'myTTS|cache/55a63bb70aea0a090e1bb93f45e9350f.mp3' AND READING = 'Usage' AND TIMESTAMP >= '2000-01-01 00:00:00' AND TIMESTAMP < '2099-01-01 00:00:00' ORDER BY TIMESTAMP
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: 2017-02-03 18:54:40, Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: myTTS, Device: cache/55a63bb70aea0a090e1bb93f45e9350f.mp3, Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: Text2Speech, Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: Dieser Testtext muellt meine Datenbank voll, Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: Usage, Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: 1, Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: , Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> 7 of 7 events successfully inserted into table history
2017.02.03 18:54:40 4: DbLog logdb -> Failed to update in current, try to insert: , , Status = 0
2017.02.03 18:54:40 4: DbLog logdb -> Failed to update in current, try to insert: cache/55a63bb70aea0a090e1bb93f45e9350f.mp3, , Status = 0
2017.02.03 18:54:40 4: DbLog logdb -> Failed to update in current, try to insert: , , Status = 0
2017.02.03 18:54:40 4: DbLog logdb -> Failed to update in current, try to insert: , , Status = 0
2017.02.03 18:54:40 4: DbLog logdb -> Failed to update in current, try to insert: , , Status = 0
2017.02.03 18:54:40 4: DbLog logdb -> Failed to update in current, try to insert: , , Status = 0
2017.02.03 18:54:40 4: DbLog logdb -> Failed to update in current, try to insert: , , Status = 0
2017.02.03 18:54:40 4: DbLog logdb -> 7 of 7 events successfully inserted into table current
2017.02.03 18:54:40 4: DbLog logdb -> Device: myTTS excluded from database logging due to attribute "excludeDevs" restrictions


Hier noch meine Definition des DbLogs:

Code Auswählen Erweitern

define logdb DbLog ./db.conf ke_Meldung_Oelpumpe_ein|ke_Oelverbrauchszaehler:appUtilization|ke_Oelverbrauchszaehler:pulseTimeOverall|du_Oelverbrauch_l_Monat|du_Oelverbrauch_l_Tag|du_Oelverbrauch_l_Woche|ze_Leistungszaehler_1:kWh|ze_Leistungszaehler_1:power_mittel_w|ze_Leistungszaehler_1:statKWhDayLast|ze_LeistungszaehlerhLast|ze_Leistungszaehler_1:gerundet_euro_statKWhDayLast|.*:temperature|.*:humidity|.*:dewpoint

Ich bin mit meinem Latein wirklich am Ende und komm nicht weiter.

[Tobias]

Also bie mir ist die logdb mit .*:.* definiert und das TTSDevice mit dem Attribut DbLogExclude .*
ICh habe keinen TTS Eintrag in meiner DB... Dein Fhem ist up-to-date?

[1907]

Ja, FHEM ist up-to-date.
Den gleichen DbLogExclude Eintrag habe ich auch im TTSDevice stehen.

Das komische ist, dass dieser Log-Eintrag (bzw. diese Log-Einträge) auch nicht irgendwo im text2speech Device auftauchen und die Logs dann auch so komisch zerstückelt werden.
Das scheint irgendwas im Hintergrund zu sein, denn es gibt auch kein passendes Event welches den komischen Logeintrag mit der "tts-Cache-Datei" erzeugen könnte.

Diese Events werden von meinem text2speech-Device erzeugt:

Code Auswählen Erweitern

2017-02-03 20:24:39 MPD mympd presence: present
2017-02-03 20:24:39 MPD mympd volume: 85
2017-02-03 20:24:39 MPD mympd repeat: 0
2017-02-03 20:24:39 MPD mympd random: 0
2017-02-03 20:24:39 MPD mympd single: 0
2017-02-03 20:24:39 MPD mympd consume: 0
2017-02-03 20:24:39 MPD mympd playlist: 2
2017-02-03 20:24:39 MPD mympd playlistlength: 1
2017-02-03 20:24:39 MPD mympd mixrampdb: 0.000000
2017-02-03 20:24:39 MPD mympd stop
2017-02-03 20:24:39 MPD mympd song: 0
2017-02-03 20:24:39 MPD mympd songid: 1
2017-02-03 20:24:39 MPD mympd uptime: 19782
2017-02-03 20:24:39 MPD mympd playtime: 0
2017-02-03 20:24:39 MPD mympd artists: 3
2017-02-03 20:24:39 MPD mympd albums: 4
2017-02-03 20:24:39 MPD mympd songs: 17
2017-02-03 20:24:39 MPD mympd db_playtime: 102
2017-02-03 20:24:39 MPD mympd db_update: 1484995837
2017-02-03 20:24:39 MPD mympd file: fury.mp3
2017-02-03 20:24:39 MPD mympd Last-Modified: 2016-12-01T22:03:38Z
2017-02-03 20:24:39 MPD mympd Time: 2
2017-02-03 20:24:39 MPD mympd Pos: 0
2017-02-03 20:24:39 MPD mympd Id: 1
2017-02-03 20:24:39 Text2Speech myTTS playing: 1
2017-02-03 20:24:39 Text2Speech myTTS duration: 1
2017-02-03 20:24:39 Text2Speech myTTS endTime: 00:00:00
2017-02-03 20:24:41 Text2Speech myTTS playing: 0

Wenn ich mal die Datenbankfragmente zusammenbastle, könnte der Eintrag wie folgt aussehen:

Code Auswählen Erweitern

2017-02-03 18:54:40   myTTS   cache/55a63bb70aea0a090e1bb93f45e9350f.mp3   Usage   Text2Speech   Dieser Testtext muellt meine Datenbank voll

Ich frage mich halt wo kommt dieser Eintrag her? Und warum wird er so zerstückelt in die Datenbank eingetragen?

Interessant finde ich auch den Abschnitt im Log:

Code Auswählen Erweitern

2017.02.03 18:54:40 4: Processing Statement: SELECT
                  TIMESTAMP,
                  DEVICE,
                  READING,
                  VALUE
                  ,TYPE,EVENT,UNIT FROM current WHERE 1=1 AND DEVICE  = 'myTTS|cache/55a63bb70aea0a090e1bb93f45e9350f.mp3' AND READING = 'Usage' AND TIMESTAMP >= '2000-01-01 00:00:00' AND TIMESTAMP < '2099-01-01 00:00:00' ORDER BY TIMESTAMP
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: 2017-02-03 18:54:40, Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: myTTS, Device: cache/55a63bb70aea0a090e1bb93f45e9350f.mp3, Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: Text2Speech, Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: Dieser Testtext muellt meine Datenbank voll, Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: Usage, Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: 1, Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: , Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> 7 of 7 events successfully inserted into table history

Was bedeutet hier Processing Statement? und anschließend steht ja, dass 7 Events in die Datenbank eingetragen wurden. Aber Ich sehe diese Events nirgendwo.

[1907]

Ich bin nun ein wenig weiter gekommen.
Das Problem wird definitv vom Text2Speech Modul verursacht.
Das Modul legt im Hintergrund eine Statistik an, wie oft die einzelnen Cache-Dateien verwendet wurden und schreibt hierfür einen Eintrag in eine eventuell vorhandene DBLog Datenbank. Leider funktioniert dies (bei mir zumindest nicht). Es werden ungültige Datenbankeinträge erzeugt und die Datensätze werden zerstückelt.
Eigentlich gibt es im Text2Speech Modul ein Attribut (TTS_noStatisticsLog), mit dem man diese Statistikfunktion abschalten kann. Wenn ich das Attribut setze, hat dies aber leider keine Auswirkungen und die Einträge werden weiterhin angelegt. Vielleicht stimmt hier im Quellcode des Modus was nicht.

Ich habe mir nun vorübergehend so beholfen, indem ich im der Modul-Script-Datei "98_Text2Speech.pm" die Zeile 903 mit dem Aufruf der Subroutine für die Statistikfunktion komplett auskommentiert habe.
Jetzt werden keine Statistiken mehr angelegt und meine Datenbank bleibt sauber.

Eventuell ist es möglich, dass dies mit der Datenbank nicht universell in allen Konstellationen funktioniert. Vieleicht geht es mit MySql und mit SQlite wieder nicht.

[Tobias]

kannst du mal bitte einen Screentshot deiner LogTabelle aus phpMyAdmin o.ä. dieser Mülleinträge machen?
Ich verstehe noch nicht warum das so bei dir ist.

Normalerweise soll pro cache mp3 ein einziger Eintrag in der Current Tabelle sein. Im Value steht die Anzahl der Aufrufe, der Timestamp zeigt die letzte Verwendung.
Ziel des Ganzen soll es irgendwann mal sein, anhand diese Statistiken alte, nicht mehr genutzte Cachefiles gezielt zu löschen.

[1907]

Hallo Tobias vielen Dank für deine Hilfe!

Der Screenshot hängt in dem ersten Post dieses Threads.
Reicht dieser, oder brauchst du noch etwas anderes?.
In dem Screenshot fehlt lediglich noch der Eintrag mit der "1" der wird aber auch separat (ich glaube im Feld TIMESTAMP) angelegt und ein weiterer Datenbankeintrag, der komplett leer ist.

Aber man sieht auch ganz gut am Logfile von dblog, dass irgendwie 7 einzelne Einträge angelegt werden.
Sonst funktioniert dblog aber einwandfrei.

Code Auswählen Erweitern

2017.02.03 18:54:40 4: Processing Statement: SELECT
                  TIMESTAMP,
                  DEVICE,
                  READING,
                  VALUE
                  ,TYPE,EVENT,UNIT FROM current WHERE 1=1 AND DEVICE  = 'myTTS|cache/55a63bb70aea0a090e1bb93f45e9350f.mp3' AND READING = 'Usage' AND TIMESTAMP >= '2000-01-01 00:00:00' AND TIMESTAMP < '2099-01-01 00:00:00' ORDER BY TIMESTAMP
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: 2017-02-03 18:54:40, Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: myTTS, Device: cache/55a63bb70aea0a090e1bb93f45e9350f.mp3, Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: Text2Speech, Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: Dieser Testtext muellt meine Datenbank voll, Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: Usage, Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: 1, Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> processing event Timestamp: , Device: , Type: , Event: , Reading: , Value: , Unit:
2017.02.03 18:54:40 4: DbLog logdb -> 7 of 7 events successfully inserted into table history

[Tobias]

Hab es mal hier angesprochen...
https://forum.fhem.de/index.php/topic,62998.msg578371.html#msg578371

[1907]

Super, vielen Dank!

Hab gerade erst kapiert, dass du der Entwickler des Moduls bist. 
Auf jeden Fall erst mal grundsätzlich Danke für das nützliche Modul!

[1907]

Hallo Tobias,

mit dem heutigen Update wurde das Problem bei mir behoben!
Vielen Dank dafür (Ich gehe mal davon aus, dass du das gefixt hast - In dem anderen Thread habe ich nur "Bahnhof" verstanden ).
Nun werden die Datenbankeinträge korrekt angelegt.
Das Attribut zur Deaktivierung der Statistikfunktion arbeitet nun auch korrekt.

Super!

Ich hätte noch eine kleine Verständnissfrage. Werden die selten benutzten Cachedateien automatisch vom Modul gelöscht, oder muss man sich selbst mit einer "Auswertung der Datenbank" darum kümmern?

Viele Grüße

[Tobias]

Ich hätte noch eine kleine Verständnissfrage. Werden die selten benutzten Cachedateien automatisch vom Modul gelöscht, oder muss man sich selbst mit einer "Auswertung der Datenbank" darum kümmern?

Leider noch nicht, steht aber auf meiner ToDoListe