DBLog funktioniert nicht richtig

Teamdrachen · 05 Juli 2017, 09:40:55

Hallo gemeinde,

ich hab ein seltsames Problem mit meiner Sqlite Datenbank.
Hin und wieder funktioniert sie, aber zu 99% wird nicht in die DB geschrieben.
Die DB selbst ist schon etwas älter und genügend werte drin, der Fehler tritt aber auch auf wenn eine neue DB angelegt wird.
Sqlite & der Raspi alles frisch installiert.

Fhem selbst sagt "connected"
Fhem kann auch in die Datenbank schreiben, ein Test mit "reducelog" verlief erfolgreich.

Code Auswählen

./db.conf .*:(temperature|valveposition|countsOverall|countsPerDay|humidity|measured-temp|desired-temp|state|STATE|R-winOpnMode|appUtilization|gasabsolut|gasleistung).*

auch

Code Auswählen

./db.conf .*:.* bringt keine Veränderungen.
Attr " Current/History" ist ebenfalls gesetzt.

Beim Start von FHEM werden die Files fhem.db-shm und FHEM.db-wal angelegt, in die Datenbank wird allerdings nichts geschrieben.
"rereadcfg" führt manchmal zu einem neuen Bearbeitungszeitstempel der DB Files, manchmal aber auch nicht. Geschrieben wird in die DB jedoch dabei nix.

Teamdrachen · 05 Juli 2017, 11:04:52

mal zum Spaß eine mysql DB angelegt und verbunden.
selbes Problem. FHEM sagt connected und in der Prozesslist von MySQL ist der Fhemuser auch verbunden. aber es wird nichts geloggt und es können auch keine werte die per direktverbindung in die DB eingetrafgen werden in den Plots ausgelesen werden.

rabehd · 05 Juli 2017, 11:34:22

Ich habe keine Ahnung und mit DBLog in Sqlite auf dem Raspberry kein Problem (bei mir wird in die DB geschrieben).
Was ich einwerfen würde: "Dateirechte ?"

Teamdrachen · 05 Juli 2017, 11:56:10

die Dateirechte stimmen und FHEM kann ja auch connecten und reducelog funktioniert ebefalls.
Allerdings war es das dann auch. es werden weder Werte geschrieben, noch gelesen.

Code Auswählen

Result of connection check

Connection to database fhem successfully done.
Recommendation: settings o.k.

Result of encoding check

Encoding used by Client (connection): LATIN1
Encoding used by fhem: UTF8
Recommendation: Both encodings should be identical. You can adjust the usage of UTF8 connection by setting the UTF8 parameter in file './db.conf' to the right value.

Result of logmode check

Logmode of DbLog-device DbLog is: asynchronous
Recommendation: settings o.k.

Result of table 'history' check

Column width set in DB fhem: 'DEVICE' = 32, 'TYPE' = 32, 'EVENT' = 512, 'READING' = 32, 'VALUE' = 32, 'UNIT' = 32
Column width used by DbLog: 'DEVICE' = 64, 'TYPE' = 64, 'EVENT' = 512, 'READING' = 64, 'VALUE' = 128, 'UNIT' = 32
Recommendation: The relation between column width in table history and the field width used in device DbLog don't meet the requirements. Please make sure that the width of database field definition is equal or larger than the field width used by the module. Compare the given results.
Currently the default values for field width are:

DEVICE: 64
TYPE: 64
EVENT: 512
READING: 64
VALUE: 128
UNIT: 32

You can change the column width in database by a statement like 'alter table history modify VALUE varchar(128);' (example for changing field 'VALUE'). You can do it for example by executing 'sqlCMD' in DbRep or in a SQL-Editor of your choice. (switch DbLog to asynchron mode for non-blocking).
The field width used by the module can be done by setting attributes 'colEvent', 'colReading', 'colValue',

Result of table 'current' check

Column width set in DB fhem: 'DEVICE' = 32, 'TYPE' = 32, 'EVENT' = 512, 'READING' = 32, 'VALUE' = 32, 'UNIT' = 32
Column width used by DbLog: 'DEVICE' = 64, 'TYPE' = 64, 'EVENT' = 512, 'READING' = 64, 'VALUE' = 128, 'UNIT' = 32
Recommendation: The relation between column width in table current and the field width used in device DbLog don't meet the requirements. Please make sure that the width of database field definition is equal or larger than the field width used by the module. Compare the given results.
Currently the default values for field width are:

