Plugin simulation midnight exception

[whe]

um Mitternacht liefert das "Simulation Plugin" einen I/O error:

2018-08-01  00:00:00 ERROR    plugins.simulation.midnight Method plugins.simulation.midnight exception: I/O operation on closed file.
Traceback (most recent call last):
  File "/usr/local/smarthome/lib/scheduler.py", line 517, in _task
    obj()
  File "/usr/local/smarthome/plugins/simulation/__init__.py", line 288, in _midnight
    self.file.write('NextDay\n')
ValueError: I/O operation on closed file.

ich nutze den master branch von v1.5.1
habe festgestellt, dass es hier in develop auch noch keine Anpassung gibt.
keine Ahnung, wie ich das im code lösen soll

[psilo]

Ja das ist bekannt und "irgendjemand" muss sich der Lösung annehmen Ansonsten muss man halt die sehr selten vorkommende Logmeldung ertragen ;-) PS: zum Plugin gibt es auch einen Thread, da ist meines Wissens bspw. auch vom Problem berichtet. https://knx-user-forum.de/forum/supp...ulation-plugin

zumindest sollte jegliche diskussion in diesen initialen thread. vielleicht liest der pluginautor dort sogar noch mit... mir reichen meine 2 hand voll eigenen plugins zu maintainen.. wobei ich dem sim plugin ja sogar eine grafische gui spendiert habe

Ich ergänze den Link mal in den Plugin Metadaten

[whe]

PS: zum Plugin gibt es auch einen Thread, da ist meines Wissens bspw. auch vom Problem berichtet. https://knx-user-forum.de/forum/supp...ulation-plugin

dieser Thread ist von mir.
das waren meine Probleme nach der Umstellung auf 1.4 im Wesentlichen aber smartVISU Probleme bei der Visualisierung

[psilo]

dann gibt es noch einen älteren, in dem auch der sourcecode war.. mangels zeit kann ich jetzt aber nicht google spielen :> auf die schnelle finde ichs nicht mehr.. wäre toll wenn den link noch wer hat

[MichaelBu]

Hier bitte:
https://knx-user-forum.de/forum/supp...simulation-0-1

Ich geb ja zu, ich hab das damals geschrieben und seither fast nix mehr dran gemacht. Es hat sich trotzdem einiges
geändert, was ich mit erstmal alles anschauen muss wenn ich da wieder einsteigen will. Vielleicht wenn mein
Parkett fertig ist...
Der Quelltext ist ja im git. Gruß,
Die genannte Fehlermeldung sagt mir erstmal nichts. Bei mir passiert das nicht. Aber ich bin halt auch
noch auf einer ältreren Version.

Michael

[whe]

ich weis nicht warum, aber das midnight Problem hat sich von selbst gelöst, es tritt nicht mehr auf.
ich habe zur Analyse das logging für die Simulation auf DEBUG gestellt.
mittlerweile muss ich wohl gestehen, dass alles so funktioniert, wie ich es erwarte.

da ich überwiegend alles über Logiken automatisiert habe, erscheinen nur die manuellen Schaltungen in der file.
( so hatte ich es anfangs auch einmal gefordert )

ich werde das weiter beobachten.
im Moment bin ich mit dem plugin sehr zufrieden; es macht, was es soll und ist m.E. eine sehr nützliche Erfindung.

[psilo]

das problem wird wieder auftreten. aber sehr selten. es entsteht durch unguenstiges timing um mitternacht, wo einige interne operationen laufen. irgendwer hatte das schon mal genauer angesehen. ich pers. finde es aber nicht tragisch

[whe]

ich werde das Gefühl nicht los, dass Dinge nach der Umstellung auf 1.5 nicht mehr funktionieren.
in der yaml habe ich folgendes konfiguriert:

simulation:
    class_name: Simulation
    class_path: plugins.simulation
    data_file: /usr/local/smarthome/var/db/simulation.txt
#    callers:
#        - KNX
#        - Visu

