Hallo!
Ich würde ein wenig Hilfe bei der Fehlersuche benötigen. Ich musste mein komplettes System wiederherstellen, dabei auch die MariaDB in die ich logge. Ohne Änderungen an der FHEM Konfiguration werden jetzt einige Readings nicht mehr geloggt. Der Status ist aber korrekt und ändert sich stetig. An DBlog exclude/include hat sich nichts geändert. Ich bekomme für mich kryptische Fehlermeldungen im FHEM Log:
2023.01.04 12:15:22 2: DbLog DBLogging - Error table history - 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 '' at line 1 [for Statement "INSERT IGNORE INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES"] at ./FHEM/93_DbLog.pm line 2757.
2023.01.04 12:15:22 2: DbLog DBLogging - Transaction is switched off. Transferred data is lost.
Danke!
Matthias
Das ist keine Anfängerfrage, sondern eine Problembeschreibung zu DbLog.
Das solltest Du im richtigen Unterforum schreiben bzw. diesen Thread dorthin verschieben, damit der Modulautor davon auch etwas mitbekommt.
https://forum.fhem.de/index.php/topic,13092.0.html
Sorry ich fühl mich immernoch so anfängerig :-[
Ich versuches...
Hallo Matthias,
bitte ein list deines DbLog Devices posten.
Hallo DS_Starter,
vielen Dank, anbei:
Internals:
COLUMNS field length used for Device: 64, Type: 64, Event: 512, Reading: 64, Value: 128, Unit: 32
CONFIGURATION /opt/fhem/db.conf
DEF /opt/fhem/db.conf .*:.*
FD 5
FUUID 5d595aca-f33f-db1a-9fae-2143ffbee32056c7
FVERSION 93_DbLog.pm:v5.5.9-s26923/2022-12-29
MODE asynchronous
MODEL MYSQL
NAME DBLogging
NR 2
NTFY_ORDER 50-DBLogging
PID 5869
REGEXP .*:.*
SBP_PID 5870
SBP_STATE running
STATE Another operation is in progress - resync at NextSync
TYPE DbLog
UTF8 0
dbconn mysql:database=fhem;host=192.168.1.2;port=19648
dbuser fhemuser
eventCount 29
HELPER:
COLSET 1
DEVICECOL 64
EVENTCOL 512
LASTLIMITRUNTIME 1672837151.60521
LONGRUN_PID 1672837151.60489
OLDSTATE Another operation is in progress - resync at NextSync
PACKAGE main
READINGCOL 64
TC current
TH history
TYPECOL 64
UNITCOL 32
VALUECOL 128
VERSION 5.5.9
Helper:
DBLOG:
CacheOverflowLastState:
DBLogging:
TIME 1672837181.58673
VALUE normal
DBD::mysql::st execute failed:
DBLogging:
TIME 1672837025.06969
VALUE 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 '' at line 1 [for Statement "INSERT IGNORE INTO history (TIMESTAMP, DEVICE, TYPE, EVENT, READING, VALUE, UNIT) VALUES"] at ./FHEM/93_DbLog.pm line 2755.
state:
DBLogging:
TIME 1672837181.59546
VALUE Another operation is in progress - resync at NextSync
OLDREADINGS:
READINGS:
2023-01-04 13:59:41 CacheOverflowLastNum 0
2023-01-04 13:59:41 CacheOverflowLastState normal
2023-01-04 13:59:46 CacheUsage 180
2023-01-04 13:59:41 NextSync 2023-01-04 14:00:11 or when CacheUsage 250 is reached
2023-01-04 13:59:41 state Another operation is in progress - resync at NextSync
Attributes:
DbLogExclude CacheOverflowLastNum.*
DbLogSelectionMode Exclude/Include
DbLogType Current/History
addStateEvent 0
asyncMode 1
bulkInsert 1
cacheLimit 250
commitMode basic_ta:off
event-on-change-reading .*
room System
useCharfilter 1
verbose 3
Löche das Attr commitMode, setze bulkInsert = 0 (evtl. bessere Fehlermitteilung) und verbose = 4.
Wenn der Fehler wieder auftaucht, bitte den Logausschnitt posten und den Inhalt von "set ... listCache".
Danke, hab ich gemacht, seit einem "shutdown restart" läuft es jetzt erstmal fehlerfrei (meine Log wird halt beängstigend groß grad...). Aber das Nicht-Loggen hat sich nicht gebessert. Im FHEM Log steht aber dass er es übermittelt
2023.01.04 15:09:49 4: DbLog DBLogging - ################################################################
2023.01.04 15:09:49 4: DbLog DBLogging - ### start of new Logcycle ###
2023.01.04 15:09:49 4: DbLog DBLogging - ################################################################
2023.01.04 15:09:49 4: DbLog DBLogging - number of events received: 2 of device: AlleBewegungsmelderSperren
2023.01.04 15:09:49 4: DbLog DBLogging - check Device: AlleBewegungsmelderSperren , Event: setG1: on
2023.01.04 15:09:49 4: DbLog DBLogging - added event - Timestamp: 2023-01-04 15:09:49, Device: AlleBewegungsmelderSperren, Type: KNX, Event: setG1: on, Reading: setG1, Value: on, Unit:
2023.01.04 15:09:49 4: DbLog DBLogging - check Device: AlleBewegungsmelderSperren , Event: on
2023.01.04 15:09:49 4: DbLog DBLogging - added event - Timestamp: 2023-01-04 15:09:49, Device: AlleBewegungsmelderSperren, Type: KNX, Event: on, Reading: on, Value: , Unit:
[...]
2023.01.04 15:10:02 4: DbLog DBLogging - ################################################################
2023.01.04 15:10:02 4: DbLog DBLogging - ### start of new Logcycle ###
2023.01.04 15:10:02 4: DbLog DBLogging - ################################################################
2023.01.04 15:10:02 4: DbLog DBLogging - number of events received: 2 of device: AlleBewegungsmelderSperren
2023.01.04 15:10:02 4: DbLog DBLogging - check Device: AlleBewegungsmelderSperren , Event: setG1: off
2023.01.04 15:10:02 4: DbLog DBLogging - added event - Timestamp: 2023-01-04 15:10:02, Device: AlleBewegungsmelderSperren, Type: KNX, Event: setG1: off, Reading: setG1, Value: off, Unit:
2023.01.04 15:10:02 4: DbLog DBLogging - check Device: AlleBewegungsmelderSperren , Event: off
2023.01.04 15:10:02 4: DbLog DBLogging - added event - Timestamp: 2023-01-04 15:10:02, Device: AlleBewegungsmelderSperren, Type: KNX, Event: off, Reading: off, Value: , Unit:
bzw.:
2023.01.04 15:10:40 4: DbLog DBLogging - ################################################################
2023.01.04 15:10:40 4: DbLog DBLogging - ### start of new Logcycle ###
2023.01.04 15:10:40 4: DbLog DBLogging - ################################################################
2023.01.04 15:10:40 4: DbLog DBLogging - number of events received: 2 of device: Aussentemperatur
2023.01.04 15:10:40 4: DbLog DBLogging - check Device: Aussentemperatur , Event: getG1: 8.16
2023.01.04 15:10:40 4: DbLog DBLogging - check Device: Aussentemperatur , Event: 8.16
2023.01.04 15:10:40 4: DbLog DBLogging - added event - Timestamp: 2023-01-04 15:10:40, Device: Aussentemperatur, Type: KNX, Event: 8.16, Reading: 8.16, Value: , Unit:
Also offenbar hat das eine mit dem anderen nichts zu tun?
Kannst wieder auf verbose 3 wechseln.
Das Thema ist halt das berühmt / berüchtigte loggen von Reading "state".
Der Datensatz kommt ohne Readingname im Event :
Zitatadded event - Timestamp: 2023-01-04 15:09:49, Device: AlleBewegungsmelderSperren, Type: KNX, Event: on, Reading: on, Value: , Unit:
Dadurch klappt das parsen nicht.
Das KNX-Modul hat dankenswerter Weise eine sogenannte DbLog-SplitFn eingebaut (KNX_DbLog_split).
Die scheint aber das Reading "state" nicht richtig zu behandeln. Das solltest du dem Maintainer des Moduls melden.
Übergangsweise kannst du versuchen ob im DbLog das Attr addStateEvent = 0 dir hilft.
Ah cool, das hat es gebracht. Dann muss das ein Problem mit der Version ab 30.12. sein, denn bis dahin hat es problemlos ohne addStateEvent geklappt.
Vielen vielen lieben Dank!
Jetzt hoffe ich nur dass der Database Error auch weg ist und weg bleibt :)
Zitat
Dann muss das ein Problem mit der Version ab 30.12. sein, denn bis dahin hat es problemlos ohne addStateEvent geklappt.
Ich glaube es dir, allerdings ist die Eventverarbeitung identisch zur V4.... so ganz gehe ich über diese Brücke noch nicht.
Zitat
Jetzt hoffe ich nur dass der Database Error auch weg ist und weg bleibt :)
Das denke ich. Allerdings mache ich mir noch Gedanken weil ein undefined Value-Feld nicht zu einem solchen Fehler führen darf.
Ich habe auch schon eine Idee die ich teste und wenn es klappt ins nächste Release kommt.
LG
Sorry Mad-at,
ja ich habe da etwas im KNX-modul geändert, was das Problem ausgelöst hat - sorry!
@Heiko:
ich war mir sicher, das ich das checken auf state / nostate nicht mehr brauche, weil in deiner DbLog_Log folgendes vorkommt:
my $events = deviceEvents($dev_hash, AttrVal($name, "addStateEvent", 1));
return if(!$events);
... und wenn ich das richtig verstehe, ergibt AttrVal '1' falls KEIN attr im DbLog-device gesetzt ist...
... und deviceEvents($hash,1) sollte lt. wiki das "state" im array liefern ? https://wiki.fhem.de/wiki/DevelopmentModuleAPI#deviceEvents (https://wiki.fhem.de/wiki/DevelopmentModuleAPI#deviceEvents)
Wo ist der Wurm ?
PS: ich kann natürlich die Änderung im KNX Modul jederzeit zurückdrehen- kein Problem!
l.g. erwin
Moin erwin,
also ich finde erstmal wirklich gut dass du eine DbLog_SplitFn drin hast. :)
Die sieht so aus:
sub KNX_DbLog_split {
my ($event, $device) = @_;
my $unit = q{}; # default
# split event into reading & value
my ($reading, $value) = split(/:\s/x, $event, 2);
if (! defined($reading)) {
$reading = 'state';
$value = $event;
}
.....
"state" geht verloren, wenn DbLog deine Fn aufruft und in $event "state" enthält , z.B. "state: 34".
EDIT: das war Unsinn von mir ... Knoten im Hirn . ;)
Wenn Mad-at im KNX verbose 5 einstellt, müsste man das Split-Ergebnis sehen.
Hi Heiko,
ja state geht verloren, da funktioniert das split nicht! - mein Fehler!
.. ich werde das heute noch fixen.
Die Frage bleibt: ist das wiki falsch bez. deviceEvents ... oder...?
offen gesagt, den code deviceEvents (in der fhem.pl) durchschau ich nicht.
l.g. erwin
Zitat
ja state geht verloren, da funktioniert das split nicht! - mein Fehler!
:D ... also nach zweimal hingucken dachte ich, dass meine Schlußfolgerung falsch war ...
Ich schaue mir die deviceEvents sub auch mal an.
So Mad-at & Heiko,
fix für KNX-modul ist am SVN,
bitte morgen um update & test!
sorry Heiko, dass das Problem bei dir aufgeschlagen ist.... >:(.
l.g. erwin
Danke erwin. :)
@ Mad-at, nach dem Update kannst du addStateEvent = 0 wieder rausnehmen.
Wow, vielen lieben Dank an euch beide! Ich werde morgen testen und berichten. Das Verbose 5 im KNX Modul ist jetzt sinnlos, oder?
Lg
Matthias
ZitatDas Verbose 5 im KNX Modul ist jetzt sinnlos, oder?
Ja, entweder morgen in der Datenbank checken, oder kurz bei EINEM KNX-Device setzen und
KNX_DbLog_Split (dpt3tst): EVENT= state: -3 % READING= state VALUE= -3 UNIT= %nach so einem Log-Eintrag suchen. Wichtig dabei ist nur dass READING = state vorkommt!
l.g. erwin
Hallo! Vielen Dank nochmal, kann mich garnicht genug bedanken!
Vor dem Update
2023.01.04 21:29:19 4: KNX_Parse (Aussentemperatur): -process gadName=g1 cmd= w
2023.01.04 21:29:19 5: KNX_limit (Aussentemperatur): DIR= DECODE INPUT= 9.2 OUTPUT= 9.2
2023.01.04 21:29:19 5: KNX_decodeByDpt (Aussentemperatur): gadName= g1 model= dpt9 code= dpt9 value= 1873 length-value= 4 state= 9.20
2023.01.04 21:29:19 4: KNX_Parse_wp (Aussentemperatur): readingName=getG1 value=9.20
2023.01.04 21:29:19 5: KNX_DbLog_Split (Aussentemperatur): EVENT= getG1: 9.20 READING= getG1 VALUE= 9.20 UNIT=
2023.01.04 21:29:19 5: KNX_DbLog_Split (Aussentemperatur): EVENT= state: 9.20 READING= state VALUE= 9.20 UNIT=
Nach dem Update
2023.01.05 09:38:45 4: KNX_Parse (Aussentemperatur): -process gadName=g1 cmd= w
2023.01.05 09:38:45 5: KNX_limit (Aussentemperatur): DIR= DECODE INPUT= 10.88 OUTPUT= 10.88
2023.01.05 09:38:45 5: KNX_decodeByDpt (Aussentemperatur): gadName= g1 model= dpt9 code= dpt9 value= 1888 length-value= 4 state= 10.88
2023.01.05 09:38:45 4: KNX_Parse_wp (Aussentemperatur): readingName=getG1 value=10.88
2023.01.05 09:38:45 5: KNX_DbLog_Split (Aussentemperatur): EVENT= getG1: 10.88 READING= getG1 VALUE= 10.88 UNIT=
2023.01.05 09:38:45 5: KNX_DbLog_Split (Aussentemperatur): EVENT= state: 10.88 READING= state VALUE= 10.88 UNIT=
Nach Update und mit addStateEvent 0
2023.01.05 09:41:19 4: KNX_Parse (Aussentemperatur): -process gadName=g1 cmd= w
2023.01.05 09:41:19 5: KNX_limit (Aussentemperatur): DIR= DECODE INPUT= 10.96 OUTPUT= 10.96
2023.01.05 09:41:19 5: KNX_decodeByDpt (Aussentemperatur): gadName= g1 model= dpt9 code= dpt9 value= 1889 length-value= 4 state= 10.96
2023.01.05 09:41:19 4: KNX_Parse_wp (Aussentemperatur): readingName=getG1 value=10.96
2023.01.05 09:41:19 5: KNX_DbLog_Split (Aussentemperatur): EVENT= getG1: 10.96 READING= getG1 VALUE= 10.96 UNIT=
2023.01.05 09:41:19 5: KNX_DbLog_Split (Aussentemperatur): EVENT= 10.96 READING= state VALUE= 10.96 UNIT=
8)
hi Mad-at,
gerne - wieder was gefixt! ;D
addStateEvent sollte jetzt keinen Einfuss darauf mehr haben, zumindest was die KNX-devices betrifft!
bitte bei Gelegenheit den thread als [gelöst] markieren.
l.g. erwin
Hi Erwin!
ja deshalb hab ich beide logs geposted. Lustiger Weise schient es doch einen Einfluss zu haben?
EVENT= state: 10.88 READING= state VALUE= 10.88 UNIT vs EVENT= 10.96 READING= state VALUE= 10.96 UNIT=
Kann das überhaupt sein?
Lg
Matthias
Ja, hast recht, was EVENT betrifft!
Ich habe mich auf READING bezogen, was ja das ursprüngliche Problem war - und das vmtl. jenes Feld ist, das zur Auswertung/Grafik,... nötig ist.
das EVENT Feld find ich in der Db völlig unnötig, aber das ist meine pers. Meinung...
l.g. erwin
Kenn mich aus! Danke!!