Neues Plugin: AV Device (für Yamaha, Pioneer, Denon, etc.)

[Onkelandy]

Hallo zusammen!

Ich habe in den letzten Monaten ein Plugin zur Ansteuerung von AV Geräten gebastelt, das sich auch versichert, dass der korrekte Wert beim Device angekommen ist (durch Abgleich mit der Antwort seitens des Geräts).
Die Kommunikation findet wahlweise über TCP (Telnet) oder RS232 statt. Einige bestehende Plugins basieren ja auf dem Web-Interface der Geräte, das ist hier nicht implementiert und soweit auch nicht angedacht.

Das Plugin wäre so konzeptioniert, dass es mit unterschiedlichsten Geräten funktionieren sollte. Dazu gibt es ein Konfigurationsfile im Plugin Ordner, das jeder nach Belieben aufsetzen kann. Ob das nun wirklich auch mit anderen Geräten funktioniert, kann ich nicht garantieren, aber vielleicht bekommen wir das ja hin. Mit Pioneer funktioniert's soweit top, meinen Epson Beamer kann ich auch problemlos einbinden.

Aktueller Stand:
Pioneer - läuft
Epson - läuft
Denon - nur rudimentär und mit etlichen Problemen noch.. ist in Bearbeitung

Schaut es euch doch mal an:

https://github.com/onkelandy/plugins...evice/avdevice

Probleme bitte dort unter Issues posten. Schön wäre, wenn ihr dort auch fertige Config-Files eurer Geräte posten könntet, dann kann ich das für die Allgemeinheit einbinden.

Fragen zum Plugin einfach hier. Der Code ist inzwischen leider ein Drama geworden, hab da ständige Ausbesserungen und Fixes gemacht, sodass es recht unübersichtlich geworden ist. Das wird jetzt aber vorerst wohl mal so bleiben..

[Sandman60]

Cool, danke! Dann werde ich mal bei Gelegenheit meinen alten Yamaha RX-V2700 via RS232 anbinden. Muß nur mal schauen wie ich RS232 an den PI bekomme, aber da hab ich noch was in der Krabbelbox (RS232>CAT5e>USB)... Melde mich dann wieder. Ach so... Da ich mir vor Jahren mal die Zähne an einer stabilen RS232-Verbindung ausgebissen habe... Hast Du das schon bei Dir im Einsatz?

[Onkelandy]

Bei meinem Hauptgerät habe ich nur RS232 im Einsatz, da man sonst nach dem Einschalten der Steckdose eben 40 Sekunden warten muss, bis man ihn ansteuern kann. Das geht natürlich gar nicht. Insofern nutze ich schon von Beginn an den seriellen Port über einen USB-Serial Hub mit 4 Anschlüssen. Keinerlei Probleme.

Generell ist es etwas mühsam, abzufangen ob eine Verbindung besteht oder nicht, sofern man nicht ständig Daten austauscht. Aber ich behaupte mal, dass das Plugin das alles soweit recht gut abfängt.

[Sandman60]

Klasse, danke für die schnelle Rückmeldung. Schiebe das Thema Anbindung und Testen mal nach oben in meiner Prioliste und melde mich wieder.

[psilo]

hat das plugin inzwischen einer getestet? bei mir hagelt es gleich am anfang schon fehler, wie:

017-07-15  20:48:39 ERROR    avdevice-tcp-reconnect_denon Method avdevice-tcp-reconnect_denon exception: 'bool' object has no attribute 'lower'            

Traceback (most recent call last):                                                                                                                          

  File "/usr/local/smarthome/lib/scheduler.py", line 403, in _task                                                                                          

    obj()                                                                                                                                                  

  File "/usr/local/smarthome/plugins/avdevice/__init__.py", line 936, in connect_tcp                                                                        

    if ('TCP' not in self._is_connected and self._tcp is not None) and self._auto_reconnect.lower() in ['1', 'yes', 'true', 'on']:                          

AttributeError: 'bool' object has no attribute 'lower'

Offenbar hat der Code probleme wenn autoreconnect als Default mit einem "echten boolschen" False greift..

[Onkelandy]

Leider ist das Echo bis dato sehr gering..
Foxi352 wär noch am Testen dran, hab aber auch keine aktuelle Reaktion. Obiger Fehler ließe sich wohl einfach durch ein str() beheben. Welche Fehlermeldungen hast du noch? Wie ich sehe, benutzt du einen Denon? Habe leider rausfinden müssen, dass die Geräte doch ganz anders ticken als Pioneer und Epson. Hier muss ich noch massive Codeänderungen machen.

Ich habe das inzwischen so angepasst, dass zumindest boolsche Kommandos ausgeführt werden können, also Power, Mute, etc.
Angabe von Volume und Source muss ich für Denon noch implementieren, für Pioneer läuft das alles seit Monaten stabil.

Habe gerade nen Pull Request erstellt.

[psilo]

Onkelandy ok dann wundert mich nicht, dass die befehle mit denen ich experimentiert habe nicht gegangen sind. sonst gab es keine fehlermeldungen, ich hatte das autoreconnect dann in der plugin.yaml gesetzt und es war weg.. fehler sollte imho trotzdem nicht kommen, da es ja den default gibt

[Foxi352]

Leider ist das Echo bis dato sehr gering..
Foxi352 wär noch am Testen dran, hab aber auch keine aktuelle Reaktion.

