Russound RIO

tmrobert8 · October 12, 2016, 12:04pm

Good to hear it worked! I had a feeling you meant features but I wanted to make sure I didn’t overlook anything. Once I’m done with the Sony changes, I’ll swing back around to this and add those. Please let me know if you encounter any other issues.

Tomtibo · November 29, 2016, 7:40am

Hi Tim!
I finally get my hands on a MCA88. Now that I’m use to openhab 2, I can confirm there is a problem receiving any status update, and none of the commands works. However, the binding seems to connect successfully to the MCA. Here is the log, with debugging enabled, went I restart the binding.

14:58:01.203 [DEBUG] [org.openhab.binding.russound        ] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=binding.russound, component.id=14, service.id=113, service.bundleid=10, service.scope=bundle} - org.openhab.binding.russound
14:58:01.233 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:6' changed from ONLINE to UNINITIALIZED (HANDLER_MISSING_ERROR)
14:58:01.236 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH C[1].Z[6] OFF'
14:58:01.247 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH C[1].Z[5] OFF'
14:58:01.251 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:5' changed from ONLINE to UNINITIALIZED (HANDLER_MISSING_ERROR)
14:58:01.253 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH C[1].Z[3] OFF'
14:58:01.256 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:3' changed from ONLINE to UNINITIALIZED (HANDLER_MISSING_ERROR)
14:58:01.266 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH C[1].Z[4] OFF'
14:58:01.269 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:4' changed from ONLINE to UNINITIALIZED (HANDLER_MISSING_ERROR)
14:58:01.279 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:source:5' changed from OFFLINE (CONFIGURATION_ERROR): Cannot be initialized without a bridge to UNINITIALIZED (HANDLER_MISSING_ERROR)
14:58:01.284 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH S[4] OFF'
14:58:01.285 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:source:4' changed from ONLINE to UNINITIALIZED (HANDLER_MISSING_ERROR)
14:58:01.306 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH C[1].Z[1] OFF'
14:58:01.307 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:1' changed from ONLINE to UNINITIALIZED (HANDLER_MISSING_ERROR)
14:58:01.313 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH C[1].Z[2] OFF'
14:58:01.315 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:2' changed from ONLINE to UNINITIALIZED (HANDLER_MISSING_ERROR)
14:58:01.320 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:controller:main' changed from ONLINE to UNINITIALIZED (HANDLER_MISSING_ERROR)
14:58:01.324 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH S[3] OFF'
14:58:01.325 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:source:3' changed from ONLINE to UNINITIALIZED (HANDLER_MISSING_ERROR)
14:58:01.336 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH S[2] OFF'
14:58:01.336 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:source:2' changed from ONLINE to UNINITIALIZED (HANDLER_MISSING_ERROR)
14:58:01.353 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH S[1] OFF'
14:58:01.353 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:source:1' changed from ONLINE to UNINITIALIZED (HANDLER_MISSING_ERROR)
14:58:01.378 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:rio:main' changed from ONLINE to UNINITIALIZED (HANDLER_MISSING_ERROR)
14:58:01.379 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH SYSTEM OFF'
14:58:01.380 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH SYSTEM OFF'
14:58:01.384 [DEBUG] [.russound.internal.net.SocketSession] - Disconnecting from 192.168.11.74:9621
14:58:02.095 [DEBUG] [org.openhab.binding.russound        ] - BundleEvent STOPPING - org.openhab.binding.russound
14:58:02.108 [DEBUG] [org.openhab.binding.russound        ] - BundleEvent STOPPED - org.openhab.binding.russound
14:58:02.114 [DEBUG] [org.openhab.binding.russound        ] - BundleEvent STARTING - org.openhab.binding.russound
14:58:02.151 [DEBUG] [org.openhab.binding.russound        ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=binding.russound, component.id=198, service.id=331, service.bundleid=10, service.scope=bundle} - org.openhab.binding.russound
14:58:02.206 [DEBUG] [org.openhab.binding.russound        ] - BundleEvent STARTED - org.openhab.binding.russound
14:58:02.481 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:rio:main' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
14:58:02.497 [DEBUG] [russound.rio.source.RioSourceHandler] - Initializing
14:58:02.499 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:source:5' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
14:58:02.537 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:source:5' changed from INITIALIZING to OFFLINE (CONFIGURATION_ERROR): Cannot be initialized without a bridge
14:58:03.485 [DEBUG] [.russound.internal.net.SocketSession] - Connecting to 192.168.11.74:9621
14:58:03.489 [INFO ] [ussound.rio.system.RioSystemProtocol] - Russound System now connected
14:58:03.496 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH SYSTEM ON'
14:58:03.498 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET System.status'
14:58:03.500 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'VERSION'
14:58:03.502 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET System.language'
14:58:03.504 [INFO ] [russound.rio.system.RioSystemHandler] - Going online
14:58:03.513 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'VERSION'
14:58:03.524 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET System.status'
14:58:03.528 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET System.language'
14:58:03.543 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:source:2' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
14:58:03.537 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:rio:main' changed from INITIALIZING to ONLINE
14:58:03.550 [DEBUG] [russound.rio.source.RioSourceHandler] - Initializing
14:58:03.567 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:source:3' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
14:58:03.568 [DEBUG] [russound.rio.source.RioSourceHandler] - Initializing
14:58:03.572 [DEBUG] [russound.rio.source.RioSourceHandler] - Initializing
14:58:03.595 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH S[4] ON'
14:58:03.598 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[4].ipAddress'
14:58:03.602 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH S[2] ON'
14:58:03.606 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].ipAddress'
14:58:03.610 [DEBUG] [russound.rio.source.RioSourceHandler] - Initializing
14:58:03.615 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].type'
14:58:03.617 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].ipAddress'
14:58:03.618 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].macAddress'
14:58:03.629 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH S[3] ON'
14:58:03.631 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].ipAddress'
14:58:03.642 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH S[1] ON'
14:58:03.644 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[1].ipAddress'
14:58:03.661 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:controller:main' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
14:58:03.677 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:source:4' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
14:58:03.691 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].name'
14:58:03.694 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].type'
14:58:03.717 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH C[1].Z[4] ON'
14:58:03.719 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[4].enabled'
14:58:03.720 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].ipAddress'
14:58:03.728 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].composerName'
14:58:03.731 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH C[1].Z[1] ON'
14:58:03.733 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].enabled'
14:58:03.735 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].channel'
14:58:03.740 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].channel'
14:58:03.743 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH C[1].Z[2] ON'
14:58:03.743 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:source:4' changed from INITIALIZING to ONLINE
14:58:03.745 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[2].enabled'
14:58:03.746 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].genre'
14:58:03.749 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH C[1].Z[3] ON'
14:58:03.751 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[3].enabled'
14:58:03.753 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].artistName'
14:58:03.754 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH C[1].Z[5] ON'
14:58:03.756 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[5].enabled'
14:58:03.759 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].albumName'
14:58:03.761 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH C[1].Z[6] ON'
14:58:03.764 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[6].enabled'
14:58:03.767 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].type'
14:58:03.769 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].coverArtURL'
14:58:03.772 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].ipAddress'
14:58:03.774 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].coverArtURL'
14:58:03.776 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].macAddress'
14:58:03.778 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:controller:main' changed from INITIALIZING to ONLINE
14:58:03.777 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].playlistName'
14:58:03.782 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].songName'
14:58:03.787 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[2].name'
14:58:03.790 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].mode'
14:58:03.792 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[2].currentSource'
14:58:03.794 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].shuffleMode'
14:58:03.796 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[2].bass'
14:58:03.799 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[2].treble'
14:58:03.802 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].repeatMode'
14:58:03.806 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[2].balance'
14:58:03.809 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].rating'
14:58:03.813 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[2].loudness'
14:58:03.815 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].programServiceName'
14:58:03.819 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[2].turnOnVolume'
14:58:03.822 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].radioText'
14:58:03.824 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[2].doNotDisturb'
14:58:03.827 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].radioText'
14:58:03.830 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[2].partyMode'
14:58:03.832 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].radioText'
14:58:03.835 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[2].status'
14:58:03.837 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[3].radioText'
14:58:03.840 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[2].volume'
14:58:03.842 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:source:3' changed from INITIALIZING to ONLINE
14:58:03.845 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[2].mute'
14:58:03.851 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[4].name'
14:58:03.854 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[2].page'
14:58:03.856 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[4].currentSource'
14:58:03.859 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[2].sharedSource'
14:58:03.863 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[4].bass'
14:58:03.866 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[2].sleepTimeRemaining'
14:58:03.869 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[4].treble'
14:58:03.871 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[2].lastError'
14:58:03.874 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[4].balance'
14:58:03.878 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[4].loudness'
14:58:03.883 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[4].turnOnVolume'
14:58:03.888 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[4].doNotDisturb'
14:58:03.891 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:2' changed from INITIALIZING to ONLINE
14:58:03.898 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[4].partyMode'
14:58:03.900 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[5].name'
14:58:03.902 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[4].status'
14:58:03.905 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[5].currentSource'
14:58:03.908 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[4].volume'
14:58:03.912 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[5].bass'
14:58:03.914 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[4].mute'
14:58:03.917 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[5].treble'
14:58:03.920 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[4].page'
14:58:03.924 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[5].balance'
14:58:03.926 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[4].sharedSource'
14:58:03.929 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[5].loudness'
14:58:03.932 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[4].sleepTimeRemaining'
14:58:03.934 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[5].turnOnVolume'
14:58:03.938 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[4].lastError'
14:58:03.942 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[5].doNotDisturb'
14:58:03.947 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[5].partyMode'
14:58:03.951 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[5].status'
14:58:03.957 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[5].volume'
14:58:03.961 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[5].mute'
14:58:03.962 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:4' changed from INITIALIZING to ONLINE
14:58:03.968 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[5].page'
14:58:03.971 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].name'
14:58:03.973 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].currentSource'
14:58:03.975 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[5].sharedSource'
14:58:03.978 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].bass'
14:58:03.982 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[5].sleepTimeRemaining'
14:58:03.984 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].treble'
14:58:03.987 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].balance'
14:58:03.990 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[5].lastError'
14:58:03.992 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].loudness'
14:58:03.996 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].doNotDisturb'
14:58:03.999 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].partyMode'
14:58:04.002 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].status'
14:58:04.005 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].volume'
14:58:04.008 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].mute'
14:58:04.011 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].page'
14:58:04.015 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:5' changed from INITIALIZING to ONLINE
14:58:04.014 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].sharedSource'
14:58:04.026 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].sleepTimeRemaining'
14:58:04.025 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:source:1' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
14:58:04.030 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:5' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
14:58:04.031 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].lastError'
14:58:04.037 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].name'
14:58:04.040 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].type'
14:58:04.046 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].genre'
14:58:04.049 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].artistName'
14:58:04.051 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].albumName'
14:58:04.052 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:1' changed from INITIALIZING to ONLINE
14:58:04.054 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].coverArtURL'
14:58:04.058 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].coverArtURL'
14:58:04.061 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].playlistName'
14:58:04.063 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[3].name'
14:58:04.065 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].songName'
14:58:04.067 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[3].currentSource'
14:58:04.069 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].mode'
14:58:04.071 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[3].bass'
14:58:04.073 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].shuffleMode'
14:58:04.076 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[3].treble'
14:58:04.077 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].repeatMode'
14:58:04.080 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[3].balance'
14:58:04.082 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].rating'
14:58:04.085 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[3].loudness'
14:58:04.086 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].programServiceName'
14:58:04.089 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[3].turnOnVolume'
14:58:04.091 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].radioText'
14:58:04.094 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].radioText'
14:58:04.095 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[3].doNotDisturb'
14:58:04.099 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].radioText'
14:58:04.102 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[2].radioText'
14:58:04.104 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[3].partyMode'
14:58:04.105 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:source:2' changed from INITIALIZING to ONLINE
14:58:04.111 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[3].status'
14:58:04.114 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[1].name'
14:58:04.117 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[3].volume'
14:58:04.119 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET S[1].type'
14:58:04.122 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[3].mute'
14:58:04.126 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[3].page'
14:58:04.131 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[3].sharedSource'
14:58:04.135 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[3].sleepTimeRemaining'
14:58:04.139 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[3].lastError'
14:58:04.152 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:source:1' changed from INITIALIZING to ONLINE
14:58:04.157 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:4' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
14:58:04.157 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:3' changed from INITIALIZING to ONLINE
14:58:04.162 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:6' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
14:58:04.164 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[6].name'
14:58:04.168 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[6].currentSource'
14:58:04.168 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:2' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
14:58:04.171 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[6].bass'
14:58:04.175 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[6].treble'
14:58:04.177 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:1' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
14:58:04.178 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[6].balance'
14:58:04.182 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[6].loudness'
14:58:04.185 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[6].turnOnVolume'
14:58:04.185 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:3' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
14:58:04.188 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[6].doNotDisturb'
14:58:04.191 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[6].partyMode'
14:58:04.194 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[6].status'
14:58:04.197 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[6].volume'
14:58:04.200 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[6].mute'
14:58:04.203 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[6].page'
14:58:04.206 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[6].sharedSource'
14:58:04.209 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[6].sleepTimeRemaining'
14:58:04.212 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[6].lastError'

