93_DbLog - Umstellung Log-Funktion auf non-blocking

[DS_Starter]

Hallo zusammen,

das sind etwas zu wenig Infos. Ihr müßtet mal verbose 4 oder 5 einstellen damit ein paar Logs kommen.

state old BlockingCall is running - resync at NextSync

bedeutet dass ein Synclauf noch nicht fertig ist wenn der ein neuer loslaufen soll. Erstmal kein Fehler wenn es sich nicht ständig wiederholt.

@stromer-12, zurück auf 2.5 mußt du nicht .... stell einfach wieder auf asyncMode=0.
Auch hier brauchen wir mal ein paar Infos aus dem log.

Grüße
Heiko

[DS_Starter]

Hier ist zunächst kein Fehler ... nun stell mal bitte verbose 5 ein.
Du müßtest nach Ablauf von SyncInterval einen Eintrag finden der ungefähr so aussieht:

Code Auswählen Erweitern


2017.01.05 23:19:30.936 5: DbLog LogDB -> ################################################################
2017.01.05 23:19:30.937 5: DbLog LogDB -> ###              New database processing cycle                                                                             ###
2017.01.05 23:19:30.937 5: DbLog LogDB -> ################################################################
2017.01.05 23:19:30.937 5: DbLog LogDB -> MemCache contains 17 entries to process
2017.01.05 23:19:30.937 5: DbLog LogDB -> MemCache contains: 2017-01-05 23:18:48|SMA_Energymeter|SMAEM|Bezug_WirkP_Zaehler_Diff: 0.0144|Bezug_WirkP_Zaehler_Diff|0.0144|
2017.01.05 23:19:30.937 5: DbLog LogDB -> MemCache contains: 2017-01-05 23:18:48|SMA_Energymeter|SMAEM|Bezug_WirkP_Kosten_Diff: 0.0031|Bezug_WirkP_Kosten_Diff|0.0031|
2017.01.05 23:19:30.937 5: DbLog LogDB -> MemCache contains: 2017-01-05 23:18:48|SMA_Energymeter|SMAEM|Einspeisung_WirkP_Zaehler_Diff: 0|Einspeisung_WirkP_Zaehler_Diff|0|
2017.01.05 23:19:30.937 5: DbLog LogDB -> MemCache contains: 2017-01-05 23:18:48|SMA_Energymeter|SMAEM|Einspeisung_WirkP_Verguet_Diff: 0.0000|Einspeisung_WirkP_Verguet_Diff|0.0000|
2017.01.05 23:19:30.937 5: DbLog LogDB -> MemCache contains: 2017-01-05 23:18:48|SMA_Energymeter|SMAEM|-866.1|state|-866.1|
2017.01.05 23:19:30.938 5: DbLog LogDB -> MemCache contains: 2017-01-05 23:18:48|SMA_Energymeter|SMAEM|Saldo_Wirkleistung: -866.1|Saldo_Wirkleistung|-866.1|
2017.01.05 23:19:30.938 5: DbLog LogDB -> MemCache contains: 2017-01-05 23:18:48|SMA_Energymeter|SMAEM|Bezug_Wirkleistung: 866.1|Bezug_Wirkleistung|866.1|
2017.01.05 23:19:30.938 5: DbLog LogDB -> MemCache contains: 2017-01-05 23:18:48|SMA_Energymeter|SMAEM|Bezug_Wirkleistung_Zaehler: 1308.6693|Bezug_Wirkleistung_Zaehler|1308.6693|
2017.01.05 23:19:30.938 5: DbLog LogDB -> MemCache contains: 2017-01-05 23:18:48|SMA_Energymeter|SMAEM|Einspeisung_Wirkleistung: 0.0|Einspeisung_Wirkleistung|0.0|
2017.01.05 23:19:30.938 5: DbLog LogDB -> MemCache contains: 2017-01-05 23:18:48|SMA_Energymeter|SMAEM|Einspeisung_Wirkleistung_Zaehler: 1572.8506|Einspeisung_Wirkleistung_Zaehler|1572.8506|
2017.01.05 23:19:30.938 5: DbLog LogDB -> MemCache contains: 2017-01-05 23:18:49|MySTP_5000|SMAINVERTER|done|state|done|
2017.01.05 23:19:30.938 5: DbLog LogDB -> MemCache contains: 2017-01-05 23:18:49|Dum.Energy|DUMMY|TotalConsumption: 866.1|TotalConsumption|866.1|
2017.01.05 23:19:30.938 5: DbLog LogDB -> MemCache contains: 2017-01-05 23:19:17|sysmon|SYSMON|ram: Total: 876.27 MB, Used: 577.29 MB, 65.88 %, Free: 298.97 MB|ram|Total: 876.27 MB, Used: 577.29 MB, 65.88 %, Free: 298.97 MB|
2017.01.05 23:19:30.938 5: DbLog LogDB -> MemCache contains: 2017-01-05 23:19:17|sysmon|SYSMON|stat_cpu_percent: 1.36 0.00 0.49 97.87 0.14 0.00 0.14|stat_cpu_percent|1.36 0.00 0.49 97.87 0.14 0.00 0.14|
2017.01.05 23:19:30.938 5: DbLog LogDB -> MemCache contains: 2017-01-05 23:19:17|sysmon|SYSMON|eth0_diff: RX: 0.33 MB, TX: 0.08 MB, Total: 0.41 MB|eth0_diff|RX: 0.33 MB, TX: 0.08 MB, Total: 0.41 MB|
2017.01.05 23:19:30.938 5: DbLog LogDB -> MemCache contains: 2017-01-05 23:19:17|sysmon|SYSMON|swap: Total: 1293.00 MB, Used: 39.18 MB,  3.03 %, Free: 1253.82 MB|swap|Total: 1293.00 MB, Used: 39.18 MB,  3.03 %, Free: 1253.82 MB|
2017.01.05 23:19:30.939 5: DbLog LogDB -> MemCache contains: 2017-01-05 23:19:17|sysmon|SYSMON|loadavg: 0.02 0.10 0.12|loadavg|0.02 0.10 0.12|
2017.01.05 23:19:30.948 5: DbLog LogDB -> DbLog_PushAsync called with timeout: 60
2017.01.05 23:19:30.953 5: DbLog LogDB -> Start DbLog_PushAsync
2017.01.05 23:19:30.957 5: DbLog LogDB -> processing event Timestamp: 2017-01-05 23:18:48, Device: SMA_Energymeter, Type: SMAEM, Event: Bezug_WirkP_Zaehler_Diff: 0.0144, Reading: Bezug_WirkP_Zaehler_Diff, Value: 0.0144, Unit:
.....