Das stimmt so nicht ganz :-) Habe dir gestern per PM in Gitter Feedback gegeben. Ich wer das aber in Zukunft in diesem Thread machen ....

[psilo]

Onkelandy also jetzt reagiert der denon schon mal.. allerdings kriege ich nen haufen timeouts.

[Foxi352]

Ich paste die PM dann nochmals hier, so haben wir eine gemeinsame Diskussion. Mein Problem ist, dass die Kommandos sich in der Liste aufstauen aber nie entfernt werden. Hier ein Beispiel mit MUTE. Ich bin mit TCP Verbunden.

In der VISU setze ich Mute auf True:

2017-07-15 21:03:16 DEBUG item Main Item avr.mute = True via Visu 192.168.1.80:51568 None -- item.py:update:707
2017-07-15 21:03:16 DEBUG init Main Updating Item for avdevice_: Starting to update item avr.mute. Lock is: True. Reconnectrigger is True -- init.py:update_item:1475
2017-07-15 21:03:16 DEBUG init Main Updating Item for avdevice_: Trying to connect while updating item -- init.py:update_item:1478
2017-07-15 21:03:16 DEBUG init Main Connecting : Starting to connect. Current Connections: ['TCP'] -- init.py:connect:921
2017-07-15 21:03:16 DEBUG init Main Connecting : Depending is false. Message: 'NoneType' object is not callable -- init.py:connect:934
2017-07-15 21:03:16 DEBUG init Main Updating Item for avdevice_: Visu trying to update avr.mute -- init.py:update_item:1483
2017-07-15 21:03:16 DEBUG init Main Updating Item for avdevice_: Command mute is a standard command. Message: 'mute' -- init.py:update_item:1579
2017-07-15 21:03:16 DEBUG init Main Updating Item for avdevice_: Visu set mute to True for avr.mute in zone 1 -- init.py:update_item:1583
2017-07-15 21:03:16 DEBUG init Main Updating Item for avdevice_: Update Zone 1 Command On MUON for avr.mute -- init.py:update_item:1617
2017-07-15 21:03:16 DEBUG init Main Updating Item for avdevice_: Updating item. [B]Command list is ['MUON,MU?,MU1']. [/B]Sendingcommand: MUON,MU?,MU1. Lock is released. Now it is False -- init.py:update_item:1740
2017-07-15 21:03:16 DEBUG init Main Sending : Starting to send command MUON from list ['MUON,MU?,MU1']. Caller: updateitem. Lock is: True -- init.py:_send:1794
2017-07-15 21:03:16 DEBUG init Main Sending : Trying to connect while sending command -- init.py:_send:1822
2017-07-15 21:03:16 DEBUG init Main Connecting : Starting to connect. Current Connections: ['TCP'] -- init.py:connect:921
2017-07-15 21:03:16 DEBUG init Main Connecting : Depending is false. Message: 'NoneType' object is not callable -- init.py:connect:934
2017-07-15 21:03:16 DEBUG init Main Sending TCP : command was sent MUON from Multicommand-List ['MUON']. Returns 5 -- init.py:_send:1840
2017-07-15 21:03:16 DEBUG init Main Updating Item for avdevice_: Updating item. Command list is ['MUON,MU?,MU1']. Return from send is 5. Lock is released. Now it is False -- init__.py:update_item:1748

Funktioniert 1A. Dann setze ich Mute wieder auf False:

2017-07-15 21:03:19 DEBUG item Main Item avr.mute = False via Visu 192.168.1.80:51568 None -- item.py:update:707
2017-07-15 21:03:19 DEBUG init Main Updating Item for avdevice_: Starting to update item avr.mute. Lock is: True. Reconnectrigger is True -- init.py:update_item:1475
2017-07-15 21:03:19 DEBUG init Main Updating Item for avdevice_: Trying to connect while updating item -- init.py:update_item:1478
2017-07-15 21:03:19 DEBUG init Main Connecting : Starting to connect. Current Connections: ['TCP'] -- init.py:connect:921
2017-07-15 21:03:19 DEBUG init Main Connecting : Depending is false. Message: 'NoneType' object is not callable -- init.py:connect:934
2017-07-15 21:03:19 DEBUG init Main Updating Item for avdevice_: Visu trying to update avr.mute -- init.py:update_item:1483
2017-07-15 21:03:19 DEBUG init Main Updating Item for avdevice_: Command mute is a standard command. Message: 'mute' -- init.py:update_item:1579
2017-07-15 21:03:19 DEBUG init Main Updating Item for avdevice_: Visu set mute to False for avr.mute in zone 1 -- init.py:update_item:1583
2017-07-15 21:03:19 DEBUG init Main Updating Item for avdevice_: Update Zone 1 Command Off MUOFF for avr.mute -- init.py:update_item:1648
2017-07-15 21:03:19 DEBUG init Main Updating Item for avdevice_: Updating item. [B]Command list is ['MUON,MU?,MU1', 'MUOFF,MU?,MU0'].[/B] Sendingcommand: MUON,MU?,MU1. Lock is released. Now it is False --init.py:update_item:1740
2017-07-15 21:03:19 DEBUG init Main Sending : Starting to send command MUON from list ['MUON,MU?,MU1', 'MUOFF,MU?,MU0']. Caller: updateitem. Lock is: True -- init.py:_send:1794
2017-07-15 21:03:19 DEBUG init Main Sending : Trying to connect while sending command -- init.py:_send:1822
2017-07-15 21:03:19 DEBUG init Main Connecting : Starting to connect. Current Connections: ['TCP'] -- init.py:connect:921
2017-07-15 21:03:19 DEBUG init Main Connecting : Depending is false. Message: 'NoneType' object is not callable -- init.py:connect:934
2017-07-15 21:03:19 DEBUG init Main Sending TCP : command was sent MUON from Multicommand-List ['MUON']. Returns 5 -- init.py:_send:1840
2017-07-15 21:03:19 DEBUG init Main Updating Item for avdevice_: Updating item. Command list is ['MUON,MU?,MU1', 'MUOFF,MU?,MU0']. Return from send is 5. Lock is released. Now it is False -- init__.py:update_item:1748

