Viessmann Plugin Neuentwicklung Python Hilfe

[Sisamiwe]

Morg

Super, dass Du dir da noch mal angeschaut und verbessert hast.

Die neuen Funktionen mit dem Timer und der UZSU funktionieren, auch fehlerfrei. Probiere das aber weiter aus.
EDIT: Habe noch einen Fehler gefunden. In Zeile 1145 muss es heißen:

for event, time in entry.items():

; dann klappt es.

Folgendes ist mit nun an andere Stelle aufgefallen:
Beim Schreiben von Datetime Objekten wie Systemtime oder Ferienprogramm meldet das Plugin einen Fehler.
Korrigiert man die Systemtime im Backend, wirft das Plugin den Fehler:

2020-05-23  13:12:04 INFO     plugins.viessmann   viessmann: Update item: heizung.kessel.systemtime, item has been changed outside this plugin
2020-05-23  13:12:04 DEBUG    plugins.viessmann   viessmann: update_item was called with item 'Systemzeit' from caller 'admin', source 'None' and dest 'None'
2020-05-23  13:12:04 DEBUG    plugins.viessmann   viessmann: Got item value to be written: 2020-05-23T13:12:55 on command name Systemtime.
2020-05-23  13:12:04 DEBUG    plugins.viessmann   viessmann: Got a new write job: Command Systemtime with value 2020-05-23T13:12:55
2020-05-23  13:12:04 DEBUG    plugins.viessmann   viessmann: Command config: {'unit': 'TI', 'min_value': 0, 'set': True, 'max_value': 1193045, 'addr': '088E', 'len': 8}
2020-05-23  13:12:04 DEBUG    plugins.viessmann   viessmann: Unit defined to TI with config{'read_value_transform': 'non', 'type': 'datetime', 'signed': False, 'unit_de': 'SystemTime'}.
2020-05-23  13:12:04 DEBUG    plugins.viessmann   viessmann: create_write_command failed with error: unorderable types: int() <= str().
2020-05-23  13:12:04 DEBUG    plugins.viessmann   viessmann: Write for Systemtime with value 2020-05-23T13:12:55 failed, reverting value, canceling followup actions

Beim Setzen des Ferientage gibt es auch einen Fehler:

2020-05-23  13:23:02 ERROR    plugins.viessmann   viessmann: Incorrect data format, YYYY-MM-DD expected; Error: type object 'datetime.datetime' has no attribute 'fromisoformat'
2020-05-23  13:23:02 DEBUG    plugins.viessmann   viessmann: Write for Ferien_Rückreisetag_M2 with value 2020-05-24 failed, reverting value, canceling followup actions

Wenn ich den Codeteil alleine teste, funktioniert die Umwandlung.
Ich bin mir sicher, dass die beiden Funktionen schon mal funktioniert haben und am Code nichts geändert wurde.
Hast Du eine Idee?

[Morg]

Tja... da hakt es etwas in der Programmlogik.