DEVICE: 64
TYPE: 64
EVENT: 512
READING: 64
VALUE: 128
UNIT: 32

You can change the column width in database by a statement like 'alter table current modify VALUE varchar(128);' (example for changing field 'VALUE'). You can do it for example by executing 'sqlCMD' in DbRep or in a SQL-Editor of your choice. (switch DbLog to asynchron mode for non-blocking).
The field width used by the module can be done by setting attributes 'colEvent', 'colReading', 'colValue',

Result of check 'Search_Idx' availability

Index 'Search_Idx' exists and contains the recommended fields 'DEVICE', 'READING', 'TIMESTAMP'.
Recommendation: settings o.k.

amenomade · 05 Juli 2017, 13:04:48

Ich würde zuerst ein

Code Auswählen

set <DblogDevice> configCheck machen.

Danach, was ergibt ein:

Code Auswählen

set <DblogDevice> addLog <devspec>:<Reading> [Value] , mit verbose 5 aktiviert?

Andere Frage: hast vielleicht den Attr asyncMode gesetzt? Wie testest Du, dass es in der Db nicht geschrieben wird?

Ein "list <DblogDevice>" könnte auch helfen.

Teamdrachen · 05 Juli 2017, 13:44:10

Andere Frage: hast vielleicht den Attr asyncMode gesetzt? Wie testest Du, dass es in der Db nicht geschrieben wird?

Ja und ich teste direkt über terminalfenster auf der Datenbank ob was reinommt.

Code Auswählen

mysql> select * from history;
+---------------------+----------------+-------------+--------+--------------+-------+------+
| TIMESTAMP           | DEVICE         | TYPE        | EVENT  | READING      | VALUE | UNIT |
+---------------------+----------------+-------------+--------+--------------+-------+------+
| 2017-07-05 13:15:40 | C_STROMZAEHLER | HOURCOUNTER | addLog | countsPerDay | 9     |      |
| 2017-07-05 13:23:16 | C_STROMZAEHLER | HOURCOUNTER | addLog | countsPerDay | 9     |      |
| 2017-07-05 13:23:45 | C_STROMZAEHLER | HOURCOUNTER | addLog | countsPerDay | 15    |      |
+---------------------+----------------+-------------+--------+--------------+-------+------+
3 rows in set (0.00 sec)

mysql> SHOW FULL PROCESSLIST;
+-----+----------+-----------------+------+---------+------+-------+-----------------------+
| Id  | User     | Host            | db   | Command | Time | State | Info                  |
+-----+----------+-----------------+------+---------+------+-------+-----------------------+
|  56 | root     | localhost       | fhem | Query   |    0 | NULL  | SHOW FULL PROCESSLIST |
| 177 | fhemuser | localhost:40212 | fhem | Sleep   | 1019 |       | NULL                  |
+-----+----------+-----------------+------+---------+------+-------+-----------------------+
2 rows in set (0.00 sec)

Direkte Eingabe über set <DblogDevice> addLog <devspec>:<Reading> [Value] funktioniert. wie schon geschrieben habe ich keine Probleme auf die Datenbank zuzugreifen und mit direkten Befehlen über das FHEM webinterface etwas auszulösen

Code Auswählen

2017.07.05 13:23:16 4: Connection accepted from WEB_83.221.236.205_64056
2017.07.05 13:23:16 4: WEB_83.221.236.205_64056 POST /fhem&fw_id=403&fwcsrf=csrf_864373417687297&cmd=set+DbLog+addLog+C_STROMZAEHLER%3AcountsPerDay+9; BUFLEN:0
2017.07.05 13:23:16 5: Cmd: >set DbLog addLog C_STROMZAEHLER:countsPerDay 9<
2017.07.05 13:23:16 4: DbLog DbLog -> Readings extracted from Regex: countsPerDay
2017.07.05 13:23:16 3: DbLog DbLog -> addLog created - TS: 2017-07-05 13:23:16, Device: C_STROMZAEHLER, Type: HOURCOUNTER, Event: addLog, Reading: countsPerDay, Value: 9, Unit: 
2017.07.05 13:23:16 4: WEB_83.221.236.205_64056 GET /fhem?fw_id=403; BUFLEN:0
2017.07.05 13:23:16 4: WEB: /fhem?fw_id=403 / RL:1720 / text/html; charset=UTF-8 / Content-Encoding: gzip
 / 
