[gelöst]configdb + mysql weiterhin keine state Infos mehr nach Neustart

Begonnen von persching, 26 März 2022, 10:19:43

Vorheriges Thema - Nächstes Thema

persching

Hallo,
ich hab schon gelesen, dass durch ein Update die states irgendwie in die Datenbank übertragen werden sollten. Bei mir ist es aber immer noch so, dass z.B. der Status der ROOMMATE nicht gespeichert werden. Oder auch von den dummys fehlen die States. :(
Es wird wohl eine Datei in die ConfigDB geschrieben, wie man an den beiden angehängten Bildschirmfotos erkennen kann. Das eine von 10.04.06 ist vor einem "save config", das andere danach. Ich habe auch "attr global verbose 4" eingestellt, aber weiß nicht nach was ich jetzt suchen soll. Die Datei ist riesig (5,1 MB) und hat ganz viele Infos... Gibt es ein Stichwort nachdem ich suchen soll?

Gruß persching

betateilchen

Zu wenige Infos, um Dir wirklich helfen zu können.

Wenn Du ein shutdown restart ausführst und verbose=4 schon eingestellt ist, sollten kurz vor dem shutdown und kurz nach dem restart Meldungen von configDB im Log stehen. Diese Meldungen wären der erste Ansatzpunkt für eine Diagnose.
-----------------------
Formuliere die Aufgabe möglichst einfach und
setze die Lösung richtig um - dann wird es auch funktionieren.
-----------------------
Lesen gefährdet die Unwissenheit!

persching

Hier mal der Logauszug:

2022.03.26 10:04:44.427 0: Server shutdown
2022.03.26 10:04:44.430 4: configDB reading file: ./FHEM/FhemUtils/cacheDbRep
2022.03.26 10:04:44.434 4: configDB writing file: ./FHEM/FhemUtils/cacheDbRep
2022.03.26 10:04:44.444 4: configDB reading file: ./FHEM/FhemUtils/cacheDbRep
2022.03.26 10:04:44.449 4: configDB writing file: ./FHEM/FhemUtils/cacheDbRep
2022.03.26 10:04:44.457 4: configDB reading file: ./FHEM/FhemUtils/cacheDbRep
2022.03.26 10:04:44.462 4: configDB writing file: ./FHEM/FhemUtils/cacheDbRep
2022.03.26 10:04:44.470 4: configDB reading file: ./FHEM/FhemUtils/cacheDbRep
2022.03.26 10:04:44.475 4: configDB writing file: ./FHEM/FhemUtils/cacheDbRep
2022.03.26 10:04:44.483 4: configDB reading file: ./FHEM/FhemUtils/cacheDbRep
2022.03.26 10:04:44.488 4: configDB writing file: ./FHEM/FhemUtils/cacheDbRep
2022.03.26 10:04:44.497 4: configDB reading file: ./FHEM/FhemUtils/cacheDbRep
2022.03.26 10:04:44.502 4: configDB writing file: ./FHEM/FhemUtils/cacheDbRep
2022.03.26 10:04:44.516 4: DbLog logdb -> ################################################################
2022.03.26 10:04:44.517 4: DbLog logdb -> ###              start of new Logcycle                       ###
2022.03.26 10:04:44.517 4: DbLog logdb -> ################################################################
2022.03.26 10:04:44.517 4: DbLog logdb -> number of events received: 1 of device: FHEM_MQTT_Client
2022.03.26 10:04:44.517 4: DbLog logdb -> check Device: FHEM_MQTT_Client , Event: state: disconnected
2022.03.26 10:04:44.517 4: DbLog logdb -> added event - Timestamp: 2022-03-26 10:04:44, Device: FHEM_MQTT_Client, Type: MQTT2_CLIENT, Event: state: disconnected, Reading: state, Value: disconnected, Unit:
2022.03.26 10:04:44.518 4: n_publish_mqtt exec {
my $mqttRoom = AttrVal($NAME, 'mqttRoom', '');;
    my $mqttName = AttrVal($NAME, 'mqttName', '');;

    if ($mqttRoom ne '' && $mqttName ne '') {
        my $reading = "";;
        my $message = "";;

        if ($EVENT =~ qr/(.*?): (.*)/p) {
            $reading = $1;;
            $message = $2;;
        } else {
            $reading = "state";;
            $message = $EVENT;;
        }

        my $topic = "SmartHome/$mqttRoom/$mqttName/$reading";;

        fhem("set Mosquitto publish $topic $message");;
    }}
2022.03.26 10:04:44.524 4: DbLog logdb -> ################################################################
2022.03.26 10:04:44.525 4: DbLog logdb -> ###              start of new Logcycle                       ###
2022.03.26 10:04:44.525 4: DbLog logdb -> ################################################################
2022.03.26 10:04:44.525 4: DbLog logdb -> number of events received: 2 of device: Mosquitto
2022.03.26 10:04:44.525 4: DbLog logdb -> check Device: Mosquitto , Event: connection: disconnected
2022.03.26 10:04:44.525 4: DbLog logdb -> check Device: Mosquitto , Event: state: disconnected
2022.03.26 10:04:44.525 4: n_publish_mqtt exec {
my $mqttRoom = AttrVal($NAME, 'mqttRoom', '');;
    my $mqttName = AttrVal($NAME, 'mqttName', '');;

    if ($mqttRoom ne '' && $mqttName ne '') {
        my $reading = "";;
        my $message = "";;

        if ($EVENT =~ qr/(.*?): (.*)/p) {
            $reading = $1;;
            $message = $2;;
        } else {
            $reading = "state";;
            $message = $EVENT;;
        }

        my $topic = "SmartHome/$mqttRoom/$mqttName/$reading";;

        fhem("set Mosquitto publish $topic $message");;
    }}
2022.03.26 10:04:44.526 4: n_publish_mqtt exec {
my $mqttRoom = AttrVal($NAME, 'mqttRoom', '');;
    my $mqttName = AttrVal($NAME, 'mqttName', '');;

    if ($mqttRoom ne '' && $mqttName ne '') {
        my $reading = "";;
        my $message = "";;

        if ($EVENT =~ qr/(.*?): (.*)/p) {
            $reading = $1;;
            $message = $2;;
        } else {
            $reading = "state";;
            $message = $EVENT;;
        }

        my $topic = "SmartHome/$mqttRoom/$mqttName/$reading";;

        fhem("set Mosquitto publish $topic $message");;
    }}
2022.03.26 10:04:44.528 1: Shutdown executed
2022.03.26 10:04:44.537 4: configDB writing file: ./log/eventTypes.txt
2022.03.26 10:04:44.587 4: configDB save state 387bb23e494904e7f2a9cdfe53581927.fhem.save with 3884 entries
2022.03.26 10:04:44.588 4: configDB writing file: 387bb23e494904e7f2a9cdfe53581927.fhem.save
2022.03.26 10:04:47.845 3: From the FHEM_GLOBALATTR environment: attr global logfile ./log/fhem-%Y-%m-%d.log
2022.03.26 10:04:47.845 3: From the FHEM_GLOBALATTR environment: attr global pidfilename ./log/fhem.pid
2022.03.26 10:04:47.846 3: From the FHEM_GLOBALATTR environment: attr global updateInBackground 1
2022.03.26 10:04:47.846 3: From the FHEM_GLOBALATTR environment: attr global nofork 0
2022.03.26 10:04:47.853 4: configDB read config 387bb23e494904e7f2a9cdfe53581927
2022.03.26 10:04:47.886 4: configDB reading file: 387bb23e494904e7f2a9cdfe53581927.fhem.save
2022.03.26 10:04:47.891 4: configDB read state 387bb23e494904e7f2a9cdfe53581927.fhem.save
2022.03.26 10:04:47.921 4: configDB reading file: ./FHEM/FhemUtils/uniqueID
2022.03.26 10:04:47.927 3: telnetPort: port 7072 opened
2022.03.26 10:04:48.098 3: web: port 8083 opened
2022.03.26 10:04:48.117 3: WEBtablet: port 8082 opened
2022.03.26 10:04:48.138 4: configDB reading file: ./log/eventTypes.txt
2022.03.26 10:04:48.164 2: eventTypes: loaded 997 lines from ./log/eventTypes.txt
2022.03.26 10:04:48.184 3: Opening CUL_0 device /dev/virtual_CUL
2022.03.26 10:04:48.206 3: Setting CUL_0 serial parameters to 9600,8,N,1
2022.03.26 10:04:48.312 3: CUL_0: Possible commands: ABbCEeFGiKklMmNRTtUuVWXxYZ
2022.03.26 10:04:48.317 3: CUL_0 device opened
2022.03.26 10:04:48.323 2: Switched CUL_0 rfmode to MAX
2022.03.26 10:04:48.360 1: HMLAN_Parse: HMLAN1 new condition disconnected
2022.03.26 10:04:48.664 4: https://dtd9NP9xBN0KDT3P5m7eB28N5kVIDYjw:%20@api.pushbullet.com/v2/users/me: HTTP response code 200
2022.03.26 10:04:48.664 4: FHEM -> Pushbullet.com:
2022.03.26 10:04:48.665 4: Pushbullet.com -> FHEM: {"active":true,"iden":"ujCBFbNV9Xw","created":1431508562.093194,"modified":1643972693.0944939,"email":"persching1978@gmail.com","email_normalized":"persching1978@gmail.com","name":"Dirk Braun","image_url":"https://static.pushbullet.com/google-user/8607a131bf526424505f4721e24d6decba78edb43dad85af1da36fa1c6477dd3","max_upload_size":26214400}
2022.03.26 10:04:49.183 4: Looking for SVN Id in module 98_DOIF.pm
2022.03.26 10:04:49.194 3: HourCounter HourCounter Initialize.220 Init Done with Version 1.0.1.2 - 24.12.2014
2022.03.26 10:04:49.195 0: HourCounter EG_Bad_Fensterkontakt_HC Define.228 parameters: EG_Bad_Fensterkontakt_HC HourCounter EG_Bad_Fensterkontakt:onoff:.1 EG_Bad_Fensterkontakt:onoff:.0
2022.03.26 10:04:49.258 4: Looking for SVN Id in module 98_DOIF.pm
2022.03.26 10:04:49.262 4: Looking for SVN Id in module 98_DOIF.pm
2022.03.26 10:04:49.266 4: Looking for SVN Id in module 98_DOIF.pm
2022.03.26 10:04:49.271 4: Looking for SVN Id in module 98_DOIF.pm
2022.03.26 10:04:49.276 4: Looking for SVN Id in module 98_DOIF.pm
2022.03.26 10:04:49.280 0: HourCounter EG_WoZi_Fensterkontakt_HC Define.228 parameters: EG_WoZi_Fensterkontakt_HC HourCounter EG_WoZi_Fensterkontakt:onoff:.1 EG_WoZi_Fensterkontakt:onoff:.0
2022.03.26 10:04:49.281 0: HourCounter KACHELOFEN_HC Define.228 parameters: KACHELOFEN_HC HourCounter Kachelofen_dummy:an Kachelofen_dummy:aus
2022.03.26 10:04:49.296 4: Looking for SVN Id in module 98_DOIF.pm
2022.03.26 10:04:49.304 4: Looking for SVN Id in module 98_DOIF.pm
2022.03.26 10:04:49.335 4: Looking for SVN Id in module 98_DOIF.pm
2022.03.26 10:04:49.339 4: Looking for SVN Id in module 98_DOIF.pm
2022.03.26 10:04:49.343 4: Looking for SVN Id in module 98_DOIF.pm
2022.03.26 10:04:49.346 0: HourCounter OG_Bad_Fensterkontakt_HC Define.228


Was mir auffällt:

2022.03.26 10:04:44.528 1: Shutdown executed

2022.03.26 10:04:44.537 4: configDB writing file: ./log/eventTypes.txt
2022.03.26 10:04:44.587 4: configDB save state 387bb23e494904e7f2a9cdfe53581927.fhem.save with 3884 entries
2022.03.26 10:04:44.588 4: configDB writing file: 387bb23e494904e7f2a9cdfe53581927.fhem.save

2022.03.26 10:04:47.853 4: configDB read config 387bb23e494904e7f2a9cdfe53581927
2022.03.26 10:04:47.886 4: configDB reading file: 387bb23e494904e7f2a9cdfe53581927.fhem.save
2022.03.26 10:04:47.891 4: configDB read state 387bb23e494904e7f2a9cdfe53581927.fhem.save

Ich lese das so, dass erst der Shutdown ausgeführt wird, dann wird das File geschrieben und danach dasselbe wieder eingelesen... Wäre nicht die Reihenfolge
- writing file
- shutdown
- reading file

??

betateilchen

Zitat von: persching am 27 März 2022, 13:39:46
Ich lese das so, dass erst der Shutdown ausgeführt wird, dann wird das File geschrieben und danach dasselbe wieder eingelesen...

Das ist schon alles ok so, Du interpretierst die Meldungen lediglich falsch.

"shutdown executed" bedeutet nicht, dass der shutdown abgeschlossen ist, sondern dass dieser gerade ausgeführt wird. Und das Schreiben des statefile ist fester Bestandteil des shutdown.




Zurück zum eigentlichen Thema:


2022.03.26 10:04:44.587 4: configDB save state 387bb23e494904e7f2a9cdfe53581927.fhem.save with 3884 entries
2022.03.26 10:04:47.853 4: configDB read config 387bb23e494904e7f2a9cdfe53581927
2022.03.26 10:04:47.891 4: configDB read state 387bb23e494904e7f2a9cdfe53581927.fhem.save


Das ist exakt das zu erwartende korrekte Verhalten. Da hier keine Probleme erkennbar sind (keine Fehlermeldungen o.ä.) muss man davon ausgehen, dass sämtliche readings korrekt weggeschrieben wurden.

Zitat von: persching am 26 März 2022, 10:19:43
Bei mir ist es aber immer noch so, dass z.B. der Status der ROOMMATE nicht gespeichert werden.
Oder auch von den dummys fehlen die States.

Was steht denn bei den devices, die nicht korrekt gespeichert werden, in deren readings?
-----------------------
Formuliere die Aufgabe möglichst einfach und
setze die Lösung richtig um - dann wird es auch funktionieren.
-----------------------
Lesen gefährdet die Unwissenheit!

persching

Alle betroffenen Devices zeigen bei "STATE" ??? an. Irgendwelche Folgedevices wie DOIF oder so haben dann das Problem, dass sie damit nix anfangen können.

Hier bspw. mein Roommate Device:

Internals:
   DEF        Familie
   DURATIONTIMER 1648396826.27701
   FUUID      5c49a06d-f33f-e65d-a26b-77f75689c1c10583
   FVERSION   20_ROOMMATE.pm:0.195330/2019-06-02
   NAME       rr_Dirk
   NOTIFYDEV  global,DirkPresence
   NR         155
   NTFY_ORDER 50-rr_Dirk
   READY      1
   RESIDENTGROUPS Familie
   STATE      ???
   SUBTYPE    adult
   TYPE       ROOMMATE
   READINGS:
     2022-03-27 17:59:26   durTimerAbsence 00:00:00
     2022-03-27 17:59:26   durTimerAbsence_cr 0
     2022-03-27 17:59:26   durTimerPresence 00:00:00
     2022-03-27 17:59:26   durTimerPresence_cr 0
     2022-03-27 17:59:26   durTimerSleep   00:00:00
     2022-03-27 17:59:26   durTimerSleep_cr 0
   TIMER:
     rr_Dirk_DurationTimer:
       HASH       rr_Dirk
       MODIFIER   DurationTimer
       NAME       rr_Dirk_DurationTimer
Attributes:
   DbLogExclude .*
   alias      Dirk
   devStateIcon .*zuhause:user_available:absent .*anwesend:user_available:absent .*abwesend:user_away:home .*verreist:user_ext_away:home .*bettfertig:scene_toilet:asleep .*schlaeft:scene_sleeping:awoken .*schläft:scene_sleeping:awoken .*aufgestanden:scene_sleeping_alternat:home .*:user_unknown:home
   eventMap   home:zuhause absent:abwesend gone:verreist gotosleep:bettfertig asleep:schläft awoken:aufgestanden
   group      Bewohner
   icon       people_sensor
   room       Anwesenheit
   rr_autoGoneAfter 24
   rr_presenceDevices DirkPresence
   rr_realname alias
   sortby     1
   webCmd     state
   widgetOverride state:zuhause,bettfertig,schläft,aufgestanden,abwesend,verreist


Oder ein Dummy mit dem ich verschiedene Profile für die Weekdaytimer meiner Heizung vorwähle:
Internals:
   FUUID      5c49a04e-f33f-e65d-9177-595fb16e43fd3aec
   FVERSION   98_dummy.pm:0.256060/2022-02-01
   NAME       WDT_Badezimmer_Profile
   NR         71
   STATE      ???
   TYPE       dummy
Attributes:
   alias      Bad
   devStateIcon . Auto:sani_heating_automatic@lightgreen . Minimal:sani_heating_level_50@orange . Aus:sani_heating_level_0@lightblue . Manuell:time_manual_mode
   group      Profile
   icon       rc_SETUP
   mqttName   HCProfile
   mqttRoom   Bad
   room       Heizung->Thermostate,Obergeschoss->Badezimmer
   setList    state:Auto,Manuell,Minimal,Aus
   webCmd     state

betateilchen

Sorge doch mal dafür, dass die devices einen gültigen STATE bekommen. Und wenn das passiert ist, machst Du ein save config und einen shutdown restart.

Da die devices kein reading "state" haben und es auch kein Attribut "stateFormat" gibt, frage ich mich gerade, wo der Wert für das Internal  STATE herkommen soll. Ein Wert mit ??? wird jedenfalls nicht gespeichert.
-----------------------
Formuliere die Aufgabe möglichst einfach und
setze die Lösung richtig um - dann wird es auch funktionieren.
-----------------------
Lesen gefährdet die Unwissenheit!

persching

Das habe ich eben gemacht bevor ich das LIST hier gepostet habe. Und genau dann hatte ich den geposteten Zustand. :(

betateilchen

Zitat von: persching am 27 März 2022, 18:10:44
Das habe ich eben gemacht bevor ich das LIST hier gepostet habe. Und genau dann hatte ich den geposteten Zustand. :(

Wie hast Du das gemacht? Wie kommen die Werte in das internal STATE? Und was steht dann da drin?

Mit verbose=5 kannst Du Dir im Logfile genau anschauen, was zu einem bestimmten device abgespeichert wird. Schau doch mal nach, ob da bei den betroffenen devices irgendwelche Auffälligkeiten im Log stehen.

Offenbar ist es ja so, dass nur bestimmte devices von dem Problem betroffen sind und nicht alle. Und die configDB interessiert sich beim Speichern grundsätzlich nicht dafür, um welchen device-TYPE es sich handelt.
-----------------------
Formuliere die Aufgabe möglichst einfach und
setze die Lösung richtig um - dann wird es auch funktionieren.
-----------------------
Lesen gefährdet die Unwissenheit!

persching

Die Devices die größtenteils davon betroffen sind haben alle ein webcmd über die ich dann das Initialisieren auf den neuen Wert mache. Ich hatte bspw. wieder mein Roommate-Device auf "zuhause" initialisiert, dann gespeichert und ein shutdown-restart gemacht. Im Logfile steht dann dazu das hier:

2022.03.27 20:16:42.458 5: configDB: setstate rr_Dirk zuhause
2022.03.27 20:16:42.458 5: configDB: setstate rr_Dirk 2022-03-27 19:50:36 durTimerAbsence 00:00:00
2022.03.27 20:16:42.458 5: configDB: setstate rr_Dirk 2022-03-27 19:50:36 durTimerAbsence_cr 0
2022.03.27 20:16:42.459 5: configDB: setstate rr_Dirk 2022-03-27 20:15:47 durTimerPresence 00:25:02
2022.03.27 20:16:42.459 5: configDB: setstate rr_Dirk 2022-03-27 20:15:47 durTimerPresence_cr 25
2022.03.27 20:16:42.459 5: configDB: setstate rr_Dirk 2022-03-27 19:50:36 durTimerSleep 00:00:00
2022.03.27 20:16:42.459 5: configDB: setstate rr_Dirk 2022-03-27 19:50:36 durTimerSleep_cr 0
2022.03.27 20:16:42.459 5: configDB: setstate rr_Dirk 2022-03-27 19:50:45 lastArrival 2022-03-27 19:50:45
2022.03.27 20:16:42.459 5: configDB: setstate rr_Dirk 2022-03-27 19:50:45 lastLocation undefined
2022.03.27 20:16:42.459 5: configDB: setstate rr_Dirk 2022-03-27 19:50:47 lastMood sleepy
2022.03.27 20:16:42.459 5: configDB: setstate rr_Dirk 2022-03-27 19:50:47 lastState gotosleep
2022.03.27 20:16:42.459 5: configDB: setstate rr_Dirk 2022-03-27 19:50:45 location home
2022.03.27 20:16:42.459 5: configDB: setstate rr_Dirk 2022-03-27 19:50:47 mood calm
2022.03.27 20:16:42.459 5: configDB: setstate rr_Dirk 2022-03-27 19:50:45 presence present
2022.03.27 20:16:42.459 5: configDB: setstate rr_Dirk 2022-03-27 19:50:47 state home
2022.03.27 20:16:42.459 5: configDB: setstate rr_Dirk 2022-03-27 19:50:45 wayhome 0
.
.
.
.
2022.03.27 20:16:42.462 4: configDB save state 4359c58e3b22efd00cfc65b022a335fd.fhem.save with 3778 entries
2022.03.27 20:16:42.464 4: configDB writing file: 4359c58e3b22efd00cfc65b022a335fd.fhem.save
2022.03.27 20:16:42.464 4: DbLog logdb -> 181 of 181 events updated in table current
2022.03.27 20:16:42.471 4: DbLog logdb -> insert / update table current committed by autocommit
2022.03.27 20:16:42.471 5: DbLog logdb -> DbLog_PushAsync finished
2022.03.27 20:16:42.487 4: configDB save config 4359c58e3b22efd00cfc65b022a335fd
2022.03.27 20:16:43.675 4: configDB reorg started, keeping last 5 versions.
2022.03.27 20:16:44.381 5: configDB: statefile  filename >7a10db4cc89094f18bd8bdff14c8038c.fhem.save<
2022.03.27 20:16:44.381 5: configDB: statefile uuid:  >7a10db4cc89094f18bd8bdff14c8038c<
2022.03.27 20:16:44.382 5: configDB: statefile found: >notfound<
2022.03.27 20:16:44.382 5: configDB: statefile del2 >7a10db4cc89094f18bd8bdff14c8038c.fhem.save<
2022.03.27 20:16:44.383 5: configDB: statefile  filename >2fbabab8a1f632ae4ba41700722491b1.fhem.save<
2022.03.27 20:16:44.383 5: configDB: statefile uuid:  >2fbabab8a1f632ae4ba41700722491b1<
2022.03.27 20:16:44.384 5: configDB: statefile found: >2fbabab8a1f632ae4ba41700722491b1<
2022.03.27 20:16:44.384 5: configDB: statefile  filename >c937cd3ae3a56666303e938f92a3f84f.fhem.save<
2022.03.27 20:16:44.384 5: configDB: statefile uuid:  >c937cd3ae3a56666303e938f92a3f84f<
2022.03.27 20:16:44.385 5: configDB: statefile found: >c937cd3ae3a56666303e938f92a3f84f<
2022.03.27 20:16:44.385 5: configDB: statefile  filename >d96472fd956ef3f81b9081c4e8b61888.fhem.save<
2022.03.27 20:16:44.385 5: configDB: statefile uuid:  >d96472fd956ef3f81b9081c4e8b61888<
2022.03.27 20:16:44.386 5: configDB: statefile found: >d96472fd956ef3f81b9081c4e8b61888<
2022.03.27 20:16:44.386 5: configDB: statefile  filename >197f32165ff56260b052ece83e333809.fhem.save<
2022.03.27 20:16:44.387 5: configDB: statefile uuid:  >197f32165ff56260b052ece83e333809<
2022.03.27 20:16:44.387 5: configDB: statefile found: >197f32165ff56260b052ece83e333809<
2022.03.27 20:16:44.387 5: configDB: statefile  filename >f2be268de034f0ed95600ae7f6049aca.fhem.save<
2022.03.27 20:16:44.388 5: configDB: statefile uuid:  >f2be268de034f0ed95600ae7f6049aca<
2022.03.27 20:16:44.388 5: configDB: statefile found: >f2be268de034f0ed95600ae7f6049aca<
2022.03.27 20:16:44.389 5: configDB: statefile  filename >4359c58e3b22efd00cfc65b022a335fd.fhem.save<
2022.03.27 20:16:44.389 5: configDB: statefile uuid:  >4359c58e3b22efd00cfc65b022a335fd<
2022.03.27 20:16:44.389 5: configDB: statefile found: >4359c58e3b22efd00cfc65b022a335fd<
.
.
.
.
2022.03.27 20:17:13.273 5: Initializing Type Library:
2022.03.27 20:17:13.278 4: configDB read config 4359c58e3b22efd00cfc65b022a335fd
2022.03.27 20:17:13.311 4: configDB reading file: 4359c58e3b22efd00cfc65b022a335fd.fhem.save
2022.03.27 20:17:13.317 4: configDB read state 4359c58e3b22efd00cfc65b022a335fd.fhem.save
.
.
.
.
2022.03.27 20:17:33.751 4: ROOMMATE rr_Dirk: device initialization completed




Bei dem letzten Eintrag bin ich mir nicht sicher, ob das wirklich zum Zurück lesen der Datei gehört. So richtig wie beim Schreiben finde ich das nämlich nicht. Ich habe jetzt das Logfile nach "rr_Dirk" durchsucht und finde eben nur, dass scheinbar der Wert in eine Datei geschrieben wird. Die selbe Datei wird auch wieder eingelesen. Aber ich finde eben die Zuordnung nicht... aber bei global verbose 5 bin ich beim Logfile für heute schon bei 14 MB. Und 5 hatte ich nur immer kurz eingestellt.

Steht es denn genauso wie der Eintrag in die Datei auch beim Auslesen aus der Datei im Logfile?




betateilchen

Zitat von: persching am 27 März 2022, 20:56:15
2022.03.27 20:16:42.459 5: configDB: setstate rr_Dirk 2022-03-27 19:50:47 state home

Da wird jedenfalls das reading state korrekt in das statefile geschrieben.
Interessant wäre jetzt noch die Suche im Logfile beim restart, da muss es eine zugehörige Zeile geben, mit der das reading wieder geschrieben wird.

Zitat von: persching am 27 März 2022, 20:56:15
Die Devices die größtenteils davon betroffen sind haben alle ein webcmd über die ich dann das Initialisieren auf den neuen Wert mache.

Das muss ich nicht verstehen.

Aber ein Fehlverhalten der configDB kann ich nach wie vor nicht erkennen, zumal jetzt der Nachweis erbracht ist, dass die gesuchten Werte korrekt im statefile landen. Mit ziemlicher Sicherheit werden die Werte beim Einlesen auch wieder korrekt gesetzt. Vielleicht wird der Wert während des FHEM Starts durch irgendwas überschrieben. Keine Ahnung, wie/ob Dein webCmd das irgendwie beeinflussen kann.

Zitat von: persching am 27 März 2022, 20:56:15
aber bei global verbose 5 bin ich beim Logfile für heute schon bei 14 MB. Und 5 hatte ich nur immer kurz eingestellt.

Was ist denn das für eine Argumentation? Entweder, man nutzt das Logfile dazu, einem Fehler auf die Spur zu kommen oder man nutzt es halt nicht. Aber ohne Input auch kein Output. Will heißen: Wenn Du mir nicht sagst, was in Deinem Logfile geschrieben steht, kann ich Dir auch nicht helfen, herauszufinden, was da schiefläuft. Mit Hellsehen kommen wir jedenfalls nicht weiter.

Man kann ein Logfile mit "set Logfile clear" einfach leeren, bevor man "shutdown restart" macht, dann reduziert sich der Inhalt und die Größe beachtlich und auch die Suche wird erleichtert.
Oder man stellt das Logfile für die Zeit der Suche mal auf Stunden-Log um, dann bekommt man auch kleinere Dateien.
-----------------------
Formuliere die Aufgabe möglichst einfach und
setze die Lösung richtig um - dann wird es auch funktionieren.
-----------------------
Lesen gefährdet die Unwissenheit!

persching

Zitat von: betateilchen am 28 März 2022, 14:28:48
Da wird jedenfalls das reading state korrekt in das statefile geschrieben.
Interessant wäre jetzt noch die Suche im Logfile beim restart, da muss es eine zugehörige Zeile geben, mit der das reading wieder geschrieben wird.

Genau danach hab ich gestern in dem riesigen Logfile über 1 Stunde lang gesucht und keine Zeile gefunden.


Zitat
Das muss ich nicht verstehen.

Ok, das war wirklich vielleicht nicht die beste Ausdrucksweise, ich versuche es noch einmal: Mein rr_Dirk sieht nach dem "shutdown restart" so aus wie im Screenshot 19.44.31.png

Wenn ich dann ein list rr_Dirk mache, dann bekomme ich folgendes:

Internals:
   DEF        Familie
   DURATIONTIMER 1648489486.59207
   FUUID      5c49a06d-f33f-e65d-a26b-77f75689c1c10583
   FVERSION   20_ROOMMATE.pm:0.195330/2019-06-02
   NAME       rr_Dirk
   NOTIFYDEV  global,DirkPresence
   NR         155
   NTFY_ORDER 50-rr_Dirk
   READY      1
   RESIDENTGROUPS Familie
   STATE      ???
   SUBTYPE    adult
   TYPE       ROOMMATE
   Helper:
     DBLOG:
       durTimerAbsence:
         logdb:
           TIME       1648489426.60489
           VALUE      00:00:00
       durTimerAbsence_cr:
         logdb:
           TIME       1648489426.60489
           VALUE      0
       durTimerPresence:
         logdb:
           TIME       1648489426.60489
           VALUE      00:00:00
       durTimerPresence_cr:
         logdb:
           TIME       1648489426.60489
           VALUE      0
       durTimerSleep:
         logdb:
           TIME       1648489426.60489
           VALUE      00:00:00
       durTimerSleep_cr:
         logdb:
           TIME       1648489426.60489
           VALUE      0
   READINGS:
     2022-03-28 19:43:46   durTimerAbsence 00:00:00
     2022-03-28 19:43:46   durTimerAbsence_cr 0
     2022-03-28 19:43:46   durTimerPresence 00:00:00
     2022-03-28 19:43:46   durTimerPresence_cr 0
     2022-03-28 19:43:46   durTimerSleep   00:00:00
     2022-03-28 19:43:46   durTimerSleep_cr 0
   TIMER:
     rr_Dirk_DurationTimer:
       HASH       rr_Dirk
       MODIFIER   DurationTimer
       NAME       rr_Dirk_DurationTimer
Attributes:
   alias      Dirk
   devStateIcon .*zuhause:user_available:absent .*anwesend:user_available:absent .*abwesend:user_away:home .*verreist:user_ext_away:home .*bettfertig:scene_toilet:asleep .*schlaeft:scene_sleeping:awoken .*schläft:scene_sleeping:awoken .*aufgestanden:scene_sleeping_alternat:home .*:user_unknown:home
   eventMap   home:zuhause absent:abwesend gone:verreist gotosleep:bettfertig asleep:schläft awoken:aufgestanden
   group      Bewohner
   icon       people_sensor
   room       Anwesenheit
   rr_autoGoneAfter 24
   rr_presenceDevices DirkPresence
   rr_realname alias
   sortby     1
   webCmd     state
   widgetOverride state:zuhause,bettfertig,schläft,aufgestanden,abwesend,verreist


Also STATE = ???

Nun wähle ich über das Pulldown-Menü z.B. "Abwesend" aus (siehe 19.50.20.png) und danach wieder "Zuhause".

Zitat
Aber ein Fehlverhalten der configDB kann ich nach wie vor nicht erkennen, zumal jetzt der Nachweis erbracht ist, dass die gesuchten Werte korrekt im statefile landen. Mit ziemlicher Sicherheit werden die Werte beim Einlesen auch wieder korrekt gesetzt. Vielleicht wird der Wert während des FHEM Starts durch irgendwas überschrieben. Keine Ahnung, wie/ob Dein webCmd das irgendwie beeinflussen kann.

Was ist denn das für eine Argumentation? Entweder, man nutzt das Logfile dazu, einem Fehler auf die Spur zu kommen oder man nutzt es halt nicht. Aber ohne Input auch kein Output. Will heißen: Wenn Du mir nicht sagst, was in Deinem Logfile geschrieben steht, kann ich Dir auch nicht helfen, herauszufinden, was da schiefläuft. Mit Hellsehen kommen wir jedenfalls nicht weiter.

Es ist nicht so, dass ich nicht versuche zu verstehen, was hier passiert bzw. was schiefläuft oder gar dass ich dir nicht sagen möchte, was dort steht. Ich (und vermutlich auch du) möchte hier kein Megalogfile posten. Wenn es notwendig ist, dann kann ich es gerne zur Verfügung stellen.

Ich denke, mir fehlt der Suchbegriff. Aber ich habe jetzt ein "set Logfile clear" gemacht. Und habe jetzt für einen Zeitraum von 8 Minuten um den restart rund 171.000 Logzeilen. Die habe ich jetzt wieder versucht zu durchsuchen, aber ich finde zwar, dass das statefile erst geschrieben und dann gelesen wird, aber ich finde nichts wo die Werte aus dem File zugewiesen werden.

Wie würde denn ungefähr der Logeintrag aussehen, der dem Device rr_Dirk aus dem gespeicherten File wieder den Wert zuweist? Oder anders gefragt: was ist der "Gegenspieler" zum Eintrag

configDB: setstate rr_Dirk zuhause

??

Zitat
Man kann ein Logfile mit "set Logfile clear" einfach leeren, bevor man "shutdown restart" macht, dann reduziert sich der Inhalt und die Größe beachtlich und auch die Suche wird erleichtert.
Oder man stellt das Logfile für die Zeit der Suche mal auf Stunden-Log um, dann bekommt man auch kleinere Dateien.

betateilchen

Zitat von: persching am 28 März 2022, 20:34:54
Wie würde denn ungefähr der Logeintrag aussehen, der dem Device rr_Dirk aus dem gespeicherten File wieder den Wert zuweist? Oder anders gefragt: was ist der "Gegenspieler" zum Eintrag

Ich habe Dein device jetzt mit einem dummy nachgebaut


defmod test_dummy dummy
attr test_dummy webCmd state
attr test_dummy widgetOverride state:zuhause,bettfertig,schläft,aufgestanden,abwesend,verreist


dann habe ich mit der dropdown-Liste auf "bettfertig" eingestellt und bei einem "shutdown restart" passiert folgendes:



Einträge beim shutdown - hier werden die Werte in das statefile geschrieben:
2022.03.29 11:01:09 5: configDB: setstate test_dummy bettfertig
2022.03.29 11:01:09 5: configDB: setstate test_dummy 2022-03-29 11:00:37 state bettfertig

Einträge beim restart - hier werden die aus dem statefile gelesenen Werte wieder in das device geschrieben:
2022.03.29 11:01:16 5: Cmd: >setstate test_dummy bettfertig<
2022.03.29 11:01:16 5: Cmd: >setstate test_dummy 2022-03-29 11:00:37 state bettfertig<


und im device ist nach dem Neustart alles wieder wie vorher. Einen Fehler seitens der configDB kann ich nach wie vor nicht feststellen.
-----------------------
Formuliere die Aufgabe möglichst einfach und
setze die Lösung richtig um - dann wird es auch funktionieren.
-----------------------
Lesen gefährdet die Unwissenheit!

persching

Ich weiß nicht, was schiefläuft, aber hier mal ein paar Infos, was mir mein Logfile relativ schnell liefert:

Suchbegriff "configDB: setstate" -> 8282 Treffer und die Anfangsbuchstaben der Devices gehen von A-Z. Wobei das 2x speichern beinhalten müsste... also nehmen wir die Hälfte, was immer noch 4141 Treffer sind.

Suchbegriff "Cmd: >setstate" -> 629 Treffer und die Anfangsbuchstaben der Devices gehen von A-F. Der letzte Treffer zu dem Begriff steht in Zeile 16201 von insgesamt 171.413 Zeilen -> daraus schließe ich, dass es nicht daran liegt, dass ich zu früh das Logfile abgezogen habe.

Ich denke, irgendetwas bricht das Einlesen der states ab. Und dieses Problem hatte ich vor der Umstellung definitiv nicht. Du sagst immer, du kannst keine Fehlfunktion finden, aber irgendwas funktioniert ja scheinbar nicht.

betateilchen

#13
Zitat von: persching am 29 März 2022, 19:31:33
Ich denke, irgendetwas bricht das Einlesen der states ab. Und dieses Problem hatte ich vor der Umstellung definitiv nicht. Du sagst immer, du kannst keine Fehlfunktion finden, aber irgendwas funktioniert ja scheinbar nicht.

Langsam... grundsätzlich bestreite ich nicht, dass da bei Dir was schiefläuft.
Was ich nur sage, ist dass ich keine Fehlfunktion innerhalb der configDB erkennen kann. Dazu stehe ich nach wie vor. Zumal Du offenbar der Einzige bist, bei dem das Problem besteht.

Wenn das Einlesen abbricht, sollte es dazu eine Fehlermeldung in Deinem Logfile geben - entweder beim Schreiben oder beim Lesen.
Für das Problem kann es auch ganz andere Ursachen geben: Speicherproblem in der Hardware, Konfigurationsparameter der mySQL Datenbank usw.
Schau doch mal in das Fehlerlog Deines mySQL Servers, ob es dort Auffälligkeiten gibt. Wir hatten hier im Forum schon die merkwürdigsten Phänomene in diese Richtung.

Schau Dir doch mal mit "configdb fileshow <statefileName>" den Inhalt des statefiles in der Datenbank an.
Damit kannst Du zumindest feststellen, ob die Daten tatsächlich alle in der Datenbank stehen.
Auf diesem Weg können wir eingrenzen, ob das Problem beim Schreiben oder beim Lesen des statefile auftritt.
-----------------------
Formuliere die Aufgabe möglichst einfach und
setze die Lösung richtig um - dann wird es auch funktionieren.
-----------------------
Lesen gefährdet die Unwissenheit!

persching

Jetzt dachte ich gerade schon, dass ich dem ganze ein wenig näher gekommen bin, aber dem war nicht wirklich so.

Ich hatte mir die gespeicherten save.files angeschaut und immer bei einem Eintrag vom Modul Calendar hatte ich eine über 1400 Zeichen langen String. Da dachte ich, dass das vielleicht zu Problemen führt. Daraufhin habe ich das Device von FHEM_Kalender zu zzz_FHEM_Kalender umbenannt, weil es ja offenbar so ist, dass es nach alphabetischer Reihenfolge in die Datei geschrieben wird. Meine Erwartung wäre also gewesen, dass es jetzt bis zzz durchläuft.
Leider war dem nicht so. Es steht jetzt als letzte Zeile etwas anderes drin. Es bricht sogar mitten in der Zeile ab.
Jetzt habe ich mal alles in ein Word-Dokument kopiert, damit ich die Anzahl der Zeichen rausbekomme, aber es ist nicht die identische Zeichenanzahl. Aber es sind einmal 48.019 Zeichen (nach der Umbenennung) und einmal 48.044 Zeichen (vor der Umbenennung). Nach dem Umbenennen auf den Ursprungsnamen ist es wieder wie zuvor. Es bricht also scheinbar zuverlässig irgendwo bei 48.000 Zeichen ab...

Die einzige Erkenntnis: das File wird nicht sauber geschrieben.

Ich muss mich jetzt mal anschauen, wie ich das mit der Analyse mysql-Server-seitig mache. Das läuft bei mir alles in einem Docker Container und ich habe zwar ein Pfad zum Logverzeichnis in der docker-compose angegeben, aber in dem Logfile ist der letzte Eintrag von vor 2 Jahren. Da stimmt wohl was nicht, sonst würde ja das Logfile beschrieben werden.