tmrobert8 · December 28, 2016, 6:57pm

Been way too busy for awhile but getting back to this (now that I’ve rebuild my pc). I’m a bit confused by the log because it looks like it connected but is receiving no feedback. Tell you what - I’m going to be committing some new code (will only work with the nightly builds however). I’ll post a message when committed and would want you to try to retest it if you would (with logging message).

Thanks,
Tim

tmrobert8 · December 29, 2016, 3:20am

How technical are you? If I tell you to telnet into the mca88 and execute some commands, are you comfortable doing that?

Thanks,
Tim

Tomtibo · December 29, 2016, 7:53am

I’m not a programmer but, I’m use to linux command line. For now, I can control the Russound system using a script (1364 lines of code lol) executed by the exec binding.

#!/bin/sh

IP=192.168.11.74
PORT=9621

case $1 in
 powerall)
STATE=$2
	echo "EVENT c[1].z[1]!all$STATE" | nc -C $IP $PORT
	;;
#######
##ZONE1
 powerz1)
STATE=$2
	echo "EVENT c[1].z[1]!zone$STATE" | nc -C $IP $PORT
	;;
 volz1) 
LEVEL=`echo "$2/2" | bc`
	echo "set c[1].z[1].turnOnVolume=\"$LEVEL\"" | nc -C $IP $PORT
	;;	
 ....