2017.07.05 13:23:16 4: WEB_83.221.236.205_64056 GET /fhem/pgm2/style.css?v=1499252076; BUFLEN:0
2017.07.05 13:23:16 4: WEB_83.221.236.205_64056 => 304 Not Modified
2017.07.05 13:23:16 5: DbLog DbLog -> ################################################################
2017.07.05 13:23:16 5: DbLog DbLog -> ###      New database processing cycle - asynchronous        ###
2017.07.05 13:23:16 5: DbLog DbLog -> ################################################################
2017.07.05 13:23:16 5: DbLog DbLog -> MemCache contains 1 entries to process
2017.07.05 13:23:16 5: DbLog DbLog -> MemCache contains: 2017-07-05 13:23:16|C_STROMZAEHLER|HOURCOUNTER|addLog|countsPerDay|9|
2017.07.05 13:23:16 4: BlockingCall (DbLog_PushAsync): created child (3348), uses telnetPort to connect back
2017.07.05 13:23:16 5: DbLog DbLog -> DbLog_PushAsync called with timeout: 1800
2017.07.05 13:23:16 5: DbLog DbLog -> Start DbLog_PushAsync
2017.07.05 13:23:16 4: Connection accepted from WEB_83.221.236.205_64057
2017.07.05 13:23:16 5: DbLog DbLog -> DbLogType is: Current/History
2017.07.05 13:23:16 4: Connection accepted from WEB_83.221.236.205_64058
2017.07.05 13:23:16 4: Connection accepted from WEB_83.221.236.205_64060
2017.07.05 13:23:16 4: Connection accepted from WEB_83.221.236.205_64059
2017.07.05 13:23:16 4: WEB_83.221.236.205_64059 GET /fhem/pgm2/jquery-ui.min.js; BUFLEN:0
2017.07.05 13:23:16 4: WEB_83.221.236.205_64059 => 304 Not Modified
2017.07.05 13:23:16 4: WEB_83.221.236.205_64058 GET /fhem/pgm2/fhemweb.js; BUFLEN:0
2017.07.05 13:23:16 5: DbLog DbLog -> Primary Key used in fhem.history: none
2017.07.05 13:23:16 5: DbLog DbLog -> Primary Key used in fhem.current: none
2017.07.05 13:23:16 4: WEB_83.221.236.205_64058 => 304 Not Modified
2017.07.05 13:23:16 5: DbLog DbLog -> processing event Timestamp: 2017-07-05 13:23:16, Device: C_STROMZAEHLER, Type: HOURCOUNTER, Event: addLog, Reading: countsPerDay, Value: 9, Unit: 
2017.07.05 13:23:16 4: WEB_83.221.236.205_64056 GET /fhem/pgm2/jquery-ui.min.css; BUFLEN:0
2017.07.05 13:23:16 5: DbLog DbLog -> 1 of 1 events inserted into table history

Ändere ich dagegen den Wert im device selber, greift irgendetwas nicht und es wird nichts geschrieben.

Code Auswählen