Das MUON ist immer noch in der Liste, und wenn wird, egal was ich hinterher schiebe, immer wieder ausgeführt. Die anderen Kommandos stauen sich in der Liste on, werden aber nie ausgeführt. Ich kann dann auch noch 5 mal das Mute Item in SV triggern, die Liste mit MUON, MUOFF,MUON,MUOFF u.s.w. wird immer länger. Will heissen nach einem SHNG restart kann ich 1 Mute Kommando korrekt schicken, danach nichts mehr weil sich einfach die Liste immer nur erweitert.

[psilo]

Bei mir: 1x PWON geht, danach schiesst es mir aber das log mit sowas voll:

16.07.2017 13:34:36

Processing Response denon: Connection error. Error: timed out Resend Counter: 2. Resend Max: 10

16.07.2017 13:34:30

Processing Response denon: Problems buffering TCP response. Error: timed out. Increasing timeout temporarily.

Danach geht augenscheinlich nichts mehr

[Onkelandy]

Kleines Update im Anhang. Das mit den Timeouts ist auch komisch.. bei Foxi funzt die Response auch gar nicht.. kommt nicht mal was im Log. Könnt ihr beide mir hier eure kompletten Debug Logs vom Plugin posten?

Korrekterweise sollte das Log so aussehen.. Theoretisch auch ohne Timeout, aber gerade beim ersten Mal gibt es wohl immer wieder mal Verbindungsprobleme..

