openhab / openhab-addons

Add-ons for openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.86k stars 3.57k forks source link

[denonmarantz] The Thing sometimes go to UNKNOWN #4271

Closed radokristof closed 5 years ago

radokristof commented 5 years ago

Dear Developers!

I'm having this issue for a long time and I haven't found a solution for it (yet). So sometimes my Denon AVR Thing goes to Unknown state. I don't know why and when it changes, but then I can't control it.

The error:

2018-11-23 12:35:56.745 [DEBUG] [org.openhab.binding.denonmarantz    ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=529, service.bundleid=250, service.scope=bundle, component.name=org.openhab.binding.denonmarantz.internal.DenonMarantzHandlerFactory, component.id=359} - org.openhab.binding.denonmarantz

2018-11-23 12:35:56.858 [DEBUG] [internal.handler.DenonMarantzHandler] - Configuring zone channels

2018-11-23 12:35:56.866 [DEBUG] [internal.handler.DenonMarantzHandler] - No zone channels have been added

2018-11-23 12:35:56.870 [DEBUG] [internal.handler.DenonMarantzHandler] - No zone channels have been removed

2018-11-23 12:35:56.883 [DEBUG] [ctor.telnet.DenonMarantzTelnetClient] - Denon listener created

2018-11-23 12:35:56.886 [DEBUG] [ctor.telnet.DenonMarantzTelnetClient] - Connecting to 10.0.0.192

2018-11-23 12:35:56.887 [DEBUG] [internal.handler.DenonMarantzHandler] - Unsupported command REFRESH for channel general#artist

2018-11-23 12:35:56.891 [DEBUG] [internal.handler.DenonMarantzHandler] - Unsupported command REFRESH for channel general#album

2018-11-23 12:35:56.894 [DEBUG] [ctor.telnet.DenonMarantzTelnetClient] - Denon telnet client connected to 10.0.0.192

2018-11-23 12:35:56.895 [DEBUG] [r.telnet.DenonMarantzTelnetConnector] - Sending command 'PW?'

2018-11-23 12:35:56.898 [DEBUG] [ctor.telnet.DenonMarantzTelnetClient] - Sending command PW?

2018-11-23 12:35:56.907 [DEBUG] [ery.DenonMarantzDiscoveryParticipant] - AVR found: 0005CD9D14AE@Denon AVR-X3400H._raop._tcp.local.

2018-11-23 12:35:56.910 [DEBUG] [ery.DenonMarantzDiscoveryParticipant] - This seems like a supported Denon/Marantz AVR!

2018-11-23 12:35:56.914 [DEBUG] [ery.DenonMarantzDiscoveryParticipant] - Could not determine IP address for the Denon/Marantz AVR

2018-11-23 12:35:56.921 [DEBUG] [org.openhab.binding.denonmarantz    ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.mdns.MDNSDiscoveryParticipant}={service.id=530, service.bundleid=250, service.scope=bundle, component.name=org.openhab.binding.denonmarantz.internal.discovery.DenonMarantzDiscoveryParticipant, component.id=360} - org.openhab.binding.denonmarantz

2018-11-23 12:35:56.927 [DEBUG] [org.openhab.binding.denonmarantz    ] - BundleEvent STARTED - org.openhab.binding.denonmarantz

2018-11-23 12:35:56.968 [DEBUG] [internal.handler.DenonMarantzHandler] - Unsupported command REFRESH for channel general#track

2018-11-23 12:35:56.987 [DEBUG] [r.telnet.DenonMarantzTelnetConnector] - Sending command 'MV?'

2018-11-23 12:35:56.988 [DEBUG] [r.telnet.DenonMarantzTelnetConnector] - Sending command 'SI?'

2018-11-23 12:35:56.990 [DEBUG] [r.telnet.DenonMarantzTelnetConnector] - Sending command 'MU?'

2018-11-23 12:35:56.990 [DEBUG] [r.telnet.DenonMarantzTelnetConnector] - Sending command 'ZM?'

2018-11-23 12:35:56.993 [DEBUG] [ctor.telnet.DenonMarantzTelnetClient] - Sending command MU?

2018-11-23 12:35:56.993 [DEBUG] [ctor.telnet.DenonMarantzTelnetClient] - Sending command ZM?

2018-11-23 12:35:57.009 [DEBUG] [ctor.telnet.DenonMarantzTelnetClient] - Sending command MV?

2018-11-23 12:35:57.010 [DEBUG] [ctor.telnet.DenonMarantzTelnetClient] - Sending command SI?

2018-11-23 12:35:57.201 [DEBUG] [r.telnet.DenonMarantzTelnetConnector] - Sending command 'MS?'

2018-11-23 12:35:57.203 [DEBUG] [ctor.telnet.DenonMarantzTelnetClient] - Sending command MS?

==> /var/log/openhab2/events.log <==

2018-11-23 12:35:56.835 [hingStatusInfoChangedEvent] - 'denonmarantz:avr:0005cd9d14ae' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2018-11-23 12:35:56.875 [hingStatusInfoChangedEvent] - 'denonmarantz:avr:0005cd9d14ae' changed from INITIALIZING to UNKNOWN

==> /var/log/openhab2/openhab.log <==

2018-11-23 12:35:57.505 [DEBUG] [r.telnet.DenonMarantzTelnetConnector] - Sending command 'MV?'

2018-11-23 12:35:57.506 [DEBUG] [ctor.telnet.DenonMarantzTelnetClient] - Sending command MV?

2018-11-23 12:35:57.811 [DEBUG] [r.telnet.DenonMarantzTelnetConnector] - Sending command 'ZM?'

2018-11-23 12:35:57.814 [DEBUG] [ctor.telnet.DenonMarantzTelnetClient] - Sending command ZM?

2018-11-23 12:35:58.117 [DEBUG] [r.telnet.DenonMarantzTelnetConnector] - Sending command 'MU?'

2018-11-23 12:35:58.120 [DEBUG] [ctor.telnet.DenonMarantzTelnetClient] - Sending command MU?

2018-11-23 12:35:58.423 [DEBUG] [r.telnet.DenonMarantzTelnetConnector] - Sending command 'SI?'

2018-11-23 12:35:58.426 [DEBUG] [ctor.telnet.DenonMarantzTelnetClient] - Sending command SI?

2018-11-23 12:35:58.729 [DEBUG] [r.telnet.DenonMarantzTelnetConnector] - Sending command 'Z2?'

2018-11-23 12:35:58.731 [DEBUG] [ctor.telnet.DenonMarantzTelnetClient] - Sending command Z2?

2018-11-23 12:35:59.034 [DEBUG] [r.telnet.DenonMarantzTelnetConnector] - Sending command 'Z2MU?'

2018-11-23 12:35:59.036 [DEBUG] [ctor.telnet.DenonMarantzTelnetClient] - Sending command Z2MU?

So it seems that the Binding can send commands to the AVR, so I don't really know what is wrong... Sometimes it solves itself after a little time, sometimes restarting the bundle helps, but sometimes only restarting the AVR can help and solve this...

piejanssens commented 5 years ago

@radokristof Solved? I have the same problem.

radokristof commented 5 years ago

Yes. I got an update for the AVR some time ago. Since then I can't reproduce this error, it stays online