2017.07.05 13:40:12 4: WEB_83.221.236.205_64795 POST /fhem?cmd.setC_STROMZAEHLER%3Dset%20C_STROMZAEHLER%20countsPerDay%2016&XHR=1&fwcsrf=csrf_864373417687297&fw_id=440; BUFLEN:0
2017.07.05 13:40:12 5: Cmd: >set C_STROMZAEHLER countsPerDay 16<
2017.07.05 13:40:12 4: HourCounter C_STROMZAEHLER Set.343 hits: 0 needPara:1
2017.07.05 13:40:12 4: HourCounter C_STROMZAEHLER Set.349 command : countsPerDay 16
2017.07.05 13:40:12 5: Starting notify loop for C_STROMZAEHLER, 1 event(s), first is countsPerDay: 16
2017.07.05 13:40:12 5: createNotifyHash
2017.07.05 13:40:12 4: DbLog DbLog -> ################################################################
2017.07.05 13:40:12 4: DbLog DbLog -> ###              start of new Logcycle                       ###
2017.07.05 13:40:12 4: DbLog DbLog -> ################################################################
2017.07.05 13:40:12 4: DbLog DbLog -> amount of events received: 1 for device: C_STROMZAEHLER
2017.07.05 13:40:12 4: DbLog DbLog -> check Device: C_STROMZAEHLER , Event: countsPerDay: 16
2017.07.05 13:40:12 5: End notify loop for C_STROMZAEHLER
2017.07.05 13:40:12 4: WEB: /fhem?cmd.setC_STROMZAEHLER%3Dset%20C_STROMZAEHLER%20countsPerDay%2016&XHR=1&fwcsrf=csrf_864373417687297&fw_id=440 / RL:20 / text/plain; charset=UTF-8 / Content-Encoding: gzip

Code Auswählen

Internals: 
   COLUMNS    field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32 
   CONFIGURATION ./db.conf 
   DBMODEL    MYSQL 
   DEF        ./db.conf .*:.* 

   MODE       synchronous 
   MODEL      MYSQL 
   NAME       DbLog 
   NR         2 
   NTFY_ORDER 50-DbLog 
   PID        3194 
   REGEXP     .*:.* 

   STATE      connected 
   TYPE       DbLog 
   UTF8       0 
   VERSION    2.18.3 
   dbconn     mysql:database=fhem;host=127.000.000.001;port=3306 
   dbuser     fhemuser 
   HELPER: 
     COLSET     1 
     DEVICECOL  64 
     EVENTCOL   512 
     READINGCOL 64 
     TYPECOL    64 
     UNITCOL    32 
     VALUECOL   128 
   READINGS: 
     2017-07-05 13:49:16   CacheUsage      0 
     2017-07-05 13:49:16   NextSync        2017-07-05 13:49:46 or if CacheUsage 500 reached 
     2017-07-05 13:10:46   countCurrent    0 
     2017-07-05 13:10:46   countHistory    0 
     2017-07-05 13:11:21   reduceLogState  Rows processed: 0, deleted: 0, time: 0.00sec 
     2017-07-05 13:49:16   state           connected 
   cache: 
     index      2 
     memcache: 
Attributes: 
   DbLogType  Current/History 
   asyncMode  1 
   room       Automatik

amenomade · 05 Juli 2017, 13:51:43

ZitatAndere Frage: hast vielleicht den Attr asyncMode gesetzt?

Du antwortest "Ja...".

Zitat von: asyncMode

attr <device> asyncMode [1|0]
Dieses Attribut stellt den Arbeitsmodus von DbLog ein. Im asynchronen Modus (asyncMode=1), werden die zu speichernden Events zunächst in Speicher gecacht. Nach Ablauf der Synchronisationszeit (Attribut syncInterval) oder bei Erreichen der maximalen Anzahl der Datensätze im Cache (Attribut cacheLimit) werden die gecachten Events im Block in die Datenbank geschrieben.

Defaultwert für cacheLimit ist 500.
Defautlwert für syncInterval ist 30 Sek.

Zeig mal ein "list DbLog"

Teamdrachen · 05 Juli 2017, 13:56:00

Listing vom DbLog ist im Post drüber, hatte gerade editiert.
Der Cache beträgt 500 Einträge , oder 30 Sekunden. Die Zeit wurde gewartet und der Cache wird auch mit 0 Einträgen gelistet.
Der async Mode war auch erst etwa 20 Minuten drin zu testzwecken.

amenomade · 05 Juli 2017, 16:20:27

Ok anscheinend soweit in Ordnung.
Du hast aber nicht geantwortet: was sagt ein

Code Auswählen

set <DblogDevice> configCheck ?

amenomade · 05 Juli 2017, 16:29:49

Und hast Du überhaupt Einträge in der "current" Tabelle?