2017-07-16  19:46:36 DEBUG    Main         Updating Item for avdevice_wz: Command power is a standard command. Message: 'power'
2017-07-16  19:46:36 DEBUG    Main         Updating Item for avdevice_wz: CLI set power to True for Musik.OG.Denon.Power in zone 1
2017-07-16  19:46:36 DEBUG    Main         Updating Item for avdevice_wz: Update Zone 1 Command On ZMON for Musik.OG.Denon.Power
2017-07-16  19:46:36 DEBUG    Main         Updating Item for avdevice_wz: Command Power On for zone: 1. Appending relevant query commands: ['MV?,MV?,MV', 'MU?,MU?,MU', 'ZM?,ZM?,ZM']
2017-07-16  19:46:36 DEBUG    Main         Updating Item for avdevice_wz: Updating item. Command list is ['ZMON,ZM?,ZM1', 'MV?,MV?,MV', 'MU?,MU?,MU', 'ZM?,ZM?,ZM']. Sendingcommand: ZMON,ZM?,ZM1. Lock is released. Now it is False
2017-07-16  19:46:36 DEBUG    Main         Sending WZ: Starting to send command ZMON from list ['ZMON,ZM?,ZM1', 'MV?,MV?,MV', 'MU?,MU?,MU', 'ZM?,ZM?,ZM']. Caller: updateitem. Lock is: True
2017-07-16  19:46:36 DEBUG    Main         Sending WZ: Trying to connect while sending command
2017-07-16  19:46:36 DEBUG    Main         Connecting WZ: Starting to connect. Current Connections: ['TCP']
2017-07-16  19:46:36 DEBUG    Main         Connecting WZ: Depending is false. Message: 'NoneType' object is not callable
2017-07-16  19:46:36 DEBUG    Main         Sending TCP WZ: command was sent ZMON from Multicommand-List ['ZMON']. Returns 5
2017-07-16  19:46:36 DEBUG    Main         Updating Item for avdevice_wz: Updating item. Command list is ['ZMON,ZM?,ZM1', 'MV?,MV?,MV', 'MU?,MU?,MU', 'ZM?,ZM?,ZM']. Return from send is 5. Lock is released. Now it is False
2017-07-16  19:46:36 DEBUG    avdevice-tcp-reconnect_WZ Processing Response WZ: Error reading.. Error: timed out. Sending Command: ZMON,ZM?,ZM1. RS232: None, Host: 10.0.0.130, Socket: <socket.socket fd=18, family=AddressFamily.AF_INET, type=2049, proto=0, laddr=('10.0.0.152', 54196), raddr=('10.0.0.130', 23)>
2017-07-16  19:46:36 WARNING  avdevice-tcp-reconnect_WZ Processing Response WZ: Problems buffering TCP response. Error: timed out. Increasing timeout temporarily.
2017-07-16  19:46:37 DEBUG    avdevice-tcp-reconnect_WZ Sending WZ: Starting to send Resendcommand ZMON,ZM?,ZM1 from list ['ZMON,ZM?,ZM1', 'MV?,MV?,MV', 'MU?,MU?,MU', 'ZM?,ZM?,ZM']. Caller: getresponse. Lock is: True
2017-07-16  19:46:37 DEBUG    avdevice-tcp-reconnect_WZ Sending WZ: Trying to connect while sending command
2017-07-16  19:46:37 DEBUG    avdevice-tcp-reconnect_WZ Connecting WZ: Starting to connect. Current Connections: ['TCP']
2017-07-16  19:46:37 DEBUG    avdevice-tcp-reconnect_WZ Connecting WZ: Depending is false. Message: 'NoneType' object is not callable
2017-07-16  19:46:37 DEBUG    avdevice-tcp-reconnect_WZ Sending TCP WZ: Resendcommand was sent ZMON,ZM?,ZM1 from Multicommand-List ['ZMON,ZM?,ZM1']. Returns 13
2017-07-16  19:46:37 DEBUG    avdevice-tcp-reconnect_WZ Processing Response WZ: Error reading.. Return from send is 13. Error: timed out
2017-07-16  19:46:41 ERROR    avdevice-tcp-reconnect_WZ Processing Response WZ: Connection error. Error: timed out Resend Counter: 0. Resend Max: 10
2017-07-16  19:46:41 DEBUG    avdevice-tcp-reconnect_WZ Parsing Input WZ: Response: ERROR.
2017-07-16  19:46:41 DEBUG    avdevice-tcp-reconnect_WZ Parsing Input WZ: Parsing input while waiting for response. Lock is: True
2017-07-16  19:46:41 DEBUG    avdevice-tcp-reconnect_WZ Parsing Input WZ: Expected response while parsing: ['ZM1', 'MV', 'MU', 'ZM'].
2017-07-16  19:46:41 DEBUG    avdevice-tcp-reconnect_WZ Parsing Input WZ: Depending is false. Message 'NoneType' object is not callable.
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Parsing Input WZ: Requesting query from ZMON,ZM?,ZM1 because response was ERROR. Requery Counter: 1
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Parsing Input WZ: Newly sorted send commands at end of parsing: ['ZMON,ZM?,ZM1', 'MV?,MV?,MV', 'MU?,MU?,MU', 'ZM?,ZM?,ZM']
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Sending WZ: Starting to send query ZM? from list ['ZMON,ZM?,ZM1', 'MV?,MV?,MV', 'MU?,MU?,MU', 'ZM?,ZM?,ZM']. Caller: parseinput_final. Lock is: True
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Sending WZ: Trying to connect while sending command
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Connecting WZ: Starting to connect. Current Connections: ['TCP']
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Connecting WZ: Depending is false. Message: 'NoneType' object is not callable
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Sending TCP WZ: query was sent ZM? from Multicommand-List ['ZM?']. Returns 4
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Parsing Input WZ: Sending again because list is not empty yet. Sending return is 4. Lock is released. Now it is False.
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Parsing Input WZ: Response: ZMON.
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Parsing Input WZ: Parsing input while waiting for response. Lock is: True
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Parsing Input WZ: Expected response while parsing: ['ZM1', 'MV', 'MU', 'ZM'].
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Storing Values WZ: Starting to store value in dictionary. Lock is: True.
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Storing Values WZ: Limiting bool value for received data.
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Storing Values WZ: Found writeable dict key: ZM. Zone: zone1. Value: 1. Function: power.
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Storing Values WZ: Finished. Lock is: False.
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Parsing Input WZ: got entry {'Item': [Item: Musik.OG.Denon.Power], 'Value': '1'}. Value: 1
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Parsing Input WZ: FOUND ['ZM1']. Written to dict: {'Item': [Item: Musik.OG.Denon.Power], 'Value': '1'}
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Storing Values WZ: Starting to store value in dictionary. Lock is: True.
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Storing Values WZ: Limiting bool value for received data.
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Storing Values WZ: Found writeable dict key: ZM. Zone: zone1. Value: 1. Function: power.
2017-07-16  19:46:43 DEBUG    avdevice-tcp-reconnect_WZ Storing Values WZ: Finished. Lock is: False.

Mein plugin.yaml sieht so aus:

denon_og:
    class_name: AVDevice
    class_path: plugins.avdevice
    tcp: 10.0.0.130, 23
    #rs232: /dev/ttyUSB1, 9600, 0.1, 0.2
    model: denon-avr6300
    #manufacturer: denon
    instance: WZ
    ignoreresponse: RGB, RGC, RGD, GBH, GHH, LM0, VTA, AUA, AUB
    #errorresponse: E02, E04, E06
    autoreconnect: false
    reconnectcycle: 10
    sendretries: 10
    resendwait: 1.0
    resetonerror: True
    secondstokeep: 50
    dependson: steckdosen.og.wohnen_kino.SA, True
    depend0_power0: True
    depend0_volume0: True
    responsebuffer: -5

Habs' auch ohne Instance getestet, klappt bei mir auch. Eventuell spielt das Dependson einen Streich, aber dann würde eigtl. auch gar keinen Command senden.

[Foxi352]

Hier jetzt mal ein komplette logging von Anfang an:

1. Smarthome restarted
2. Mute ON in SV (hat funktioniert)
3. Mute OFF in SV (hat nicht mehr funktioniert)
4. Mute ON in SV (nicht funktioniert)
5. Mute OFF in SV (nicht funktionert)

Das war allerdings ohne das plugin.yaml anzupassen. Plugin.yaml ist folgendermassen:

