Entwicklung Plugin für Denon / Marantz Receiver

[Morg]

Das ist tatsächlich ein bisher nicht aufgefallener Fehler im master. Es passiert genau das, was ich oben befürchtet habe - die SmartPlugin-Klasse setzt - routinemäßig - das Suspend-Item, aber gibt den Parameter nicht mit, der eine erneute Bearbeitung in update_item verhindert.

Im aktuellen develop ist das durch die komplette Umstellung des suspend-Mechanismus gefixt, falls das für dich eine Option ist. Ansonsten müsstest du bei dir eine Datei anpassen (lib/model/smartplugin.py, Zeilen 92 und 104:

self._suspend_item(False, self.get_fullname())

bzw.

self._suspend_item(True, self.get_fullname())

Gib gern Bescheid, wie du dich entscheidest und ob es dann geholfen hat

[loeserman]

Toll dass Du das so schnell gefunden hast. Ich habe mal Variante zwei genommen und die beiden Zeilen umgeändert und den Master bei mir ansonsten belassen. Das scheint schon zu gehen mit dem SUSPEND.

Habe mal folgendes gemacht
+ Neustart SH - Plugin läuft / Verstärker ist an
+ Kommando gesendet -- geht
+ SUSPEND auf True
+ Kommando gesendet -- geht nicht (also auch okay)

+ Log Einstellungen auf DEBUG (siehe Logausgabe START)
+ SUSPEND auf False gesetzt
+ Kommando gesendet -- geht
+ SUSPEND auf True gesetzt
+ Kommando gesendet -- geht nicht (also auch okay)
+ SUSPEND auf False gesetzt
+ Log Einstellungen auf INFO (siehe Logausgabe ENDE)

Log Ausgabe

2024-09-30  20:24:46 NOTICE   modules.admin.loggers Logger 'lib.model.sdp' changed from WARNING to DEBUG
2024-09-30  20:24:52 NOTICE   modules.admin.loggers Logger 'plugins.denon' changed from NOTICE to DEBUG
2024-09-30  20:25:35 DEBUG    plugins.denon       Update_item was called with item "Rxx Denon Plugin suspendieren / fortfuehren" from caller smartVISU, source 192.168.123.17 and dest None
2024-09-30  20:25:35 DEBUG    plugins.denon       Suspend item changed to False
2024-09-30  20:25:35 DEBUG    plugins.denon       Suspend mode disabled (set by suspend item SONDERFUNKTIONEN.PLUGINS.SUSPEND_DENON)
2024-09-30  20:25:35 INFO     plugins.denon       plugin resumed by suspend item SONDERFUNKTIONEN.PLUGINS.SUSPEND_DENON, connections will be resumed
2024-09-30  20:25:35 DEBUG    plugins.denon       Update_item was called with item "Rxx Denon Plugin suspendieren / fortfuehren" from caller denon, source None and dest None
2024-09-30  20:25:35 DEBUG    lib.model.sdp.connection open method called for connection
2024-09-30  20:25:35 DEBUG    lib.model.sdp.connection SDPConnectionNetTcpClient opening connection with params {'serialport': '', 'baudrate': 9600.0, 'bytesize': 8.0, 'parity': 'N', 'stopbits': 1.0, 'protocol': None, 'host': '192.168.123.26', 'port': 23, 'binary': False, 'timeout': 3.0, 'autoreconnect': True, 'autoconnect': True, 'connect_retries': 5.0, 'connect_cycle': 3.0, 'retry_cycle': 30.0, 'retry_suspend': 3.0, 'terminator': b'\r', 'connected_callback': None, 'disconnected_callback': None, 'suspend_callback': <bound method SmartDevicePlugin.set_suspend of <plugins.denon.denon object at 0x7f9ade8ffb50>>, 'done': False, 'model': 'AVR-X3300W', 'conn_type': 'net_tcp_client', 'command_class': 'SDPCommandParseStr', 'suspend_item': 'SONDERFUNKTIONEN.PLUGINS.SUSPEND_DENON', 'webif_pagelength': 0, 'plugin_path': 'plugins.denon', 'custom_patterns': {1: '', 2: '', 3: ''}}
2024-09-30  20:25:35 WARNING  lib.network         (denon_192.168.123.26:23) TCP connection failed 1/5 times, last error was: [Errno 111] Verbindungsaufbau abgelehnt
2024-09-30  20:25:35 WARNING  lib.network         self._connect() for denon did not work
2024-09-30  20:25:38 INFO     lib.model.sdp.connection on_connect called by denon
2024-09-30  20:26:01 DEBUG    plugins.denon       Update_item was called with item "R16.MARANTZ.zone1.control.power" from caller smartVISU, source 192.168.123.17 and dest None
2024-09-30  20:26:01 INFO     plugins.denon       Update item: R16.MARANTZ.zone1.control.power: item has been changed outside this plugin
2024-09-30  20:26:01 DEBUG    plugins.denon       Writing value "True" from item R16.MARANTZ.zone1.control.power with command "zone1.control.power"
2024-09-30  20:26:01 DEBUG    plugins.denon       command zone1.control.power with value True yielded send data_dict {'payload': 'ZMON\r', 'data': 'ON', 'limit_response': b'\r'}
2024-09-30  20:26:01 DEBUG    lib.model.sdp.connection received raw data "ZMON" from "denon"
2024-09-30  20:26:01 DEBUG    plugins.denon       received data "ZMON" from denon without command specification
2024-09-30  20:26:01 DEBUG    lib.model.sdp.commands matched reply_pattern ZM(ON|OFF) as regex against data ZMON, found command zone1.control.power
2024-09-30  20:26:01 DEBUG    lib.model.sdp.command parse_str command got data ZMON of type <class 'str'>
2024-09-30  20:26:01 DEBUG    plugins.denon       received data "ZMON" for command zone1.control.power converted to value True
2024-09-30  20:26:01 DEBUG    plugins.denon       Command zone1.control.power wants to update item R16.STECKDOSE.MARANTZ.zone1.control.power with value True received from denon
2024-09-30  20:26:01 DEBUG    plugins.denon       Update_item was called with item "R16.STECKDOSE.MARANTZ.zone1.control.power" from caller denon, source None and dest None
2024-09-30  20:26:01 DEBUG    plugins.denon       Command zone1.control.power wants to update item R16.MARANTZ.zone1.control.power with value True received from denon
2024-09-30  20:26:02 DEBUG    lib.model.sdp.connection received raw data "PWON" from "denon"
2024-09-30  20:26:02 DEBUG    plugins.denon       received data "PWON" from denon without command specification
2024-09-30  20:26:02 DEBUG    lib.model.sdp.commands matched reply_pattern PW(ON|STANDBY) as regex against data PWON, found command general.power
2024-09-30  20:26:02 DEBUG    lib.model.sdp.command parse_str command got data PWON of type <class 'str'>
2024-09-30  20:26:02 DEBUG    plugins.denon       received data "PWON" for command general.power converted to value True
2024-09-30  20:26:02 DEBUG    plugins.denon       Command general.power wants to update item R16.STECKDOSE.MARANTZ.general.power with value True received from denon
2024-09-30  20:26:02 DEBUG    plugins.denon       Update_item was called with item "R16.STECKDOSE.MARANTZ.general.power" from caller denon, source None and dest None
2024-09-30  20:26:02 DEBUG    plugins.denon       Command general.power wants to update item R16.MARANTZ.general.power with value True received from denon
2024-09-30  20:26:02 DEBUG    plugins.denon       Update_item was called with item "R16.MARANTZ.general.power" from caller denon, source None and dest None
2024-09-30  20:26:08 DEBUG    lib.model.sdp.connection received raw data "SSINFAISSIG 02" from "denon"
2024-09-30  20:26:08 DEBUG    plugins.denon       received data "SSINFAISSIG 02" from denon without command specification
2024-09-30  20:26:08 DEBUG    lib.model.sdp.commands matched reply_pattern SSINFAISSIG (01|02|03|04|05|06|07|08|09|10|11|12|13|14|15|16|17|18) as regex against data SSINFAISSIG 02, found command general.inputsignal
2024-09-30  20:26:08 DEBUG    lib.model.sdp.command parse_str command got data SSINFAISSIG 02 of type <class 'str'>
2024-09-30  20:26:08 DEBUG    plugins.denon       received data "SSINFAISSIG 02" for command general.inputsignal converted to value PCM
2024-09-30  20:26:08 DEBUG    plugins.denon       Command general.inputsignal wants to update item R16.STECKDOSE.MARANTZ.general.inputsignal with value PCM received from denon
2024-09-30  20:26:08 DEBUG    plugins.denon       Command general.inputsignal wants to update item R16.MARANTZ.general.inputsignal with value PCM received from denon
2024-09-30  20:26:08 DEBUG    lib.model.sdp.connection received raw data "SSINFAISFSV 48K" from "denon"
2024-09-30  20:26:08 DEBUG    plugins.denon       received data "SSINFAISFSV 48K" from denon without command specification
2024-09-30  20:26:08 DEBUG    lib.model.sdp.commands matched reply_pattern SSINFAISFSV (\d{2,3}|NON) as regex against data SSINFAISFSV 48K, found command general.inputrate
2024-09-30  20:26:08 DEBUG    lib.model.sdp.command parse_str command got data SSINFAISFSV 48K of type <class 'str'>
2024-09-30  20:26:08 DEBUG    plugins.denon       received data "SSINFAISFSV 48K" for command general.inputrate converted to value 48
2024-09-30  20:26:08 DEBUG    plugins.denon       Command general.inputrate wants to update item R16.STECKDOSE.MARANTZ.general.inputrate with value 48 received from denon
2024-09-30  20:26:08 DEBUG    plugins.denon       Command general.inputrate wants to update item R16.MARANTZ.general.inputrate with value 48 received from denon
2024-09-30  20:26:10 DEBUG    lib.model.sdp.connection received raw data "PWON" from "denon"
2024-09-30  20:26:10 DEBUG    plugins.denon       received data "PWON" from denon without command specification
2024-09-30  20:26:10 DEBUG    lib.model.sdp.commands matched reply_pattern PW(ON|STANDBY) as regex against data PWON, found command general.power
2024-09-30  20:26:10 DEBUG    lib.model.sdp.command parse_str command got data PWON of type <class 'str'>
2024-09-30  20:26:10 DEBUG    plugins.denon       received data "PWON" for command general.power converted to value True
2024-09-30  20:26:10 DEBUG    plugins.denon       Command general.power wants to update item R16.STECKDOSE.MARANTZ.general.power with value True received from denon
2024-09-30  20:26:10 DEBUG    plugins.denon       Command general.power wants to update item R16.MARANTZ.general.power with value True received from denon
2024-09-30  20:26:40 DEBUG    plugins.denon       Update_item was called with item "R16.MARANTZ.zone1.control.power" from caller smartVISU, source 192.168.123.17 and dest None
2024-09-30  20:26:40 INFO     plugins.denon       Update item: R16.MARANTZ.zone1.control.power: item has been changed outside this plugin
2024-09-30  20:26:40 DEBUG    plugins.denon       Writing value "False" from item R16.MARANTZ.zone1.control.power with command "zone1.control.power"
2024-09-30  20:26:40 DEBUG    plugins.denon       command zone1.control.power with value False yielded send data_dict {'payload': 'ZMOFF\r', 'data': 'OFF', 'limit_response': b'\r'}
2024-09-30  20:26:40 DEBUG    lib.model.sdp.connection received raw data "PWSTANDBY" from "denon"
2024-09-30  20:26:40 DEBUG    plugins.denon       received data "PWSTANDBY" from denon without command specification
2024-09-30  20:26:40 DEBUG    lib.model.sdp.commands matched reply_pattern PW(ON|STANDBY) as regex against data PWSTANDBY, found command general.power
2024-09-30  20:26:40 DEBUG    lib.model.sdp.command parse_str command got data PWSTANDBY of type <class 'str'>
2024-09-30  20:26:40 DEBUG    plugins.denon       received data "PWSTANDBY" for command general.power converted to value False
2024-09-30  20:26:40 DEBUG    plugins.denon       Command general.power wants to update item R16.STECKDOSE.MARANTZ.general.power with value False received from denon
2024-09-30  20:26:40 DEBUG    plugins.denon       Update_item was called with item "R16.STECKDOSE.MARANTZ.general.power" from caller denon, source None and dest None
2024-09-30  20:26:40 DEBUG    plugins.denon       Command general.power wants to update item R16.MARANTZ.general.power with value False received from denon
2024-09-30  20:26:40 DEBUG    plugins.denon       Update_item was called with item "R16.MARANTZ.general.power" from caller denon, source None and dest None
2024-09-30  20:26:40 DEBUG    lib.model.sdp.connection received raw data "ZMOFF" from "denon"
2024-09-30  20:26:40 DEBUG    plugins.denon       received data "ZMOFF" from denon without command specification
2024-09-30  20:26:40 DEBUG    lib.model.sdp.commands matched reply_pattern ZM(ON|OFF) as regex against data ZMOFF, found command zone1.control.power
2024-09-30  20:26:40 DEBUG    lib.model.sdp.command parse_str command got data ZMOFF of type <class 'str'>
2024-09-30  20:26:40 DEBUG    plugins.denon       received data "ZMOFF" for command zone1.control.power converted to value False
2024-09-30  20:26:40 DEBUG    plugins.denon       Command zone1.control.power wants to update item R16.STECKDOSE.MARANTZ.zone1.control.power with value False received from denon
2024-09-30  20:26:40 DEBUG    plugins.denon       Update_item was called with item "R16.STECKDOSE.MARANTZ.zone1.control.power" from caller denon, source None and dest None
2024-09-30  20:26:40 DEBUG    plugins.denon       Command zone1.control.power wants to update item R16.MARANTZ.zone1.control.power with value False received from denon
2024-09-30  20:27:12 DEBUG    plugins.denon       Update_item was called with item "Rxx Denon Plugin suspendieren / fortfuehren" from caller smartVISU, source 192.168.123.17 and dest None
2024-09-30  20:27:12 DEBUG    plugins.denon       Suspend item changed to True
2024-09-30  20:27:12 DEBUG    plugins.denon       Suspend mode enabled (set by suspend item SONDERFUNKTIONEN.PLUGINS.SUSPEND_DENON)
2024-09-30  20:27:12 INFO     plugins.denon       plugin suspended by suspend item SONDERFUNKTIONEN.PLUGINS.SUSPEND_DENON, connections will be closed
2024-09-30  20:27:12 DEBUG    plugins.denon       Update_item was called with item "Rxx Denon Plugin suspendieren / fortfuehren" from caller denon, source None and dest None
2024-09-30  20:27:12 DEBUG    lib.model.sdp.connection close method called for connection
2024-09-30  20:27:12 DEBUG    lib.model.sdp.connection SDPConnectionNetTcpClient closing connection
2024-09-30  20:27:12 DEBUG    plugins.denon       scheduler_get: name = plugins.denon.denon_cyclic
2024-09-30  20:27:24 DEBUG    plugins.denon       Update_item was called with item "R16.MARANTZ.zone1.control.power" from caller smartVISU, source 192.168.123.17 and dest None
2024-09-30  20:27:24 INFO     plugins.denon       Update item: R16.MARANTZ.zone1.control.power: item has been changed outside this plugin
2024-09-30  20:27:24 DEBUG    plugins.denon       Writing value "True" from item R16.MARANTZ.zone1.control.power with command "zone1.control.power"
2024-09-30  20:27:24 WARNING  plugins.denon       trying to send command zone1.control.power with value True, but plugin is suspended.
2024-09-30  20:27:24 DEBUG    plugins.denon       Writing value "True" from item R16.MARANTZ.zone1.control.power with command "zone1.control.power" failed, resetting item value
2024-09-30  20:27:24 DEBUG    plugins.denon       Update_item was called with item "R16.MARANTZ.zone1.control.power" from caller denon, source None and dest None
2024-09-30  20:27:52 DEBUG    plugins.denon       Update_item was called with item "Rxx Denon Plugin suspendieren / fortfuehren" from caller smartVISU, source 192.168.123.17 and dest None
2024-09-30  20:27:52 DEBUG    plugins.denon       Suspend item changed to False
2024-09-30  20:27:52 DEBUG    plugins.denon       Suspend mode disabled (set by suspend item SONDERFUNKTIONEN.PLUGINS.SUSPEND_DENON)
2024-09-30  20:27:52 INFO     plugins.denon       plugin resumed by suspend item SONDERFUNKTIONEN.PLUGINS.SUSPEND_DENON, connections will be resumed
2024-09-30  20:27:52 DEBUG    plugins.denon       Update_item was called with item "Rxx Denon Plugin suspendieren / fortfuehren" from caller denon, source None and dest None
2024-09-30  20:27:52 DEBUG    lib.model.sdp.connection open method called for connection
2024-09-30  20:27:52 DEBUG    lib.model.sdp.connection SDPConnectionNetTcpClient opening connection with params {'serialport': '', 'baudrate': 9600.0, 'bytesize': 8.0, 'parity': 'N', 'stopbits': 1.0, 'protocol': None, 'host': '192.168.123.26', 'port': 23, 'binary': False, 'timeout': 3.0, 'autoreconnect': True, 'autoconnect': True, 'connect_retries': 5.0, 'connect_cycle': 3.0, 'retry_cycle': 30.0, 'retry_suspend': 3.0, 'terminator': b'\r', 'connected_callback': None, 'disconnected_callback': None, 'suspend_callback': <bound method SmartDevicePlugin.set_suspend of <plugins.denon.denon object at 0x7f9ade8ffb50>>, 'done': False, 'model': 'AVR-X3300W', 'conn_type': 'net_tcp_client', 'command_class': 'SDPCommandParseStr', 'suspend_item': 'SONDERFUNKTIONEN.PLUGINS.SUSPEND_DENON', 'webif_pagelength': 0, 'plugin_path': 'plugins.denon', 'custom_patterns': {1: '', 2: '', 3: ''}}
2024-09-30  20:27:52 WARNING  lib.network         (denon_192.168.123.26:23) TCP connection failed 1/5 times, last error was: [Errno 111] Verbindungsaufbau abgelehnt
2024-09-30  20:27:52 WARNING  lib.network         self._connect() for denon did not work
2024-09-30  20:27:55 INFO     lib.model.sdp.connection on_connect called by denon
2024-09-30  20:28:04 NOTICE   modules.admin.loggers Logger 'plugins.denon' changed from DEBUG to NOTICE
2024-09-30  20:28:13 NOTICE   modules.admin.loggers Logger 'lib.model.sdp' changed from DEBUG to NOTICE​

Nun muss ich mal sehen, wenn das Plugin selbständig auf Suspend geht, da es den Verstärker nicht mehr erreicht, ob das Item dann auch selbständig auf True geht und ich es auf False setzen kann und alles wieder geht. Alternativ würde ich es dann einmal toggeln.

Sobald ich das weiss gebe ich nochmal Rückmeldung. Wird wohl morgen werden.
Aber vielen Lieben Dank schonmal für euren Support.

[Morg]

Das Plugin sollte (nur) automatisch (also von sich aus) auf suspend gehen, wenn die Verbindung gem. Parametern mehrfach fehlschlägt (z.B., wenn der Receiver keinen Strom hat). Dann wird auch das Item entsprechend gesetzt. Ich kann aber nicht sicher sagen, wie gut die "disconnect"-Erkennung in dem Fall funktioniert. In dem Fall würde dann auch "auf False setzen" nicht helfen, weil der Verstärker ja nicht erreichbar ist.

Wann geht es denn automatisch auf suspend?

[loeserman]

Es geht auf suspend, wenn der Verstärker stromlos ist und damit mehrere Versuche ihn zu erreichen fehlschlägt. Das ist ja auch verständlich und sinnvoll. Das item selbst wird allerdings nicht auf TRUE gesetzt sondern bleibt False. Natürlich würde ein Erneutes Setzen auf False nichts bringen, wenn der Verstärker aus ist.

Aber wenn der Verstärker an ist dann hilft ein Toggeln (-->True-->False) und dies schaltet das Plugin wieder ein und ich kann wieder den Verstärker bedienen. Klasse. Das kann ich nun in meine Funktion mit einbauen. Ich habe ein Skript, welches den Verstärker einschaltet (Strom an) und wenn ich dann das Plugin dann aus dem Suspend aufwecke können auch die Befehle wieder ausgeführt werden.

Schöner wäre es natürlich wenn man noch abfragen kann, ob das Plugin im Suspend ist. Ansonsten brauche ich das Toggeln ja nicht. Allerdings geht das nicht über das Item. Aber vielleicht ist das ja in dem DEVLOP Branch auch anders, da dieser Teil ja komplett überarbeitet wurde.

[Morg]

Das Item sollte automatisch auf True gehen, wenn standby aktiviert wird. Es ist als Schalt- und als Statusitem konzipiert. Woran siehst du, dass es das nicht tut?

Erneutes Setzen auf False sollte funktionieren; das Item muss mit enforce_updates: true erstellt werden.

[loeserman]

Naja ich erkenne es daran, dass nach längerer Zeit in dem der Verstärker aus ist und ich ihn dann wieder einschalte die Bedienung nicht geht (Fehlermeldung im Logging, dass das Plugin suspendiert ist). Das item habe ich ebenfalls in der VISU dargestellt und dort ist dann 0. Auch ist es mit enforce_update=true definiert. Wenn ich es dann über die VISU ein und aus schalte kann ich anschließend den Verstärker wieder bedienen.

Der code in den beiden Zeilen sieht folgendermaßen aus. Ich hoffe das ist nicht falsch. Oben ist es anders herum geschrieben aber im Code stand vorher an den beiden Stellen auch true und false und ich habe das dann so belassen.

    def suspend(self, by=None):
        """
        sets plugin into suspended mode, no network/serial activity and no item changed
        """
        if self.alive:
            self.logger.info(f'plugin suspended by {by if by else "unknown"}, connections will be closed')
            self.suspended = True
            if self._suspend_item is not None:
                self._suspend_item(True, self.get_fullname()) # ##### LOESER ##### vorher: self._suspend_item(True)
            if hasattr(self, 'disconnect'):
                self.disconnect()

    def resume(self, by=None):
        """
        disabled suspended mode, network/serial connections are resumed
        """
        if self.alive:
            self.logger.info(f'plugin resumed by {by if by else "unknown"}, connections will be resumed')
            self.suspended = False
            if self._suspend_item is not None:
                self._suspend_item(False, self.get_fullname()) # ##### LOESER ##### vorher: self._suspend_item(False)
            if hasattr(self, 'connect'):
                self.connect()

[Morg]

Ah, Moment...

Verstärker einschalten hat ja erstmal nix mit dem Suspend-Item zu tun...? Oder wieso sollte das Plugin "von alleine" aus dem Suspend rauskommen?

Der Code sieht richtig aus; wenn das Plugin in suspend geht, wird das suspend_item auf True (=suspended) gesetzt; bei resume auf False (=aktiv). Das sollte soweit passen. Bei anderen Plugins funktioniert das (hier) auch.

Wie schaltest du den Verstärker denn ein? Du müsstest dann dabei / zusätzlich das Suspend-Item auf False setzen, dann sollte das Plugin auch wieder aufwachen. In der Visu ist das etwas schwierig, wenn der Status nicht richtig angezeigt wird. Was sagt im suspended-Zustand die Admin-UI?