Du bekommst vom shng einen String im ISO-Datumsformat (im Log:"2020-05-23T13:12:55".

In deinen Units ist für die Unit "TI" aber definiert, dass der Minimalwert 0 und der Maximalwert 1193045 ist.

In Zeile 580 steht

 if (min_allowed_value is None or min_allowed_value <= value) and (max_allowed_value is None or max_allowed_value >= value):

und da min_allowed_value und max_allowed_value für TI definiert sind, wirft er dort nen Fehler.

Die einfachere Lösung wäre, im TI-Format die min- und max-Werte zu löschen (None); der aufwändigere Weg, den Wert vorher (update_item?) in int bzw. timestamp zu konvertieren, dann den min/max-Check wie gehabt laufen zu lassen, und in _send_write_command() dann wieder einen (echten) datetime draus zu machen, der dann in Unit TI konvertiert wird.

Der Rest von _send_write_command() geht - korrekterweise - davon aus, dass du einen String übergibst. Ich würde mal versuchen, in TI die max und min rauszunehmen.

Zum zweiten Fehler:
kann ich so nicht sagen. Vielleicht könntest du dein Logging anpassen, gem. https://www.smarthomeng.de/user/konf...practices.html, Abschnitt Erweitertes Logging für die Plugin Entwicklung

Dann steht im Log, welche Funktion den Fehler erzeugt hat, das macht es ggf. noch einfacher.

[Sisamiwe]

Der Rest von _send_write_command() geht - korrekterweise - davon aus, dass du einen String übergibst. Ich würde mal versuchen, in TI die max und min rauszunehmen.

habe ich gemacht. Nun funktioniert es bzw. es kommt nun zum gleichen Fehler, wie beim Setzen des Ferientages.

kann ich so nicht sagen. Vielleicht könntest du dein Logging anpassen, gem. https://www.smarthomeng.de/user/konf...practices.html, Abschnitt Erweitertes Logging für die Plugin Entwicklung

Hab ich gemacht. Das Log:

2020-05-23  16:06:36 DEBUG    plugins.viessmann update_item      update_item was called with item 'Systemzeit' from caller 'admin', source 'None' and dest 'None'
2020-05-23  16:06:36 DEBUG    plugins.viessmann update_item      Got item value to be written: 2020-05-23T16:06:02 on command name Systemtime.
2020-05-23  16:06:36 DEBUG    plugins.viessmann _send_write_command Got a new write job: Command Systemtime with value 2020-05-23T16:06:02
2020-05-23  16:06:36 DEBUG    plugins.viessmann _send_write_command Command config: {'max_value': None, 'addr': '088E', 'len': 8, 'unit': 'TI', 'min_value': None, 'set': True}
2020-05-23  16:06:36 DEBUG    plugins.viessmann _send_write_command Unit defined to TI with config{'unit_de': 'SystemTime', 'type': 'datetime', 'read_value_transform': 'non', 'signed': False}.
2020-05-23  16:06:36 ERROR    plugins.viessmann _send_write_command Incorrect data format, YYYY-MM-DD expected; Error: type object 'datetime.datetime' has no attribute 'fromisoformat'
2020-05-23  16:06:36 DEBUG    plugins.viessmann update_item      Write for Systemtime with value 2020-05-23T16:06:02 failed, reverting value, canceling followup actions

Es scheint an Zeile 585 zu liegen "datestring = datetime.fromisoformat(value).strftime("%Y%m%d%w%H %M%S")"

[Morg]

Mich wundert das datetime.datetime kein fromisoformat haben soll. Welche Python-Version hast du denn installiert?

Aus einem mir derzeit unklaren Grund passt da was nicht... ich hab das bei mir direkt im Python-Interpreter probiert, da ging es.

Ich vermute, wenn du Python3 direkt startest und

from datetime import datetime
datetime.fromisoformat("2020-05-23")

eingibst, kommt kein Fehler?

Du könntest noch vor der von dir genannten Zeile einfügen

self.logger.debug("value is '{}' and has type {}".format(value, type(value)))

Ehrlicherweise erwarte ich da aber keine Überraschung, sondern "2020-05-23T16:06:02" und <class 'str'>...

[Sisamiwe]

Ich vermute, wenn du Python3 direkt startest und
Code:

from datetime import datetime datetime.fromisoformat("2020-05-23")
eingibst, kommt kein Fehler?

Doch. Wenn ich auf meinen "produktiv RPI" in der Console Python3 starte, kommt der gleiche Fehler wie im Plugin.

 [smarthome@SmartHomeNG ~]$ python3
Python 3.5.3 (default, Sep 27 2018, 17:25:39)
[GCC 6.3.0 20170516] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> from datetime import datetime
>>> datetime.fromisoformat("2020-05-23")
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
AttributeError: type object 'datetime.datetime' has no attribute 'fromisoformat'
>>>

Edit:
Ich habe mit mal die zur Verfügung stehenden Attribute anzeigen lassen:

>>> print(dir(datetime))
['__add__', '__class__', '__delattr__', '__dir__', '__doc__', '__eq__', '__format__', '__ge__', '__getattribute__',                                                                   '__gt__', '__hash__', '__init__', '__le__', '__lt__', '__ne__', '__new__', '__radd__', '__reduce__', '__reduce_ex_                                                                  _', '__repr__', '__rsub__', '__setattr__', '__sizeof__', '__str__', '__sub__', '__subclasshook__', 'astimezone', 'c                                                                  ombine', 'ctime', 'date', 'day', 'dst', 'fromordinal', 'fromtimestamp', 'hour', 'isocalendar', 'isoformat', 'isowee                                                                  kday', 'max', 'microsecond', 'min', 'minute', 'month', 'now', 'replace', 'resolution', 'second', 'strftime', 'strpt                                                                  ime', 'time', 'timestamp', 'timetuple', 'timetz', 'today', 'toordinal', 'tzinfo', 'tzname', 'utcfromtimestamp', 'ut                                                                  cnow', 'utcoffset', 'utctimetuple', 'weekday', 'year']

fromisoformat ist nicht dabei.

Edit2:

Ich glaube, das Attribut "fromisoformat" ist erst mit Python 3.7 eingeführt worden.
Mein ProduktivRPI läuft noch mit 3.5.3.

Edit 3:
Die Lösung: Ich habe die "fromisoformat" durch ein anderes Attribut erstetzt.

import dateutil.parser
datestring = dateutil.parser.isoparse(value).strftime("%Y%m%d%w%H%M%S")

[Morg]

Das erklärt natürlich den Fehler aber gut, dass der gefunden ist.

Ansonsten läuft das jetzt problemlos?

[Sisamiwe]

Ansonsten läuft das jetzt problemlos?

Bislang ja. Ich möchtes es noch etwas beobachten. Dann setzt ich auf version 1.0.0 und stelle einen PR.

Was mir noch im Log aufgefallen ist:
Es gibt öfters im Log den Eintrag:

2020-05-24  10:38:26 DEBUG    plugins.viessmann send_cyclic_cmds cyclic command read took 0.0 seconds for 0 items

Ich gehen davon aus, dass diese Meldung kommt, wenn die Funktion aufgerufen wird, aber noch kein Item "due" ist.
Was meinst Du?

[Morg]

Genau, der "cyclic"-Timer läuft ja regelmäßig, und ich glaube, du hattest als Cycle-Zeit die Hälfte der kürzesten geforderten Zeitspanne genommen. Dann kann es ja immer mal passieren, dass er läuft, ohne dass was ansteht. Die Meldung kommt dann trotzdem. Ist aber debug, sollte mMn nicht stören, oder?

[Sisamiwe]

Ist aber debug, sollte mMn nicht stören, oder?

nee, passt.

[Sisamiwe]

Hallo Morg

hab heute mal wieder ins Log geschaut und wieder Fehlereinträge entdeckt.

Ich hatte letzthin am die Heizung vom Stromnetz genommen. Das Plugin verbindet sich wieder, trotzdem kommen Fehlermeldungen. Es schein, als wenn die cyclic-cmds nicht korrekt laufen/behandelt werden.

2020-05-27 10:00:20 ERROR plugins.database Database: Can't query due to fail to acquire lock
2020-05-27 10:01:08 ERROR lib.scheduler Needing more worker threads than the specified maximum of 20!
2020-05-27 10:01:40 WARNING plugins.database Skipping dump, since other dump running!
2020-05-27 10:02:03 WARNING plugins.viessmann Triggered cyclic command read, but previous cyclic run is still active. Check device and cyclic configuration (too much/too short?)
2020-05-27 10:02:04 WARNING plugins.viessmann Triggered cyclic command read, but previous cyclic run is still active. Check device and cyclic configuration (too much/too short?)
2020-05-27 10:02:05 WARNING plugins.viessmann Triggered cyclic command read, but previous cyclic run is still active. Check device and cyclic configuration (too much/too short?)
2020-05-27 10:02:05 WARNING plugins.viessmann Triggered cyclic command read, but previous cyclic run is still active. Check device and cyclic configuration (too much/too short?)
2020-05-27 10:08:59 ERROR plugins.viessmann send_command failed with IO error: IO Error: write failed: [Errno 5] Eingabe-/Ausgabefehler.
2020-05-27 10:08:59 ERROR plugins.viessmann Trying to reconnect (disconnecting, connecting
2020-05-27 10:08:59 ERROR plugins.viessmann Not connected, trying to reconnect.

2020-05-27 10:22:03 ERROR lib.scheduler Needing more worker threads than the specified maximum of 20!
2020-05-27 10:23:04 ERROR lib.scheduler Needing more worker threads than the specified maximum of 20!
2020-05-27 10:24:06 ERROR lib.scheduler Needing more worker threads than the specified maximum of 20!
2020-05-27 10:25:07 ERROR lib.scheduler Needing more worker threads than the specified maximum of 20!
2020-05-27 10:26:09 ERROR lib.scheduler Needing more worker threads than the specified maximum of 20!
2020-05-27 10:27:01 ERROR plugins.smlx Reading data from serial:///dev/ttyUSB_volkszaehler failed with exception read failed: device reports readiness to read but returned no data (device disconnected or multiple access on port?)
2020-05-27 10:27:06 WARNING plugins.viessmann Triggered cyclic command read, but previous cyclic run is still active. Check device and cyclic configuration (too much/too short?)
2020-05-27 10:27:07 WARNING plugins.viessmann Triggered cyclic command read, but previous cyclic run is still active. Check device and cyclic configuration (too much/too short?)
2020-05-27 10:27:07 WARNING plugins.viessmann Triggered cyclic command read, but previous cyclic run is still active. Check device and cyclic configuration (too much/too short?)
2020-05-27 10:27:08 WARNING plugins.viessmann Triggered cyclic command read, but previous cyclic run is still active. Check device and cyclic configuration (too much/too short?)
2020-05-27 10:27:09 WARNING plugins.viessmann Triggered cyclic command read, but previous cyclic run is still active. Check device and cyclic configuration (too much/too short?)

Kannst Du das bei Dir mal nachstellen?

[Morg]

Ich versuchs.

Was hast du für einen Lesekopf? Hast du den irgendwie konfiguriert?

Mich wundert dieses "Hängenbleiben" etwas, da scheint kein Timeout und nix zu greifen...

Ist dein Repo aktuell? Dann hole ich mir nochmal die letzte Version...

[Morg]

Ich glaube, ich weiß, wo das Problem zu suchen ist.

Die offensichtliche Wirkung ist, dass die Methode send_cyclic_cmds() nicht beendet wird, und daher weitere zyklische Leseversuche blockiert. Wieso die sich anhäufen, statt mit Meldung "Triggered..., but previous cyclic run is still active..." zu beenden, kann ich nicht sagen. Das scheint aber den Scheduler zu füllen.

Zur Frage, wieso das passiert:

beim Öffnen der seriellen Schnittstelle wird ein Timeout von 1 Sekunde festgelegt - das heißt, serial.read(bytes) liest <bytes> Bytes, wenn es kann, ansonsten beendet es nach 1 Sekunde. Soweit, sogut - aber das wird durch _read_bytes() ad absurdum geführt, weil dort in einer Schleife so lange gewartet wird, bis <bytes> Bytes angekommen sind; es findet aber keine Zeitprüfung auf Timeouts statt.
Da es auch keine Erkennung von "disconnects" gibt (anders als bei netzwerkbasierten Verbindungen), wartet er sich bei ausgeschalteter Heizung zu Tode. Nach Einschalten der Heizung weiß er ja auch nicht, dass er _connect() und _init_communication() neu aufrufen muss, also wartet er weiter.

Folgenden müsste man mMn anpassen:

• _read_bytes() umschreiben ohne Schleife, um mehr Bytes zu lesen, sondern mit einfachem Aufruf von serial.read(bytes). Wenn ich in der Zeit nicht genug bekomme, dann muss ich entweder grundsätzlich die Zeit erhöhen, oder das Paket verwerfen. Das mag eine Anzahl von Lesefehlern erzeugen, verhindert aber Blockaden
• Erkennung von Timeouts einbauen: wenn weniger Bytes gelesen wurden als erwartet, dann war es ein Fehler oder ein Timeout - das müsste man erkennen. Bei erkannten Timeouts (Verbindung weg?) Lesen abbrechen und self._connected = False setzen.
• Irgendwo (wahrscheinlich update_item() und _send_cyclic_commands()) muss vornean self._connected geprüft werden. Falls nicht verbunden, versuchen, die Verbindung neu aufzubauen. Wenn das nicht geht -> beenden, so dass das Plugin nicht (sich) blockiert.

Wenn ich das machen soll, brauche ich bitte nochmal die aktuellen Versionen; idealerweise im alten oder (ggf. schon) neuen Repo (du wolltest es umbauen? einfach den Ordner "viessmann" im Repo my_plugins als eigenes Repo "viessmann" aufsetzen)

[Morg]

Ich habe mal versucht, deine oben angesprochenen Änderungen (Typos von mir, min/max bei Systemzeit) nachzuvollziehen und die notwendigen Änderungen einzubauen.

Da ich das in meinem Produktivsystem testen musste, habe ich das in ein "klassisches" Repo gepackt (https://github.com/Morg42/viessmann.git). Ich habe

• an fast alles relevanten Stellen nochmal eine Prüfung auf self._connected() bzw. self._initialized() eingefügt
• in _send_command() die Auswertung um die Prüfung auf "not initialized" ergänzt -> forciert dann Neu-Initialisierung
• in _read_bytes() aus der 'while True'-Schleife eine mit Timeout gemacht, den Timeout-Parameter fürs Plugin eingefügt
• noch ein paar Stellen mit Fehlerkontrolle und -korrektur ergänzt
• die Methoden etwas umsortiert - "öffentliche" zuerst, danach inhaltlich sortiert und kommentiert
• noch ein paar kleinere Updates für lesbareren Code eingefügt
• Schleifenvariable 'time' in 'sw_time' umbenannt, um Namensraumkonflikte mit dem Modul 'time' zu vermeiden

In meiner Analyse oben war noch ein Fehler, zumindest ein möglicher: bei meinem Lesekopf gibt es keine Timeouts, da ja der Lesekopf immer noch reagiert und die serielle Verbindung da ist. Beim Lesen gibt es eben immer nur b'', und Schreiben ist erfolgreich, da serial.write() keinen Status zurückgibt. Also reicht der Timeout in read_bytes() nicht, sondern ich musste noch die Prüfung auf "not_initialized" ergänzen.

Verhalten bei mir:

• Plugin funktioniert fehlerfrei
• Heizung aus (Netzschalter): jeder Lesevorgang liefert b'', also 0 Bytes und ändert daher keine Items. Das Fehlen wird nicht erkannt (könnte man bei Bedarf noch überlegen)
  Ein Cycle mit 25 Items läuft jetzt immerhin schon 21 Sekunden -- wenn ich deutlich mehr Items lesen will, und den Parameter cycle zu kurz gesetzt habe, überschneiden die sich. Eigentlich sollten die neuen Schedules dann einfach ins Leere laufen ("...still active..."). Hier keine Probleme.
• Heizung wieder an: er erkennt die Antwort b'0x05' als "not initialized" und startet die Initialisierung neu, danach gleich wieder funktionsfähig.

Ich wäre dir dankbar, wenn du die neue Version nochmal testest. Falls du selbst noch weitere Änderungen gemacht hast, gib mir bitte eine entsprechende Info, dann kann ich das noch nachpflegen.

[Sisamiwe]

Hallo Morg,

ich komme erst jetzt dazu, Dir zu antworten.

Was hast du für einen Lesekopf? Hast du den irgendwie konfiguriert?

Den Orgininalen vonm Viessmann Concect.

Die offensichtliche Wirkung ist, dass die Methode send_cyclic_cmds() nicht beendet wird, und daher weitere zyklische Leseversuche blockiert. Wieso die sich anhäufen, statt mit Meldung "Triggered..., but previous cyclic run is still active..." zu beenden, kann ich nicht sagen. Das scheint aber den Scheduler zu füllen.

Ok.

Ich wäre dir dankbar, wenn du die neue Version nochmal testest. Falls du selbst noch weitere Änderungen gemacht hast, gib mir bitte eine entsprechende Info, dann kann ich das noch nachpflegen.

Das mache ich gern. Komme morgen oder am WE dazu und melde mich.

[Sisamiwe]

Ich wäre dir dankbar, wenn du die neue Version nochmal testest. Falls du selbst noch weitere Änderungen gemacht hast, gib mir bitte eine entsprechende Info, dann kann ich das noch nachpflegen.

Test läuft!
Bislang alles gut.