denon:
    class_name: AVDevice
    class_path: plugins.avdevice
    model: avr-1912
    tcp: 192.168.2.52, 23

Hier das Log:

2017-07-16 19:53:54 DEBUG    __init__     Main         Initializing Serial : Serialport is None. -- __init__.py:__init__:78

2017-07-16 19:53:54 DEBUG    __init__     Main         Initializing TCP : IP is 192.168.2.52. -- __init__.py:__init__:106

2017-07-16 19:53:54 DEBUG    __init__     Main         Initializing TCP : Port is 23. -- __init__.py:__init__:113

2017-07-16 19:53:54 DEBUG    __init__     Main         Initializing : Dependson Item: None. No value for item given, assuming True. -- __init__.py:__init__:162

2017-07-16 19:53:54 DEBUG    __init__     Main         Initializing : Special Settings: Ignoring responses ['']. -- __init__.py:__init__:196

2017-07-16 19:53:54 DEBUG    __init__     Main         Initializing : Special Settings: Error responses ['E02', 'E04', 'E06']. -- __init__.py:__init__:197

2017-07-16 19:53:54 DEBUG    __init__     Main         Initializing : Special Settings: Force buffer ['']. -- __init__.py:__init__:198

2017-07-16 19:53:54 DEBUG    __init__     Main         Initializing : Special Settings: Ignore Display [''] -- __init__.py:__init__:199

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Dependson Item: None. -- __init__.py:run:899

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Running. Lock is True -- __init__.py:run:904

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Items: {'zone0': {'power': {'Item': [Item: avr.power], 'Value': False}}, 'zone2': {}, 'zone4': {}, 'zone1': {'volume-': {'Item': [Item: avr.volumeDown], 'Value': False}, 'mute': {'Item': [Item: avr.mute], 'Value': False}, 'volume+': {'Item': [Item: avr.volumeUp], 'Value': False}, 'volume': {'Item': [Item: avr.volume], 'Value': 0}}, 'zone3': {}} -- __init__.py:run:906

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Speaker Items: {'zone1': {}, 'zone2': {}, 'zone3': {}} -- __init__.py:run:907

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Running. Lock is released. Now it is False -- __init__.py:run:914

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Starting to read file for model avr-1912. Lock is True -- __init__.py:_read_commandfile:388

2017-07-16 19:53:55 WARNING  __init__     denon        Initializing : Function power on for zone 1 not used by any item. Re-visit items and config file! -- __init__.py:_read_commandfile:443

2017-07-16 19:53:55 WARNING  __init__     denon        Initializing : Function power off for zone 1 not used by any item. Re-visit items and config file! -- __init__.py:_read_commandfile:443

2017-07-16 19:53:55 WARNING  __init__     denon        Initializing : Function volumemax for zone 1 not used by any item. Re-visit items and config file! -- __init__.py:_read_commandfile:443

2017-07-16 19:53:55 WARNING  __init__     denon        Initializing : Function statusupdate for zone 0 not used by any item. Re-visit items and config file! -- __init__.py:_read_commandfile:443

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Number of zones: 1 -- __init__.py:_read_commandfile:449

2017-07-16 19:53:55 INFO     __init__     denon        Initializing : Created functions list, including entries for 1 zones. -- __init__.py:_read_commandfile:456

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Functions: {'zone0': {'power on': ['0', 'power on', 'PWON|PWON', 'PW?', 'PW**', 'RW', 'no', '', 'bool'], 'power off': ['0', 'power off', 'PWOFF', 'PW?', 'PW***', 'RW', 'no', '', 'bool']}, 'zone2': {}, 'zone4': {}, 'zone1': {'volume-': ['1', 'volume-', 'MVDOWN', 'MV?', 'MV', 'W', 'no', '', 'bool'], 'mute on': ['1', 'mute on', 'MUON', 'MU?', 'MU**', 'RW', 'no', '', 'bool'], 'volume set': ['1', 'volume set', 'MV**', 'MV?', 'MV**', 'RW', 'no', '', 'num'], 'volume+': ['1', 'volume+', 'MVUP', 'MV?', 'MV', 'W', 'no', '', 'bool'], 'mute off': ['1', 'mute off', 'MUOFF', 'MU?', 'MU***', 'RW', 'no', '', 'bool']}, 'zone3': {}} -- __init__.py:_read_commandfile:458

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Finishing reading file. Lock is released. Lock is now False -- __init__.py:_read_commandfile:461

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Starting to create response commands. Lock is True -- __init__.py:_create_responsecommands:294

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Response: PW, Function: power, Item: [Item: avr.power], Type: bool -- __init__.py:_create_responsecommands:318

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Response: PW, Function: power, Item: [Item: avr.power], Type: bool -- __init__.py:_create_responsecommands:318

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Response: MV, Function: volume-, Item: [Item: avr.volumeDown], Type: bool -- __init__.py:_create_responsecommands:318

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Response: MU, Function: mute, Item: [Item: avr.mute], Type: bool -- __init__.py:_create_responsecommands:318

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Response: MV, Function: volume, Item: [Item: avr.volume], Type: num -- __init__.py:_create_responsecommands:318

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Response: MV, Function: volume+, Item: [Item: avr.volumeUp], Type: bool -- __init__.py:_create_responsecommands:318

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Response: MU, Function: mute, Item: [Item: avr.mute], Type: bool -- __init__.py:_create_responsecommands:318

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Response commands: {'MU': [2, 2, 2, [Item: avr.mute], 'mute', 'zone1', 'no', 'bool'], 'MV': [2, 2, 2, [Item: avr.volume], 'volume', 'zone1', 'no', 'num'], 'PW': [2, 2, 2, [Item: avr.power], 'power', 'zone0', 'no', 'bool']} -- __init__.py:_create_responsecommands:364

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Special commands for solving Display issues: {'Display': {'Command': '', 'Ignore': 1}, 'Speakers': {'Command': ''}, 'Nowplaying': {'Command': ''}, 'Input': {'Command': '', 'Ignore': 1}} -- __init__.py:_create_responsecommands:374