die "callers" Angabe ist doch Optional; wenn ich die raus nehme, wird nichts mehr aufgezeichnet.
im DEBUG log finde ich bei Änderungen an items, die sim=track haben immer folgende Einträge:

2018-08-15  22:40:18 DEBUG    plugins.simulation scheduler_get: name = plugins.simulation.startrecord
2018-08-15  22:40:18 DEBUG    plugins.simulation scheduler_get: name = plugins.simulation.simulate
2018-08-15  22:40:18 DEBUG    plugins.simulation is_staticfile: path=static/img/plugin_logo.png, complete_path=/usr/local/smarthome/plugins/simulation/webif/static/img/plugin_logo.png, result=True
2018-08-15  22:40:18 INFO     cherrypy.access.1745930480 192.168.178.21 - - [15/Aug/2018:22:40:18] "GET /simulation/?cmd=show_data_file HTTP/1.1" 200 7132 "http://192.168.178.42:8383/simulation/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:61.0) Gecko/20100101 Firefox/61.0"
2018-08-15  22:41:57 DEBUG    plugins.simulation scheduler_get: name = plugins.simulation.startrecord
2018-08-15  22:41:57 DEBUG    plugins.simulation scheduler_get: name = plugins.simulation.simulate
2018-08-15  22:41:57 DEBUG    plugins.simulation is_staticfile: path=static/img/plugin_logo.png, complete_path=/usr/local/smarthome/plugins/simulation/webif/static/img/plugin_logo.png, result=True
2018-08-15  22:41:57 INFO     cherrypy.access.1745930480 192.168.178.21 - - [15/Aug/2018:22:41:57] "GET /simulation/ HTTP/1.1" 200 13806 "http://192.168.178.42:8383/simulation/?cmd=show_data_file" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:61.0) Gecko/20100101 Firefox/61.0"
2018-08-15  22:41:59 DEBUG    plugins.simulation scheduler_get: name = plugins.simulation.startrecord
2018-08-15  22:41:59 DEBUG    plugins.simulation scheduler_get: name = plugins.simulation.simulate
2018-08-15  22:41:59 DEBUG    plugins.simulation is_staticfile: path=static/img/plugin_logo.png, complete_path=/usr/local/smarthome/plugins/simulation/webif/static/img/plugin_logo.png, result=True
2018-08-15  22:41:59 INFO     cherrypy.access.1745930480 192.168.178.21 - - [15/Aug/2018:22:41:59] "POST /simulation/ HTTP/1.1" 200 13806 "http://192.168.178.42:8383/simulation/?" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:61.0) Gecko/20100101 Firefox/61.0"
2018-08-15  22:42:44 DEBUG    plugins.simulation scheduler_get: name = plugins.simulation.startrecord
2018-08-15  22:42:44 DEBUG    plugins.simulation scheduler_get: name = plugins.simulation.simulate
2018-08-15  22:42:44 DEBUG    plugins.simulation is_staticfile: path=static/img/plugin_logo.png, complete_path=/usr/local/smarthome/plugins/simulation/webif/static/img/plugin_logo.png, result=True
2018-08-15  22:42:44 INFO     cherrypy.access.1745930480 192.168.178.21 - - [15/Aug/2018:22:42:44] "POST /simulation/ HTTP/1.1" 200 13806 "http://192.168.178.42:8383/simulation/?" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:61.0) Gecko/20100101 Firefox/61.0"
2018-08-15  22:42:49 DEBUG    plugins.simulation scheduler_get: name = plugins.simulation.startrecord
2018-08-15  22:42:49 DEBUG    plugins.simulation scheduler_get: name = plugins.simulation.simulate
2018-08-15  22:42:49 DEBUG    plugins.simulation is_staticfile: path=static/img/plugin_logo.png, complete_path=/usr/local/smarthome/plugins/simulation/webif/static/img/plugin_logo.png, result=True
2018-08-15  22:42:49 INFO     cherrypy.access.1745930480 192.168.178.21 - - [15/Aug/2018:22:42:49] "GET /simulation/?cmd=show_data_file HTTP/1.1" 200 7132 "http://192.168.178.42:8383/simulation/?" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:61.0) Gecko/20100101 Firefox/61.0"
2018-08-15  22:42:52 DEBUG    plugins.simulation scheduler_get: name = plugins.simulation.startrecord
2018-08-15  22:42:52 DEBUG    plugins.simulation scheduler_get: name = plugins.simulation.simulate
2018-08-15  22:42:52 DEBUG    plugins.simulation is_staticfile: path=static/img/plugin_logo.png, complete_path=/usr/local/smarthome/plugins/simulation/webif/static/img/plugin_logo.png, result=True
2018-08-15  22:42:52 INFO     cherrypy.access.1745930480 192.168.178.21 - - [15/Aug/2018:22:42:52] "POST /simulation/?cmd=show_data_file HTTP/1.1" 200 7132 "http://192.168.178.42:8383/simulation/?cmd=show_data_file" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:61.0) Gecko/20100101 Firefox/61.0"
2018-08-15  22:42:54 DEBUG    plugins.simulation scheduler_get: name = plugins.simulation.startrecord
2018-08-15  22:42:54 DEBUG    plugins.simulation scheduler_get: name = plugins.simulation.simulate
2018-08-15  22:42:54 DEBUG    plugins.simulation is_staticfile: path=static/img/plugin_logo.png, complete_path=/usr/local/smarthome/plugins/simulation/webif/static/img/plugin_logo.png, result=True
2018-08-15  22:42:54 INFO     cherrypy.access.1745930480 192.168.178.21 - - [15/Aug/2018:22:42:54] "POST /simulation/?cmd=show_data_file HTTP/1.1" 200 7132 "http://192.168.178.42:8383/simulation/?cmd=show_data_file" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:61.0) Gecko/20100101 Firefox/61.0"
2018-08-15  22:46:21 DEBUG    plugins.simulation scheduler_get: name = plugins.simulation.startrecord
2018-08-15  22:46:21 DEBUG    plugins.simulation scheduler_get: name = plugins.simulation.simulate
2018-08-15  22:46:21 DEBUG    plugins.simulation is_staticfile: path=static/img/plugin_logo.png, complete_path=/usr/local/smarthome/plugins/simulation/webif/static/img/plugin_logo.png, result=True