EDIT: mit SQlite ist die "current" Tabelle im Speicher. Bei mySQL weiss ich nicht. Dann lieber die DbLog durch ein "get" in fhemweb abfragen.

Teamdrachen · 05 Juli 2017, 16:56:42

Configcheck hatte ich schon mal gepostet, aber da es kein Aufwand ist.

Code Auswählen

Result of connection check

Connection to database fhem successfully done. 
Recommendation: settings o.k. 

Result of encoding check

Encoding used by Client (connection): LATIN1 
Encoding used by fhem: UTF8 
Recommendation: Both encodings should be identical. You can adjust the usage of UTF8 connection by setting the UTF8 parameter in file './db.conf' to the right value. 

Result of logmode check

Logmode of DbLog-device DbLog is: synchronous 
Recommendation: Switch DbLog to the asynchronous logmode by setting the 'asyncMode' attribute. The advantage of this mode is to log events non-blocking. 
There are attributes 'syncInterval' and 'cacheLimit' relevant for this working mode. 
Please refer to Commandref attributes for further informations. 

Result of table 'history' check

Column width set in DB fhem: 'DEVICE' = 64, 'TYPE' = 64, 'EVENT' = 512, 'READING' = 64, 'VALUE' = 128, 'UNIT' = 32 
Column width used by DbLog: '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 DB fhem: 'DEVICE' = 64, 'TYPE' = 64, 'EVENT' = 512, 'READING' = 64, 'VALUE' = 128, 'UNIT' = 32 
Column width used by DbLog: '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 the recommended fields 'DEVICE', 'READING', 'TIMESTAMP'. 
Recommendation: settings o.k. 

Result of check 'Reading_Time_Idx' availability for DbRep-devices

You don't use any DbRep-device assigned to DbLog. Hence an index for DbRep isn't needed. 
Recommendation: settings o.k.

Current hat den letzten Wert, der über manuelles addlog eingegeben wurde
FHEM startet den Logcycle und bricht dann einfach ab, bzw. nach

Code Auswählen

 WEB: /fhem?cmd.setC_STROMZAEHLER%3Dset%20C_STROMZAEHLER%20countsPerDay%2016&XHR=1&fwcsrf=csrf_864373417687297&fw_id=440 / RL:20 / text/plain; charset=UTF-8 / Content-Encoding: gzip

geht es nicht weiter.

amenomade · 05 Juli 2017, 17:30:42

Ich habe ein bisschen im Modul geschaut, und jetzt würde mich ein "list C_STROMZAEHLER" interessieren.

Teamdrachen · 05 Juli 2017, 17:55:49

Ich habe jetzt einfach alle configs gelöscht und noch mal neu gemacht.

Es loggt wieder.
Zurück auf SQLite
Es loggt immer noch

Ich verstehe immer noch nicht, wieso die Logs gestern Abend 22.30 plötzlich aufhörten.
Im Moment lüppt es wieder und vor allem, das es absolut keine Fehlermeldung gab.

Jetzt funktioniert es wieder dafür fehlt im DB Device der Punkt "configCheck"
Führe ich diesen durch Eingabe aus erhalte ich

Code Auswählen

Result of connection check

Connection to database was not successful. 
Recommendation: Plese see logfile for further information.

Aber es loggt.

amenomade · 05 Juli 2017, 18:46:50

Eigentlich komisch...

Kann es sein, dass Du dich mit den verschiedenen Einstellungen verwirrt hast... z.B. irgendwo loggen, aber irgendwo anders die Events gesucht? Hast fhem jedes mal neugestartet?

Ich verstehe das auch nicht... aber wenn es jetzt läuft...

Teamdrachen · 06 Juli 2017, 08:03:14

Das System lief vor einem Überspannungsschaden schon ~2 Jahre und die Events vom HourCounter sind ja gleich geblieben.
Neu ist nur die Hardware von Rpi2 auf Rpi3
Seltsam auch, es hörte in der Nacht grundlos auf zu loggen.
Ja, FHEM wurde nach jeder Änderung neu gestartet.

Gestern den halben Tag damit verbracht einen Gremlin zu jagen. So lange er nicht wieder kommt geb ich mich damit zufrieden.