2017-07-16 19:53:55 INFO     __init__     denon        Initializing : Created response commands, including 3 entries. -- __init__.py:_create_responsecommands:376

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Finished creating response commands. Lock is released. Lock is now False -- __init__.py:_create_responsecommands:379

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Starting to create power commands. Lock is True -- __init__.py:_create_powercommands:264

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Finished creating power commands: ['PWON|PWON,PW?,PWON']. Lock is released. Lock is now False -- __init__.py:_create_powercommands:286

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Starting to create query commands. Lock is True -- __init__.py:_create_querycommands:212

2017-07-16 19:53:55 DEBUG    __init__     denon        Initializing : Created query commands: ['PW?,PW?,PW', 'MU?,MU?,MU', 'MV?,MV?,MV']. Created query zone commands: {'zone0': ['PW?,PW?,PW'], 'zone2': [], 'zone4': [], 'zone1': ['MU?,MU?,MU', 'MV?,MV?,MV'], 'zone3': []}. Lock is now False -- __init__.py:_create_querycommands:254

2017-07-16 19:53:55 INFO     __init__     denon        Initializing : Created query commands, including 3 entries. -- __init__.py:_create_querycommands:256

2017-07-16 19:53:55 DEBUG    __init__     denon        Connecting : Starting to connect. Current Connections: [] -- __init__.py:connect:921

2017-07-16 19:53:55 DEBUG    __init__     denon        Connecting : Depending is false. Message: 'NoneType' object is not callable -- __init__.py:connect:934

2017-07-16 19:53:55 DEBUG    __init__     avdevice-tcp-reconnect Connecting TCP : Starting to connect to 192.168.2.52. -- __init__.py:connect_tcp:952

2017-07-16 19:53:55 INFO     __init__     avdevice-tcp-reconnect Connecting TCP : Connected to 192.168.2.52:23 -- __init__.py:connect_tcp:960

2017-07-16 19:53:55 DEBUG    __init__     avdevice-tcp-reconnect Connecting TCP : Deactivating reconnect scheduler. Command list while connecting: []. Keep Commands: {} -- __init__.py:connect_tcp:994

2017-07-16 19:54:00 DEBUG    __init__     Main         Updating Item for avdevice_: Starting to update item avr.mute. Lock is: True. Reconnectrigger is True -- __init__.py:update_item:1475

2017-07-16 19:54:00 DEBUG    __init__     Main         Updating Item for avdevice_: Trying to connect while updating item -- __init__.py:update_item:1478

2017-07-16 19:54:00 DEBUG    __init__     Main         Connecting : Starting to connect. Current Connections: ['TCP'] -- __init__.py:connect:921

2017-07-16 19:54:00 DEBUG    __init__     Main         Connecting : Depending is false. Message: 'NoneType' object is not callable -- __init__.py:connect:934

2017-07-16 19:54:00 DEBUG    __init__     Main         Updating Item for avdevice_: Visu trying to update avr.mute -- __init__.py:update_item:1483

2017-07-16 19:54:00 DEBUG    __init__     Main         Updating Item for avdevice_: Command mute is a standard command. Message: 'mute' -- __init__.py:update_item:1579

2017-07-16 19:54:00 DEBUG    __init__     Main         Updating Item for avdevice_: Visu set mute to True for avr.mute in zone 1 -- __init__.py:update_item:1583

2017-07-16 19:54:00 DEBUG    __init__     Main         Updating Item for avdevice_: Update Zone 1 Command On MUON for avr.mute -- __init__.py:update_item:1617

2017-07-16 19:54:00 DEBUG    __init__     Main         Updating Item for avdevice_: Updating item. Command list is ['MUON,MU?,MU1']. Sendingcommand: MUON,MU?,MU1. Lock is released. Now it is False -- __init__.py:update_item:1740

2017-07-16 19:54:00 DEBUG    __init__     Main         Sending : Starting to send command MUON from list ['MUON,MU?,MU1']. Caller: updateitem. Lock is: True -- __init__.py:_send:1794

2017-07-16 19:54:00 DEBUG    __init__     Main         Sending : Trying to connect while sending command -- __init__.py:_send:1822

2017-07-16 19:54:00 DEBUG    __init__     Main         Connecting : Starting to connect. Current Connections: ['TCP'] -- __init__.py:connect:921

2017-07-16 19:54:00 DEBUG    __init__     Main         Connecting : Depending is false. Message: 'NoneType' object is not callable -- __init__.py:connect:934

2017-07-16 19:54:00 DEBUG    __init__     Main         Sending TCP : command was sent MUON from Multicommand-List ['MUON']. Returns 5 -- __init__.py:_send:1840