wer schreibt die raus und was bedeuten sie.

[psilo]

Das sind Info und Debug (!) Logs aur über das SmartPlugin genutzten Methode scheduler_get, die (wie früher) an die zentrale Schedulerverwaltung delegiert.
Das sind keine Errors und vollkommen normal wie bereits häufig erörtert. Via logging.yaml kann man das ausblenden.

Das Info besagt, dass eine PNG Datei via Web geladen wird (vermutlich vom Webinterface).

Die Aufnahme startet bei noch keinen Einträgen übrigens um 0:00 des Folgetags. Als ich das WebIF gebaut und das angezeigt habe, war mir das auch etwas schleierhaft, es war aber noch nie anders (jetzt sieht man es halt).

fff.JPG

Hier die start_record Methode - wenn es keinen Entry gibt, wird start auf 0:00 des Folgetags gesetzt, ansonsten auf den Wert des last_entry:

    def _start_record(self):
        tank = self._get_tank()
        self.logger.debug('Tank: {}'.format(tank))
        self.tank(tank)
        now = self.shtime.now()
        last_entry = self._lastentry.replace(year=now.year, month=now.month, day=now.day, tzinfo=now.tzinfo)
        self.logger.debug('last entry: {}'.format(last_entry))
        self.logger.debug('now: {}'.format(now))
        now -= timedelta(minutes=15)
        if now.time() < last_entry.time():
            self._schedule_recording_start(last_entry)
        else:
            start = last_entry
            start += timedelta(days=1)
            self._schedule_recording_start(start)