Just tell me which telnet command you want me to do and I will do it! Also I can retest your binding with the latest nightly, but you will have to provide me the new compiled binding jar file. Because I don’t know how to compile it from sources.
Nice to to see you back on track!

Thanks!
Tom

tmrobert8 · December 29, 2016, 1:25pm

Tom,

If you would do the following (all commands case sensitive)

Telnet to 192.168.11.74:9621
Enter “WATCH C[1].Z[1] ON” - you’ll get a whole bunch of replies
Enter “EVENT C[1].Z[1]!ZoneOn” - again you’ll get some replies
Enter “EVENT C[1].Z[1]!ZoneOff” - again you’ll get some replies
Close the session

Then copy/paste the whole session into a reply

Thanks,
Tim

Tomtibo · December 29, 2016, 5:43pm

Easy!

Trying 192.168.11.74...
Connected to 192.168.11.74.
Escape character is '^]'.
WATCH C[1].Z[1] ON
S
N C[1].Z[1].name="Salon"
N C[1].Z[1].treble="0"
N C[1].Z[1].balance="0"
N C[1].Z[1].loudness="OFF"
N C[1].Z[1].turnOnVolume="10"
N C[1].Z[1].doNotDisturb="OFF"
N C[1].Z[1].currentSource="1"
N C[1].Z[1].volume="15"
N C[1].Z[1].status="OFF"
N C[1].Z[1].mute="OFF"
N C[1].Z[1].partyMode="OFF"
N C[1].Z[1].bass="2"
N C[1].Z[1].page="OFF"
N C[1].Z[1].sharedSource="OFF"
N C[1].Z[1].sleepTimeRemaining="0"
N C[1].Z[1].lastError=""
N S[1].name="Bluetooth"
N S[1].type="BTC-1"