2017-07-16 19:54:01 DEBUG    __init__     Main         Updating Item for avdevice_: Updating item. Command list is ['MUON,MU?,MU1']. Return from send is 5. Lock is released. Now it is False -- __init__.py:update_item:1748

2017-07-16 19:54:02 DEBUG    __init__     Main         Updating Item for avdevice_: Starting to update item avr.mute. Lock is: True. Reconnectrigger is True -- __init__.py:update_item:1475

2017-07-16 19:54:02 DEBUG    __init__     Main         Updating Item for avdevice_: Trying to connect while updating item -- __init__.py:update_item:1478

2017-07-16 19:54:02 DEBUG    __init__     Main         Connecting : Starting to connect. Current Connections: ['TCP'] -- __init__.py:connect:921

2017-07-16 19:54:02 DEBUG    __init__     Main         Connecting : Depending is false. Message: 'NoneType' object is not callable -- __init__.py:connect:934

2017-07-16 19:54:02 DEBUG    __init__     Main         Updating Item for avdevice_: Visu trying to update avr.mute -- __init__.py:update_item:1483

2017-07-16 19:54:02 DEBUG    __init__     Main         Updating Item for avdevice_: Command mute is a standard command. Message: 'mute' -- __init__.py:update_item:1579

2017-07-16 19:54:02 DEBUG    __init__     Main         Updating Item for avdevice_: Visu set mute to False for avr.mute in zone 1 -- __init__.py:update_item:1583

2017-07-16 19:54:02 DEBUG    __init__     Main         Updating Item for avdevice_: Update Zone 1 Command Off MUOFF for avr.mute -- __init__.py:update_item:1648

2017-07-16 19:54:02 DEBUG    __init__     Main         Updating Item for avdevice_: Updating item. Command list is ['MUON,MU?,MU1', 'MUOFF,MU?,MU0']. Sendingcommand: MUON,MU?,MU1. Lock is released. Now it is False -- __init__.py:update_item:1740

2017-07-16 19:54:02 DEBUG    __init__     Main         Sending : Starting to send command MUON from list ['MUON,MU?,MU1', 'MUOFF,MU?,MU0']. Caller: updateitem. Lock is: True -- __init__.py:_send:1794

2017-07-16 19:54:02 DEBUG    __init__     Main         Sending : Trying to connect while sending command -- __init__.py:_send:1822

2017-07-16 19:54:02 DEBUG    __init__     Main         Connecting : Starting to connect. Current Connections: ['TCP'] -- __init__.py:connect:921

2017-07-16 19:54:02 DEBUG    __init__     Main         Connecting : Depending is false. Message: 'NoneType' object is not callable -- __init__.py:connect:934

2017-07-16 19:54:02 DEBUG    __init__     Main         Sending TCP : command was sent MUON from Multicommand-List ['MUON']. Returns 5 -- __init__.py:_send:1840

2017-07-16 19:54:03 DEBUG    __init__     Main         Updating Item for avdevice_: Updating item. Command list is ['MUON,MU?,MU1', 'MUOFF,MU?,MU0']. Return from send is 5. Lock is released. Now it is False -- __init__.py:update_item:1748

2017-07-16 19:54:06 DEBUG    __init__     Main         Updating Item for avdevice_: Starting to update item avr.mute. Lock is: True. Reconnectrigger is True -- __init__.py:update_item:1475

2017-07-16 19:54:06 DEBUG    __init__     Main         Updating Item for avdevice_: Trying to connect while updating item -- __init__.py:update_item:1478

2017-07-16 19:54:06 DEBUG    __init__     Main         Connecting : Starting to connect. Current Connections: ['TCP'] -- __init__.py:connect:921

2017-07-16 19:54:06 DEBUG    __init__     Main         Connecting : Depending is false. Message: 'NoneType' object is not callable -- __init__.py:connect:934

2017-07-16 19:54:06 DEBUG    __init__     Main         Updating Item for avdevice_: Visu trying to update avr.mute -- __init__.py:update_item:1483

2017-07-16 19:54:06 DEBUG    __init__     Main         Updating Item for avdevice_: Command mute is a standard command. Message: 'mute' -- __init__.py:update_item:1579

2017-07-16 19:54:06 DEBUG    __init__     Main         Updating Item for avdevice_: Visu set mute to True for avr.mute in zone 1 -- __init__.py:update_item:1583

2017-07-16 19:54:06 DEBUG    __init__     Main         Updating Item for avdevice_: Update Zone 1 Command On MUON for avr.mute -- __init__.py:update_item:1617

2017-07-16 19:54:06 DEBUG    __init__     Main         Updating Item for avdevice_: Updating item. Command list is ['MUON,MU?,MU1', 'MUOFF,MU?,MU0', 'MUON,MU?,MU1']. Sendingcommand: MUON,MU?,MU1. Lock is released. Now it is False -- __init__.py:update_item:1740

2017-07-16 19:54:06 DEBUG    __init__     Main         Sending : Starting to send command MUON from list ['MUON,MU?,MU1', 'MUOFF,MU?,MU0', 'MUON,MU?,MU1']. Caller: updateitem. Lock is: True -- __init__.py:_send:1794

2017-07-16 19:54:06 DEBUG    __init__     Main         Sending : Trying to connect while sending command -- __init__.py:_send:1822

2017-07-16 19:54:06 DEBUG    __init__     Main         Connecting : Starting to connect. Current Connections: ['TCP'] -- __init__.py:connect:921