Der Callers Parameter wurde in https://github.com/smarthomeNG/plugi...c2690bec5c0066 optional gemacht, seitdem hat sich der Code nicht geändert.

Bugs sind hier aber auch nie auszuschliessen. Mit 1.5.x hat das dann aber nichts zu tun.

Wo ich gerade unsicher bin ist, ob dieses IF bei Angabe keiner Caller ein True erhält:

if (item.conf['sim'] == 'track') and (self.state()==2) and (self._callers and caller in self._callers):

Meiner MEinung nach müsste das eher:

if (item.conf['sim'] == 'track') and (self.state() == 2) and (self._callers is None or caller in self._callers):

heißen.

Meinungen? Ich teste das mal bei mir lokal.. Dann kann ich auch gleich auf das neue Parameterhandling via plugin.yaml migrieren

PPS: Im DEVELOP ist eine neue Version, die bei mir jetzt in den Test läuft. Scheint jetzt aber korrekt zu gehen.

[whe]

das DEBUG log hatte ich extra eingeschaltet um zu erfahren, wieso keine Daten im log landen.
das mit dem verzögerten Start ist mir klar; im Backend wird ja auch angezeigt, wann es wieder losgeht.
beim Testen ist das lästig, man muss immer 24 Stunden warten.

der IF war mir auch aufgefallen und das letzte "and" habe ich nicht verstanden; ich passe das mal an.
mit der "callers" Angabe im INI hat die Simulation ja auch etwas aufgezeichnet; aber ohne nicht.

NextDay
NextDay
NextDay
NextDay
NextDay
Tue;06:05:27;OG.Tobias.Deckenlicht;True;KNX
Di;14:44:19;Garten.LichtL1;True;Visu
Di;14:44:24;Garten.LichtRV;True;Visu
Di;14:44:28;Garten.LichtL1;False;Visu
Di;14:44:30;Garten.LichtRV;False;Visu
Di;21:57:12;Garten.LichtGS;True;Visu
NextDay

kann ich irgendwo erkennen, welche "callers" es gibt; außer in den Einträgen ?

[psilo]

whe in der README werden im Beispiel 2 genannt, theoretisch sind da aber beliebig viele mehr möglich, je nachdem welche Plugins etc Du laufen hast

simulation:
    class_name: Simulation
    class_path: plugins.simulation
    data_file: /usr/smarthome/var/db/simulation.txt
    # callers:
    #   - KNX
    #   - Visu

 `callers`: Is an optional list of event sources for recording of events. When an item is changed, the change is done by someone,
e.g. knx for changes from the bus. The caller name is set by the plugin programmer and has to be found out manually. Only item
changes with a caller in the list are recorded to the simulation file. In the example above e.g. uzsu is ignored. Be aware that the
caller in the list has to be case sensitive. Otherwise it won't trigger.

Siehst Du bspw bei den Itemdetails im Itemtree im Backend!

[psilo]

PS: die Startzeit leuchtet mir ehrlich gesagt auch nicht ein, ich will da aber nicht einfach was ändern.. Die Plugins externer Autoren sind halt oft noch nicht so richtig reif...

        now = self.shtime.now()
        last_entry = self._lastentry.replace(year=now.year, month=now.month, day=now.day, tzinfo=now.tzinfo)
        now -= timedelta(minutes=15)
        if now.time() < last_entry.time():
            self._schedule_recording_start(last_entry)
        else:
            start = last_entry
            start += timedelta(days=1)
            self._schedule_recording_start(start)

Ich hätte bspw. erwartet, dass nach einem Restart von SHNG die Zeit des LAST_ENTRY als Startzeit genommen wird. Ist aber nicht so, auch da wird 1 Tag draufaddiert.

[whe]

Meiner MEinung nach müsste das eher: Code:

if (item.conf['sim'] == 'track') and (self.state() == 2) and (self._callers is None or caller in self._callers):
heißen.

das hat geholfen, bei mir wird jetzt wieder alles aufgezeichnet.