EVENT C[1].Z[1]!ZoneOn
S
N C[1].Z[1].status="ON"
N C[1].Z[1].volume="10"

EVENT C[1].Z[1]!ZoneOff
S
N C[1].Z[1].status="OFF"

Just ask me if you need something else!

Thanks!
Tom

tmrobert8 · December 29, 2016, 7:10pm

Well - that’s what I expected. Try the file I uploaded over on openhab2-addons (and make sure you’re using the latest nightly build). Turn on the debug log for russound and reply with it (from when it starts up to when nothing really happens)

Tomtibo · December 30, 2016, 6:52am

Hi Tim. It seems to me that the problem is still there. I’m using openhab2-offline 2.0.0~20161230034201 and your latest jar file.

01:46:41.907 [DEBUG] [org.openhab.binding.russound        ] - BundleEvent STARTING - org.openhab.binding.russound
01:46:41.971 [DEBUG] [org.openhab.binding.russound        ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=binding.russound, component.id=188, service.id=319, service.bundleid=201, service.scope=bundle} - org.openhab.binding.russound
01:46:41.974 [DEBUG] [org.openhab.binding.russound        ] - BundleEvent STARTED - org.openhab.binding.russound
01:46:42.266 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:rio:home' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
01:46:43.304 [DEBUG] [.russound.internal.net.SocketSession] - Connecting to 192.168.11.74:9621
01:46:43.307 [INFO ] [ussound.rio.system.RioSystemProtocol] - Russound System now connected
01:46:43.314 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'VERSION'
01:46:43.317 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET System.language'
01:46:43.326 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH SYSTEM ON'
01:46:43.321 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:rio:home' changed from INITIALIZING to ONLINE
01:46:43.349 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET System.status'
01:46:43.352 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'VERSION'
01:46:43.357 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET System.language'
01:46:43.360 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:controller:controller' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
01:46:43.364 [INFO ] [russound.rio.system.RioSystemHandler] - Going online
01:46:43.366 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].type'
01:46:43.367 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].ipAddress'
01:46:43.380 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].macAddress'
01:46:43.389 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:controller:controller' changed from INITIALIZING to ONLINE
01:46:43.411 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:1' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
01:46:43.416 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH C[1].Z[1] ON'
01:46:43.419 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].enabled'
01:46:43.421 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].name'
01:46:43.424 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].currentSource'
01:46:43.426 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].bass'
01:46:43.428 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].treble'
01:46:43.431 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].balance'
01:46:43.433 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].loudness'
01:46:43.436 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].doNotDisturb'
01:46:43.438 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].partyMode'
01:46:43.441 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].status'
01:46:43.443 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].volume'
01:46:43.445 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].mute'
01:46:43.448 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].page'
01:46:43.450 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].sharedSource'
01:46:43.453 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].sleepTimeRemaining'
01:46:43.455 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].lastError'
01:46:43.461 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:1' changed from INITIALIZING to ONLINE
01:47:13.364 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: ''