2017-07-16 19:54:06 DEBUG    __init__     Main         Connecting : Depending is false. Message: 'NoneType' object is not callable -- __init__.py:connect:934

2017-07-16 19:54:06 DEBUG    __init__     Main         Sending TCP : command was sent MUON from Multicommand-List ['MUON']. Returns 5 -- __init__.py:_send:1840

2017-07-16 19:54:07 DEBUG    __init__     Main         Updating Item for avdevice_: Updating item. Command list is ['MUON,MU?,MU1', 'MUOFF,MU?,MU0', 'MUON,MU?,MU1']. Return from send is 5. Lock is released. Now it is False -- __init__.py:update_item:1748

2017-07-16 19:54:08 DEBUG    __init__     Main         Updating Item for avdevice_: Starting to update item avr.mute. Lock is: True. Reconnectrigger is True -- __init__.py:update_item:1475

2017-07-16 19:54:08 DEBUG    __init__     Main         Updating Item for avdevice_: Trying to connect while updating item -- __init__.py:update_item:1478

2017-07-16 19:54:08 DEBUG    __init__     Main         Connecting : Starting to connect. Current Connections: ['TCP'] -- __init__.py:connect:921

2017-07-16 19:54:08 DEBUG    __init__     Main         Connecting : Depending is false. Message: 'NoneType' object is not callable -- __init__.py:connect:934

2017-07-16 19:54:08 DEBUG    __init__     Main         Updating Item for avdevice_: Visu trying to update avr.mute -- __init__.py:update_item:1483

2017-07-16 19:54:08 DEBUG    __init__     Main         Updating Item for avdevice_: Command mute is a standard command. Message: 'mute' -- __init__.py:update_item:1579

2017-07-16 19:54:08 DEBUG    __init__     Main         Updating Item for avdevice_: Visu set mute to False for avr.mute in zone 1 -- __init__.py:update_item:1583

2017-07-16 19:54:08 DEBUG    __init__     Main         Updating Item for avdevice_: Update Zone 1 Command Off MUOFF for avr.mute -- __init__.py:update_item:1648

2017-07-16 19:54:08 DEBUG    __init__     Main         Updating Item for avdevice_: Updating item. Command list is ['MUON,MU?,MU1', 'MUOFF,MU?,MU0', 'MUON,MU?,MU1', 'MUOFF,MU?,MU0']. Sendingcommand: MUON,MU?,MU1. Lock is released. Now it is False -- __init__.py:update_item:1740

2017-07-16 19:54:08 DEBUG    __init__     Main         Sending : Starting to send command MUON from list ['MUON,MU?,MU1', 'MUOFF,MU?,MU0', 'MUON,MU?,MU1', 'MUOFF,MU?,MU0']. Caller: updateitem. Lock is: True -- __init__.py:_send:1794

2017-07-16 19:54:08 DEBUG    __init__     Main         Sending : Trying to connect while sending command -- __init__.py:_send:1822

2017-07-16 19:54:08 DEBUG    __init__     Main         Connecting : Starting to connect. Current Connections: ['TCP'] -- __init__.py:connect:921

2017-07-16 19:54:08 DEBUG    __init__     Main         Connecting : Depending is false. Message: 'NoneType' object is not callable -- __init__.py:connect:934

2017-07-16 19:54:08 DEBUG    __init__     Main         Sending TCP : command was sent MUON from Multicommand-List ['MUON']. Returns 5 -- __init__.py:_send:1840

2017-07-16 19:54:08 DEBUG    __init__     Main         Updating Item for avdevice_: Updating item. Command list is ['MUON,MU?,MU1', 'MUOFF,MU?,MU0', 'MUON,MU?,MU1', 'MUOFF,MU?,MU0']. Return from send is 5. Lock is released. Now it is False -- __init__.py:update_item:1748

Vollständigkeitshalber hier das .txt:

ZONE;FUNCTION;SEND;QUERY;RESPONSE;READWRITE;INVERTRESPONSE;MAXVALUE;TYPE
0;power on;PWON|PWON;PW?;PW**;RW
0;power off;PWOFF;PW?;PW***;RW
1;power on;ZMON;ZM?;ZM**;RW
1;power off;ZMOFF;ZM?;ZM***;RW
1;mute on;MUON;MU?;MU**;RW
1;mute off;MUOFF;MU?;MU***;RW
1;volume set;MV**;MV?;MV**;RW
1;volume+;MVUP;MV?;MV;W
1;volume-;MVDOWN;MV?;MV;W
1;volumemax;;MV?;MVMAX **;R
0;statusupdate;;;;W

[Foxi352]

Hab aber nicht deine neue init.py von obendrüber genommen. Hast du da schon was geupdated ? Hab deins aus dem PM bis jetzt ....

[Onkelandy]

Im PM müsste das gleiche sein wie hier im Anhang.
Mach doch bitte mal in Zeile 996 aus
if 'TCP' in self._is_connected:
ein
if 'a' == 'a':

Denn dieser Teil des Codes wird offenbar nicht ausgeführt und drum werden auch keine Antworten ausgewertet. Zeile 997 eventuell noch auskommentieren.

So müsste nach dem "Deactivating reconnect scheduler" im Log eine der beiden Zeilen auftauchen "Updated Item after connection" oder "No statusupdate defined.." und die parse_input Funktion gestartet werden.