Schau mal wie es bei dir aussieht.

[DS_Starter]

Ich glaube noch einen Fehler gefunden zu haben der bei mir nicht aufgefallen ist.

Versuche mal die V2.8.1. Mach bitte auf jeden Fall ein FHEM Restart.

Grüße
Heiko

[Newbie]

Heiko,

ja das war es funktioniert. SUPER

[DS_Starter]

Sehr schön 

Gute Nacht !

[stromer-12]

Moin,

Gestern waren folgede Fehler:

Code Auswählen Erweitern

2017.01.05 22:16:16.803 2: DbLog myDbLog -> Error: DBD::mysql::db begin_work failed: Turning off AutoCommit failed at ./FHEM/93_DbLog.pm line 920.
2017.01.05 22:16:16.806 1: PERL WARNING: rollback ineffective with AutoCommit enabled at ./FHEM/93_DbLog.pm line 991.

und einmalig nach dem ersten Restart:

Code Auswählen Erweitern

Undefined subroutine &main::tv_interval called at ./FHEM/93_DbLog.pm line 1257.

und selbiger dauernder state wie bei newbie.

Mit der 2.8.1 läuft es jetzt.

[DS_Starter]

Moin stromer-12,

super dass es nun auch bei dir klappt. Hatte vergessen ein Perl-Modul zu laden was bei mir bereits mit DbRep verwendet wird. Deswegen
hatte ich bei mir auch keine Sorgen deswegen.

Grüße
Heiko

[Tobias]

Wenn ich die Version 2.8.1. downloade, hört bei mir das Modul mitten in der Doku  in Zeile 3257 auf.
Kannst du mal bitte nachsehen?

[DS_Starter]

Hi Tobias,

bin grad bei der Doku am überarbeiten. Habe auch festgestellt dass mir der Editor, warum auch immer, in der 2.8.1 einen Streich gespielt hat.
Stelle die Version mit überarbeiteter Doku in Kürze hier rein.

Grüße
Heiko

[DS_Starter]

Hi Tobias, @all,

anbei die Version 2.8.2 in der die Commandref überarbeitet und mit der Beschreibung der neuen Attribute ergänzt ist.
Ich habe sie auch mit commandref_join.pl gecheckt -> no issues.

Grüße
Heiko

[Tobias]

hab ich jetzt am laufen... WOW, nun sehe ich mal was so alles in 30sek bei mir aufläuft... immer zwischen 100 und 130 Datensätze...

nach den vielen Rückmeldungen checke ich es nun ein
Edit: laufen denn die GET abfragen für die Plots auch asyncron?
Edit2: nimm mal bitte für eine Weiterentwicklung die aus dem Repo, ich habe die Item Summary´s noch eingefügt

[DS_Starter]

Hi Tobias,

laufen denn die GET abfragen für die Plots auch asyncron?

Nein, bis jetzt habe ich "nur" die eigentliche Log-Funktion, also DbLog_Log und was dazu drumherum nötig war aufgebohrt.
Alle anderen Funktionen wie GET oder auch Reducelog usw. sind nicht berührt und laufen wie bisher.
Der asynchrone Modus verwendet auch ein eigenes Datenbankhandle was undabhängig ist vom "normalen" $dbh.

Das wäre also noch eine mögliche Weiterentwicklung ...

nimm mal bitte für eine Weiterentwicklung die aus dem Repo, ich habe die Item Summary´s noch eingefügt

ok, mach ich.

Grüße
Heiko

[rudolfkoenig]

laufen denn die GET abfragen für die Plots auch asyncron?

Wenn plotfork gesetzt ist, dann ja. Bitte lieber plotfork unterstuetzen, und nicht "asynchrones get" implementieren, da ohne plotfork das aufwendigere SVG-Erstellen synchron bleibt.

[Tobias]

Hi rudi,
abe greift denn plotfork auch unabhängig der SVG Erstellung? Also zb. wenn TabletUI Daten für den eigenen Chart abzieht?

[DS_Starter]

Vielleicht nochmal zum gegenseitigen Abgleich was ich unter dem asynchronen Modus für die Get-Funktion verstanden habe.
Es würde für mich bedeuten, dass beim GET auch Daten aus dem Cache mit berücksichtigt werden (wenn async Mode an) und sich noch nicht in der DB befinden. Das würde dem Hinweis/Wunsch von Joe entsprechen.

War es das was du meintest Tobias /Rudi oder ein anderer Gedanke ?