tmrobert8 · December 30, 2016, 12:57pm

The log makes it look like we aren’t receiving anything. I’m betting we are receiving stuff but are not recognizing the new line. I have a feeling that that your mca88x doesn’t end lines with a carriage return/new line combo (like the other mcas) - I’m betting it’s simply one or the other. I posted a new zip (over on openhab2-addons) that will log the exact bytes we received (if any). Try that one and post the results again (don’t need the full log this time - just up to when the “>>>” logging message shows more than one response in the same line)

Thanks,
Tim

Tomtibo · December 30, 2016, 4:58pm

Hummm. I’m receiving the exact same log using the new jar. Nothing is received. I’m available this afternoon if you need me to test something else.
Thanks,
Tom

Tomtibo · December 30, 2016, 5:23pm

I remember having similar behavior with the onkyo1 binding issue, using a newer device. Briefly, the problem was “Data length was incorrectly calculated. It seems that older models are immune for this problems. Probably because they ignore the length field and just search EOF (every message ends to the EOF character).” Here is the closed bug report : https://github.com/openhab/openhab/issues/1999 Not sure if this can help.

tmrobert8 · December 30, 2016, 6:09pm

Just posted one with an unbelievable amount of debugging statements - give it a try. If the log doesn’t change again, then something is up on your end (this one definitely creates new logging message starting with “>>>”)

