Hallo,
Ich habe das Problem das nach einen restart von Fhem meine dbrep Instanzen immer auf disconnect gehen. Wenn ich unter def die Datenbank logdb neu eintragen dann initialisiert sich das Modul, sobald ich z.b countEntries ausführe geht das Modul direkt wieder auf disconnected. Wenn ich garnichts mache dann bleiben die dbrep Module auf disconnected, wenn ich öfter mal die Definition neu eintrage geht es irgendwann wieder..... wenn es einmal geht da laufen die dbrep Instanzen ohne Probleme bis zum nächsten restart..... Mein Ziel ist es das die dbrep Modul nach eine restart direkt wieder connecten.....
Internals:
DATABASE fhem
DEF logdb
FUUID 5c44a29d-f33f-0405-ad45-eefb16c44ff76281
LASTCMD insert 2019-04-15,21:00:00,134.5
MODEL Client
NAME logdb_strom_WP
NOTIFYDEV global,logdb_strom_WP
NR 516
NTFY_ORDER 50-logdb_strom_WP
ROLE Client
STATE disconnected
TYPE DbRep
UTF8 0
VERSION 8.13.0
.attraggr:
.attrminint:
HELPER:
DBLOGDEVICE logdb
IDRETRIES -135
I_DEVICE Verbrauch_Monat_WP_doif
I_EVENT manual
I_READING Verbrauch
I_TIMESTAMP 2019-04-15 21:00:00
I_TYPE manual
I_UNIT
I_VALUE 134.5
DBREPCOL:
COLSET 1
DEVICE 64
EVENT 512
READING 64
TYPE 64
UNIT 32
VALUE 128
READINGS:
2019-04-17 05:19:01 state disconnected
dbloghash:
.triggerUsed 1
COLUMNS field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32
CONFIGURATION ./dbsynology.conf
DEF ./dbsynology.conf .*:.*
FUUID 5c44a297-f33f-0405-eba5-375314849666f35f
MODE asynchronous
MODEL MYSQL
NAME logdb
NR 184
NTFY_ORDER 50-logdb
PID 1023
REGEXP .*:.*
STATE connected
TYPE DbLog
UTF8 0
VERSION 3.13.1
dbconn mysql:database=fhem;host=192.168.1.20;port=3306
dbuser fhemuser
.attraggr:
.attrminint:
.userReadings:
HASH(0x55c565487d38)
HELPER:
COLSET 1
DEVICECOL 64
EVENTCOL 512
OLDSTATE connected
READINGCOL 64
TYPECOL 64
UNITCOL 32
VALUECOL 128
READINGS:
2019-04-17 06:37:36 CacheUsage 3
2019-04-17 06:37:35 NextSync 2019-04-17 06:38:05 or if CacheUsage 500 reached
2019-04-17 06:37:36 notify_processing_time 0.0004
2019-04-17 06:37:35 state connected
cache:
index 41302
.memcache:
41300 2019-04-17 06:37:36|WP_HTTPMod|HTTPMOD|FBH_VL: 29.3|FBH_VL|29.3|
41301 2019-04-17 06:37:36|WP_HTTPMod|HTTPMOD|SO_RL_2: 17.0|SO_RL_2|17.0|
41302 2019-04-17 06:37:36|WP_HTTPMod|HTTPMOD|SO_VL: 9.8|SO_VL|9.8|
Attributes:
allowDeletion 1
device Verbrauch_Monat_WP_doif
fastStart 1
group Datenbank
reading Verbrauch
room JCT
timeout 86400
timestamp_begin current_month_begin
timestamp_end current_month_end
verbose 2
Internals:
.triggerUsed 1
COLUMNS field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32
CONFIGURATION ./dbsynology.conf
DEF ./dbsynology.conf .*:.*
FUUID 5c44a297-f33f-0405-eba5-375314849666f35f
MODE asynchronous
MODEL MYSQL
NAME logdb
NR 184
NTFY_ORDER 50-logdb
PID 1023
REGEXP .*:.*
STATE connected
TYPE DbLog
UTF8 0
VERSION 3.13.1
dbconn mysql:database=fhem;host=192.168.1.20;port=3306
dbuser fhemuser
.attraggr:
.attrminint:
.userReadings:
HASH(0x55c565487d38)
HELPER:
COLSET 1
DEVICECOL 64
EVENTCOL 512
OLDSTATE connected
READINGCOL 64
TYPECOL 64
UNITCOL 32
VALUECOL 128
READINGS:
2019-04-17 06:37:01 CacheUsage 12
2019-04-17 06:36:35 NextSync 2019-04-17 06:37:05 or if CacheUsage 500 reached
2019-04-17 06:37:01 notify_processing_time 0.0023
2019-04-17 06:36:35 state connected
cache:
index 41286
.memcache:
41275 2019-04-17 06:36:35|Tuerschloss|CUL_HM|state: unreachable|state|unreachable|
41276 2019-04-17 06:36:37|WP_HTTPMod|HTTPMOD|FBH_RL: 28.5|FBH_RL|28.5|
41277 2019-04-17 06:36:37|WP_HTTPMod|HTTPMOD|SO_RL: 9.3|SO_RL|9.3|
41278 2019-04-17 06:36:46|WP_HTTPMod|HTTPMOD|SO_RL: 9.4|SO_RL|9.4|
41279 2019-04-17 06:36:46|WP_HTTPMod|HTTPMOD|SO_RL_2: 17.0|SO_RL_2|17.0|
41280 2019-04-17 06:36:53|Stromzaehler_WP|DOIF|wh: 2892720|wh|2892720|
41281 2019-04-17 06:36:54|Wz_Heizung|CUL_HM|desired-temp: 18.0|desired-temp|18.0|
41282 2019-04-17 06:36:56|WP_HTTPMod|HTTPMOD|FBH_RL: 28.4|FBH_RL|28.4|
41283 2019-04-17 06:36:56|WP_HTTPMod|HTTPMOD|SO_RL_2: 16.9|SO_RL_2|16.9|
41284 2019-04-17 06:37:01|sysmon|SYSMON|ram_free: 3524.13|ram_free|3524.13|
41285 2019-04-17 06:37:01|sysmon|SYSMON|eth0_diff_RX: 1107.25|eth0_diff_RX|1107.25|
41286 2019-04-17 06:37:01|sysmon|SYSMON|eth0_diff_TX: 1246.46|eth0_diff_TX|1246.46|
Attributes:
DbLogSelectionMode Include
DbLogType Current/History
asyncMode 1
disable 0
group Datenbank
room JCT
showNotifyTime 1
shutdownWait 2
userReadings DbFileSize:reduceLogState.* { (split(' ',`du -m fhem.db`))[0] }
Vielen Dank für eure Hilfe
Gruß
Thorsten
Sorgt das Attribut Faststart nicht dafür dass das DbRep erst beim ersten Gebrauch initialisiert wird?
Nimm das mal raus und teste nochmal.
Gesendet von meinem Doogee S60 mit Tapatalk
Habe ich mal getestet... beim Start sind die Module initialized, sobald darauf zugegriffen wird gehen diese auf disconnect.
Guten Morgen,
aus irgendwelchen Gründen dauert das Holen der initialen Informationen sehr lange bzw. bricht ab. Du müsstest mal den verbose Level hochdrehen und ins Log schauen was dort ausgeschrieben wird wenn das Device losgelassen wird.
Wo befindet sich deine Datenbank ?
Ich habe seit einem der letzten Synology Updates ein ähnliches Problem mit MariaDB10 auf der Syno, die MariaDB5 auf der gleichen Maschine läuft weiterhin ohne Probleme.
Bei der MariaDB10 dauert der erste Connect über 160s :
2019.04.17 08:05:52.049 3: DbRep Rep.CPU - Initial data information retrieved successfully - total time used: 162.532141 seconds
2019.04.17 08:05:52.066 3: DbRep Rep.CPU - Connectiontest to db mysql:database=fhemtest;host=192.168.2.10;port=3307 successful
Wenn die initialen Informationen geholt sind, funktioniert alles weitere dann wieder einwandfrei.
Gib mal bitte ein paar Infos zu deiner eingesetzten DB.
Der Grund liegt wahrscheinlich darin, dass der Befehl:
SELECT min(TIMESTAMP) FROM history;
(zu) lange dauert.
Kannst du diesen Befehl mal auf deiner DB ausführen und die Zeit messen ? Er dauert auf meiner MariaDB5 0.0009 s, auf der MariaDB10 über 100s. Möglicherweise liegt es auch an einem Index, ich muß mir das mal auf dieser DB genauer anschauen.
LG,
Heiko
Ich habe den Befehl
SELECT min(TIMESTAMP) FROM history;
soeben mal auf einer anderen MariaDB10 ausgeführt. Er dauerte nur 0.0010 Sekunden bei 31463560 Datensätzen.
Also irgendwie liegt es spezifisch and der MariaDB10 auf der Syno.
Hey DSStarter,
SELECT min(TIMESTAMP) FROM history;
Bei meiner MariaDB10 dauert es 18,2316 Sekunden bei 18.2316 Datensätzen....
Also liegt der Fehler an der Synology? Welchen daten über die Datenbank brauchst du den?
Gruß und danke
Thorsten
Hi Thorsten,
mir reicht erstmal die Info ob du auch MariaDB10 auf Synology nutzt.
Die Anzahl der Datensätze passt irgendwie nicht ;)
Das Problem will ich heute Abend versuchen auf meiner Maria10 näher einzugrenzen.
LG,
Heiko
Hallo,
MariaDB10 ist installiert auf der Synology, aber diese wird nicht verwendet.... Verwendet wird nur die MariaDB5...
eine dbrep habe ich mal auf verbose 5 gestellt. Diese war disconnected...nachher war diese dann wieder connectet.....hmm
Dann bis heute Abend :-)
2019.04.17 09:46:00 3: DbRep logdb_strom_monat_jct - get initial structure information of database "fhem", remaining attempts: -76
2019.04.17 09:46:13 4: DbRep logdb_strom_monat_jct - initialized
2019.04.17 09:46:17 3: DbRep logdb_strom_monat_jct - Connectiontest to database mysql:database=fhem;host=192.168.1.20;port=3306 with user fhemuser
2019.04.17 09:46:22 3: DbRep logdb_strom_monat_jct - WARNING - old process 32283 will be killed now to start a new BlockingCall
2019.04.17 09:46:22 1: DbRep logdb_strom_monat_jct -> BlockingCall DbRep_getInitData pid:32283 Timeout: process terminated
2019.04.17 09:46:22 3: DbRep logdb_strom_monat_jct - get initial structure information of database "fhem", remaining attempts: 3
2019.04.17 09:46:22 3: DbRep logdb_strom_monat_jct - Connectiontest to database mysql:database=fhem;host=192.168.1.20;port=3306 with user fhemuser
2019.04.17 09:46:42 3: DbRep logdb_strom_monat_jct - Initial data information retrieved successfully - total time used: 20.449708 seconds
2019.04.17 09:46:42 3: DbRep logdb_strom_monat_jct - Connectiontest to db mysql:database=fhem;host=192.168.1.20;port=3306 successful
2019.04.17 09:46:42 4: DbRep logdb_strom_monat_jct - -------- New selection ---------
2019.04.17 09:46:42 4: DbRep logdb_strom_monat_jct - Command: countEntries history
2019.04.17 09:46:42 5: DbRep logdb_strom_monat_jct - Timestamp begin epocheseconds: 1555452000
2019.04.17 09:46:42 4: DbRep logdb_strom_monat_jct - Timestamp begin human readable: 2019-04-17 00:00:00
2019.04.17 09:46:42 5: DbRep logdb_strom_monat_jct - Timestamp end epocheseconds: 1555538399
2019.04.17 09:46:42 4: DbRep logdb_strom_monat_jct - Timestamp end human readable: 2019-04-17 23:59:59
2019.04.17 09:46:42 5: DbRep logdb_strom_monat_jct - weekday of start for selection: Mi -> wdadd: 432000
2019.04.17 09:46:42 4: DbRep logdb_strom_monat_jct - Aggregation: no
2019.04.17 09:46:42 5: DbRep logdb_strom_monat_jct - IsTimeSet: 1, IsAggrSet: 0
2019.04.17 09:46:42 5: DbRep logdb_strom_monat_jct - Timestamp-Array:
no_aggregation#2019-04-17 00:00:00#2019-04-17 23:59:59
2019.04.17 09:46:42 5: DbRep logdb_strom_monat_jct - Devices for operation - included: Verbrauch_heute_doif , excluded:
2019.04.17 09:46:42 5: DbRep logdb_strom_monat_jct - Readings for operation - included: Verbrauch, excluded:
2019.04.17 09:46:42 4: DbRep logdb_strom_monat_jct - SQL execute: SELECT COUNT(*) FROM history where DEVICE = 'Verbrauch_heute_doif' AND READING = 'Verbrauch' AND TIMESTAMP >= '2019-04-17 00:00:00' AND TIMESTAMP <= '2019-04-17 23:59:59' ;
2019.04.17 09:46:42 5: DbRep logdb_strom_monat_jct - SQL result: 1
2019.04.17 09:46:42 5: DbRep logdb_strom_monat_jct - SQL result decoded: no_aggregation#ALLREADINGS#1#2019-04-17|
Bis heute Abend :)
Ich hab schon etwas gesehen:
2019.04.17 09:46:22 3: DbRep logdb_strom_monat_jct - WARNING - old process 32283 will be killed now to start a new BlockingCall
2019.04.17 09:46:22 1: DbRep logdb_strom_monat_jct -> BlockingCall DbRep_getInitData pid:32283 Timeout: process terminated
Wahrscheinlich startest du aus Ungeduld ;) weil nach dem Anstarten von countEntries nichts passiert, es nochmal an.
Dadurch wird der (zu lange laufende initiale Connect) abgebrochen und neu aufgesetzt.
Einfach nichts tun und warten nach dem ersten Anstarten. :)
Den Rest später ...
Hey,
das Problem tritt wahrscheinlich deshalb auf, weil ich mit einen doif alte Datensätze lösche und die neuen dann 4 Sekunden später einfüge. Das ganze ca alle 180 Sekunden.
Wenn ich das entsprechende doif disable und ich bei den dbrep im initialisierten Zustand Manuel eine Aktion ausführe und ich abwarte, dann steht im state später done....
Gruß
Thorsten
Ja genau.
Lösung wäre für beide Aufgaben jeweils ein zugeodnetes DbRep zu verwenden.
Einfach kopieren.
LG
Hey Heiko,
so habe ich das nun gelöst.....
([Stromzaehler_JCT:energy]and [00:30-23:59]and [logdb_strom_monat_jct]ne "initialized")
(setreading $SELF Verbrauch {([Zaehlerstand_doif:Zaehlerstand]-[Zaehlerstand_doif:Zaehlerstand_gestern])})
(set logdb_strom_monat_jct delEntries)
{ fhem "set logdb_strom_monat_jct insert ".$year."-".sprintf("%02d",$month)."-".sprintf("%02d",$mday).",00:00:00,".(ReadingsNum("Verbrauch_heute_doif","Verbrauch",0) ) }
DOELSE
So greifen die doif´s erst auf das dbrep zu wenn es nicht mehr am initialisieren ist.... Hat nach einen neustart von fhem super funktioniert.... Danke für die Hilfe :-)
Gruß
Thorsten
Hallo Thorsten,
prima :)
Ich bin auch schon ein Stückchen weiter.
Es ist nicht das Problem der DB, sondern eine ungüstige Indexverwendung. Ich versuche das Statement zu verändern um das Problem an der Wurzel zu beseitigen.
Du könntest einen Test im DbRep machen wenn ich etwas brauchbares habe.
Grüße,
Heiko
Kannst du mal bitte im DbRep ausführen:
set ... sqlCmd ALTER TABLE `fhemtest`.`history` DROP INDEX `Report_Idx`, ADD INDEX `Report_Idx` (TIMESTAMP,READING) USING BTREE;
Das sollte längere Zeit laufen. Wenn nicht, alternativ dann bitte getrennt durchführen:
set ... sqlCmd ALTER TABLE `fhemtest`.`history` DROP INDEX `Report_Idx`;
set ... sqlCmd ALTER TABLE ADD INDEX `Report_Idx` (TIMESTAMP,READING) USING BTREE;
Wenn das durch ist, ein
get ... minTimestamp
ausführen. Jetzt sollte die Abfrage im Millisekundenbereich eine Antwort bringen.
Grüße,
Heiko
Hey,
Beides geht leider nicht:
DBD::mysql::st execute failed: Table 'fhemtest.history' doesn't exist at ./FHEM/93_DbRep.pm line 5673.
Gruß
Thorsten
Gesendet von iPhone mit Tapatalk
Sorry, du musst natürlich "fhemtest" mit dem Namen deiner Datenbank ersetzen. Sollte bei dir "fhem" sein.
Nun ist der error:
DBD::mysql::st execute failed: Can't DROP 'Report_Idx'; check that column/key exists at ./FHEM/93_DbRep.pm line 5673.
Gesendet von iPhone mit Tapatalk
Dann hattest du noch keinen Report_Idx angelegt. Einfach fortfahren mit:
set ... sqlCmd ALTER TABLE `fhem`.`history` ADD INDEX `Report_Idx` (TIMESTAMP,READING) USING BTREE;
Der erste Teil ging jetzt... beim zweiten Teil:
sqlCmd ALTER TABLE ADD INDEX `Report_Idx` (TIMESTAMP,READING) USING BTREE
Kommt der error...
DBD::mysql::st execute failed: You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near 'ADD INDEX `Report_Idx` (TIMESTAMP,READING) USING BTREE' at line 1 at ./FHEM/93_DbRep.pm line 5673.
Da fehlt die Tabellenangabe. Schreibfehler:
sqlCmd ALTER TABLE `fhem`.`history` ADD INDEX `Report_Idx` (TIMESTAMP,READING) USING BTREE
Hmm, jetzt kommt der error:
DBD::mysql::st execute failed: Duplicate key name 'Report_Idx' at ./FHEM/93_DbRep.pm line 5673.
Muss aber gleich Schluss machen für heute...sorry
Na dann als letzten Versuch für heute in dieser Reihenfolge nacheinander:
set ... sqlCmd ALTER TABLE `fhemtest`.`history` DROP INDEX `Report_Idx`;
set ... sqlCmd ALTER TABLE `fhemtest`.`history` ADD INDEX `Report_Idx` (TIMESTAMP,READING) USING BTREE;
Wirst sehen, alle guten Dinge sind 3 :)
Hey,
Jup alles gute ist drei :-)
Jetzt gehts...
get ... minTimestamp
Ging sehr schnell.... das heisst jetzt? Jetzt erstmal Nachtruhe :-)
Gruß
Thorsten
Jo, schlaf gut :D
Das heißt ich muss die Empfehlung für die Indexerstellung für DbRep anpassen. Und du kannst morgen dein DOIF entflechten. ;)
LG,
Heiko
Hallo,
ich habe meine doif´s jetzt wieder umgestellt.... die dbrep´s gehen nacht dem fhem neustart nun sofort auf connected. Top :-) Muss ich das irgendwann wiederholen ? Oder inwieweit und was verbessert du noch?
vielen dank nochmal
Gruß
Thorsten
Hallo Thorsten,
du bist quasi fertig, brauchst nichts wiederholen. Der Index ist nun passend erstellt.
ZitatOder inwieweit und was verbessert du noch?
Ich werde im nächsten DbRep-Release die Empfehlung zum Index in der Commandref anpassen. Der check in DbLog bekommt diese Änderung auch.
Außerdem werde ich im DbRep eine Set-Funktion einbauen, mit sich der Nutzer alle benötigten Indexe per Knopfdruck in den Tabellen erzeugen oder erneuern kann. Das ist einfacher für den User und macht es mir auch leichter eventuelle Änderungen auszurollen.
Dann reicht der Hinweis zur Ausführung von "set ... (re)createIndex ..." und der neue/geänderte Index ist da.
Das kommuniziere ich zu gegebenener Zeit im DbRep-Thread.
LG und schöne Ostern,
Heiko