Tomtibo · December 30, 2016, 6:20pm

Yes now I see

>>> dispatch response: null

And also a warm warning so here is the complete log.

13:13:16.004 [DEBUG] [org.openhab.binding.russound        ] - BundleEvent STARTING - org.openhab.binding.russound
13:13:16.054 [DEBUG] [org.openhab.binding.russound        ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={component.name=binding.russound, component.id=185, service.id=316, service.bundleid=203, service.scope=bundle} - org.openhab.binding.russound
13:13:16.092 [DEBUG] [org.openhab.binding.russound        ] - BundleEvent STARTED - org.openhab.binding.russound
13:13:16.122 [WARN ] [ig.xml.osgi.XmlDocumentBundleTracker] - The XML document '/ESH-INF/binding/binding.xml' in module 'org.openhab.binding.russound' could not be parsed:  : ParseError at [row,col]:[8,83]
Message: The entity name must immediately follow the '&' in the entity reference. :  : ParseError at [row,col]:[8,83]
Message: The entity name must immediately follow the '&' in the entity reference.
---- Debugging information ----
message             :  : ParseError at [row,col]:[8,83]
Message: The entity name must immediately follow the '&' in the entity reference.
cause-exception     : com.thoughtworks.xstream.io.StreamException
cause-message       :  : ParseError at [row,col]:[8,83]
Message: The entity name must immediately follow the '&' in the entity reference.
class               : org.eclipse.smarthome.config.xml.util.NodeValue
required-type       : org.eclipse.smarthome.config.xml.util.NodeValue
converter-type      : org.eclipse.smarthome.config.xml.util.NodeValueConverter
path                : /binding/description
line number         : 8
class[1]            : java.util.ArrayList
converter-type[1]   : com.thoughtworks.xstream.converters.collections.CollectionConverter
class[2]            : org.eclipse.smarthome.core.binding.xml.internal.BindingInfoXmlResult
converter-type[2]   : org.eclipse.smarthome.core.binding.xml.internal.BindingInfoConverter
version             : 1.4.7
-------------------------------
com.thoughtworks.xstream.converters.ConversionException:  : ParseError at [row,col]:[8,83]
Message: The entity name must immediately follow the '&' in the entity reference. :  : ParseError at [row,col]:[8,83]
Message: The entity name must immediately follow the '&' in the entity reference.
---- Debugging information ----
message             :  : ParseError at [row,col]:[8,83]
Message: The entity name must immediately follow the '&' in the entity reference.
cause-exception     : com.thoughtworks.xstream.io.StreamException
cause-message       :  : ParseError at [row,col]:[8,83]
Message: The entity name must immediately follow the '&' in the entity reference.
class               : org.eclipse.smarthome.config.xml.util.NodeValue
required-type       : org.eclipse.smarthome.config.xml.util.NodeValue
converter-type      : org.eclipse.smarthome.config.xml.util.NodeValueConverter
path                : /binding/description
line number         : 8
class[1]            : java.util.ArrayList
converter-type[1]   : com.thoughtworks.xstream.converters.collections.CollectionConverter
class[2]            : org.eclipse.smarthome.core.binding.xml.internal.BindingInfoXmlResult
converter-type[2]   : org.eclipse.smarthome.core.binding.xml.internal.BindingInfoConverter
version             : 1.4.7
-------------------------------
	at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:79)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.core.AbstractReferenceUnmarshaller.convert(AbstractReferenceUnmarshaller.java:65)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:66)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:50)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.converters.collections.AbstractCollectionConverter.readItem(AbstractCollectionConverter.java:71)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.converters.collections.CollectionConverter.addCurrentElementToCollection(CollectionConverter.java:98)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.converters.collections.CollectionConverter.populateCollection(CollectionConverter.java:91)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.converters.collections.CollectionConverter.populateCollection(CollectionConverter.java:85)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.converters.collections.CollectionConverter.unmarshal(CollectionConverter.java:80)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:72)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.core.AbstractReferenceUnmarshaller.convert(AbstractReferenceUnmarshaller.java:65)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:66)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:50)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at org.eclipse.smarthome.core.binding.xml.internal.BindingInfoConverter.unmarshal(BindingInfoConverter.java:89)[99:org.eclipse.smarthome.core.binding.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:72)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.core.AbstractReferenceUnmarshaller.convert(AbstractReferenceUnmarshaller.java:65)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:66)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.core.TreeUnmarshaller.convertAnother(TreeUnmarshaller.java:50)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.core.TreeUnmarshaller.start(TreeUnmarshaller.java:134)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.core.AbstractTreeMarshallingStrategy.unmarshal(AbstractTreeMarshallingStrategy.java:32)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1185)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.XStream.unmarshal(XStream.java:1169)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.XStream.fromXML(XStream.java:1115)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.XStream.fromXML(XStream.java:1062)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at org.eclipse.smarthome.config.xml.util.XmlDocumentReader.readFromXML(XmlDocumentReader.java:82)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker$1.processBundle(XmlDocumentBundleTracker.java:129)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at org.eclipse.smarthome.config.xml.osgi.AbstractAsyncBundleProcessor$1.run(AbstractAsyncBundleProcessor.java:231)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at java.lang.Thread.run(Thread.java:745)[:1.8.0_111]
Caused by: com.thoughtworks.xstream.io.StreamException:  : ParseError at [row,col]:[8,83]
Message: The entity name must immediately follow the '&' in the entity reference.
	at com.thoughtworks.xstream.io.xml.StaxReader.pullNextEvent(StaxReader.java:73)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.io.xml.AbstractPullReader.readRealEvent(AbstractPullReader.java:148)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.io.xml.AbstractPullReader.readEvent(AbstractPullReader.java:135)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.io.xml.AbstractPullReader.getValue(AbstractPullReader.java:197)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.io.ReaderWrapper.getValue(ReaderWrapper.java:48)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.io.ReaderWrapper.getValue(ReaderWrapper.java:48)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at org.eclipse.smarthome.config.xml.util.NodeValueConverter.unmarshal(NodeValueConverter.java:33)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	at com.thoughtworks.xstream.core.TreeUnmarshaller.convert(TreeUnmarshaller.java:72)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	... 27 more
Caused by: javax.xml.stream.XMLStreamException: ParseError at [row,col]:[8,83]
Message: The entity name must immediately follow the '&' in the entity reference.
	at com.sun.org.apache.xerces.internal.impl.XMLStreamReaderImpl.next(XMLStreamReaderImpl.java:596)[:1.8.0_111]
	at com.thoughtworks.xstream.io.xml.StaxReader.pullNextEvent(StaxReader.java:58)[95:org.eclipse.smarthome.config.xml:0.9.0.201612221226]
	... 34 more
13:13:16.292 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:rio:home' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
13:13:17.288 [DEBUG] [.russound.internal.net.SocketSession] - >>> creating socket
13:13:17.322 [DEBUG] [.russound.internal.net.SocketSession] - Connecting to 192.168.11.74:9621
13:13:17.323 [DEBUG] [.russound.internal.net.SocketSession] - >>> creating writer
13:13:17.324 [DEBUG] [.russound.internal.net.SocketSession] - >>> creating reader
13:13:17.326 [DEBUG] [.russound.internal.net.SocketSession] - >>> starting dispatcher
13:13:17.329 [DEBUG] [.russound.internal.net.SocketSession] - >>> starting response reader
13:13:17.329 [DEBUG] [.russound.internal.net.SocketSession] - >>> starting dispatcher
13:13:17.335 [INFO ] [ussound.rio.system.RioSystemProtocol] - Russound System now connected
13:13:17.335 [DEBUG] [.russound.internal.net.SocketSession] - >>> Started listening for responses
13:13:17.342 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:rio:home' changed from INITIALIZING to ONLINE
13:13:17.348 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH SYSTEM ON'
13:13:17.352 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET System.status'
13:13:17.365 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'VERSION'
13:13:17.373 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'VERSION'
13:13:17.374 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET System.language'
13:13:17.376 [INFO ] [russound.rio.system.RioSystemHandler] - Going online
13:13:17.376 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET System.language'
13:13:17.381 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:controller:controller' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
13:13:17.393 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:controller:controller' changed from INITIALIZING to ONLINE
13:13:17.392 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].type'
13:13:17.402 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].ipAddress'
13:13:17.407 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].macAddress'
13:13:17.415 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:1' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
13:13:17.417 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'WATCH C[1].Z[1] ON'
13:13:17.418 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].enabled'
13:13:17.418 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'russound:zone:1' changed from INITIALIZING to ONLINE
13:13:17.422 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].name'
13:13:17.424 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].currentSource'
13:13:17.427 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].bass'
13:13:17.431 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].treble'
13:13:17.434 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].balance'
13:13:17.437 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].loudness'
13:13:17.440 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].doNotDisturb'
13:13:17.442 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].partyMode'
13:13:17.445 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].status'
13:13:17.448 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].volume'
13:13:17.450 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].mute'
13:13:17.452 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].page'
13:13:17.455 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].sharedSource'
13:13:17.458 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].sleepTimeRemaining'
13:13:17.460 [DEBUG] [.russound.internal.net.SocketSession] - Sending Command: 'GET C[1].Z[1].lastError'
13:13:18.334 [DEBUG] [.russound.internal.net.SocketSession] - >>> dispatch response: null
13:13:19.336 [DEBUG] [.russound.internal.net.SocketSession] - >>> dispatch response: null
13:13:20.338 [DEBUG] [.russound.internal.net.SocketSession] - >>> dispatch response: null
13:13:21.340 [DEBUG] [.russound.internal.net.SocketSession] - >>> dispatch response: null
13:13:22.342 [DEBUG] [.russound.internal.net.SocketSession] - >>> dispatch response: null
13:13:23.344 [DEBUG] [.russound.internal.net.SocketSession] - >>> dispatch response: null
13:13:24.345 [DEBUG] [.russound.internal.net.SocketSession] - >>> dispatch response: null
13:13:25.347 [DEBUG] [.russound.internal.net.SocketSession] - >>> dispatch response: null
13:13:26.350 [DEBUG] [.russound.internal.net.SocketSession] - >>> dispatch response: null

tmrobert8 · December 30, 2016, 6:25pm

Shoot - you downloaded before I fixed that error (was fixing some stuff that Kai pointed out). Can you redownload and try again…

tmrobert8 · December 30, 2016, 6:26pm

Actually - don’t worry about redownloading yet - that log gave me some good info

Tomtibo · December 30, 2016, 6:32pm

Ok nice! Just let me know went it’s ready for me to test!

tmrobert8 · December 30, 2016, 6:35pm

Go ahead and download again (I’m removing the download message and replacing it each time - so that one message should always be the source [I am updating the count on it so you know I’ve done something]). BTW - if you have controller channels setup, they will no longer be found and you should remove them (Kai is asking me to change some of the channels into properties - the controller I’ve already done).

Tomtibo · December 30, 2016, 6:43pm

The log have changed but always with null reponse.

13:38:42.763 [DEBUG] [.russound.internal.net.SocketSession] - >>> dispatch response: null
13:38:42.798 [DEBUG] [.russound.internal.net.SocketSession] - >>> waiting for read response
13:38:43.765 [DEBUG] [.russound.internal.net.SocketSession] - >>> dispatch response: null
13:38:43.801 [DEBUG] [.russound.internal.net.SocketSession] - >>> waiting for read response

tmrobert8 · December 30, 2016, 6:48pm

Could you post more of the log (those two messages are expected [and should repeat quite a bit])