-- Logs begin at Thu 2019-02-14 10:11:59 GMT, end at Sun 2024-05-12 22:13:44 BST. -- May 12 22:12:07 minidsp-shd volumio[959]: STREAMING PROXY: Client dropped request, destroying May 12 22:12:42 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:12:42 minidsp-shd volumio[959]: info: msSurfaceDial volumioupdatevolume callback: {"vol":71,"dbVolume":-37.5,"mute":false,"disableVolumeControl":false} May 12 22:12:42 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:12:42 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:12:42 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:12:42 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:12:42 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:12:42 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume May 12 22:12:42 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 71 May 12 22:12:42 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 69 May 12 22:12:42 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 71 May 12 22:12:42 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: true May 12 22:12:42 minidsp-shd volumio[959]: info: Setting Spotify Volume from Volumio: 71 May 12 22:12:43 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:12:43 minidsp-shd volumio[959]: info: msSurfaceDial volumioupdatevolume callback: {"vol":71,"dbVolume":-36.5,"mute":false,"disableVolumeControl":false} May 12 22:12:43 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:12:43 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:12:43 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:12:43 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:12:43 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:12:43 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume May 12 22:12:43 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 71 May 12 22:12:43 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:12:43 minidsp-shd volumio[959]: info: msSurfaceDial volumioupdatevolume callback: {"vol":73,"dbVolume":-35,"mute":false,"disableVolumeControl":false} May 12 22:12:43 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:12:43 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:12:43 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:12:43 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:12:43 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:12:43 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume May 12 22:12:43 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:12:43 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 71 May 12 22:12:43 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 73 May 12 22:12:43 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: true May 12 22:12:43 minidsp-shd volumio[959]: info: Setting Spotify Volume from Volumio: 73 May 12 22:12:44 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:12:44 minidsp-shd volumio[959]: info: msSurfaceDial volumioupdatevolume callback: {"vol":73,"dbVolume":-34.5,"mute":false,"disableVolumeControl":false} May 12 22:12:44 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:12:44 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:12:44 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:12:44 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:12:44 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:12:44 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume May 12 22:12:44 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:12:44 minidsp-shd volumio[959]: SPOTIFY: SETTING SPOTIFY VOLUME 73 May 12 22:12:44 minidsp-shd volumio[959]: info: Sending Spotify command with payload to local API: /player/volume May 12 22:12:45 minidsp-shd go-librespot[1329]: time="2024-05-12T22:12:45+01:00" level=debug msg="update volume to 47840/65535" May 12 22:12:45 minidsp-shd go-librespot[1329]: time="2024-05-12T22:12:45+01:00" level=debug msg="put connect state because VOLUME_CHANGED" May 12 22:12:45 minidsp-shd go-librespot[1329]: time="2024-05-12T22:12:45+01:00" level=trace msg="emitting websocket event: volume" May 12 22:12:45 minidsp-shd volumio[959]: SPOTIFY: received: {"type":"volume","data":{"value":73,"max":100}} May 12 22:12:45 minidsp-shd volumio[959]: SPOTIFY: RECEIVED SPOTIFY VOLUME 73 May 12 22:12:52 minidsp-shd volumio[959]: info: May 12 22:12:52 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:12:52 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:12:52 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:12:52 minidsp-shd volumio[959]: info: May 12 22:12:52 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:12:52 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:12:52 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:12:52 minidsp-shd volumio[959]: info: May 12 22:12:52 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:12:52 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:12:52 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:12:52 minidsp-shd volumio[959]: info: sendMpdCommand status took 7 milliseconds May 12 22:12:52 minidsp-shd volumio[959]: info: sendMpdCommand status took 5 milliseconds May 12 22:12:52 minidsp-shd volumio[959]: info: sendMpdCommand status took 3 milliseconds May 12 22:12:52 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:12:52 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:12:52 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:12:52 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:12:52 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:12:52 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:12:52 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:12:52 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:12:52 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:12:52 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:12:52 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:12:52 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 12 22:12:52 minidsp-shd volumio[959]: verbose: CURRENT POSITION 18 May 12 22:12:52 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService stop May 12 22:12:52 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:12:52 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:12:52 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:12:52 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:12:52 minidsp-shd volumio[959]: info: CoreStateMachine::stPlaybackTimer May 12 22:12:52 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:12:52 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:12:52 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:12:52 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:12:52 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:12:52 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:12:52 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:12:52 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:12:52 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 12 22:12:52 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:12:52 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService stop May 12 22:12:52 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus stop May 12 22:12:52 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:12:52 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:12:52 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:12:52 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:12:52 minidsp-shd volumio[959]: info: No code May 12 22:12:52 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:12:52 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:12:52 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:12:52 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:12:52 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:12:52 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:12:52 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:12:52 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:12:52 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:12:52 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:12:52 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:12:52 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 12 22:12:52 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:12:52 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService stop May 12 22:12:52 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus stop May 12 22:12:52 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:12:52 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:12:52 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:12:52 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:12:52 minidsp-shd volumio[959]: info: No code May 12 22:12:52 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:12:52 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:12:52 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:12:52 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:12:52 minidsp-shd volumio[959]: info: ------------------------------ 67ms May 12 22:12:52 minidsp-shd volumio[959]: info: ------------------------------ 65ms May 12 22:12:52 minidsp-shd volumio[959]: info: ------------------------------ 64ms May 12 22:12:52 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:12:52 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:12:52 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:12:52 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:12:52 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:12:52 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:12:52 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:12:52 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:12:55 minidsp-shd volumio[959]: verbose: New Socket.io Connection to 192.168.1.209 from 192.168.1.94 UA: unknown Total Clients: 7 May 12 22:12:56 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:12:56 minidsp-shd volumio[959]: verbose: New Socket.io Connection to 192.168.1.210 from 192.168.1.94 UA: unknown Total Clients: 8 May 12 22:12:56 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 12 22:12:56 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 12 22:12:56 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:12:56 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 12 22:12:56 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 12 22:12:56 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 12 22:12:56 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 12 22:12:56 minidsp-shd volumio[959]: info: Discovery: Getting this device information May 12 22:12:56 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:12:56 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 12 22:12:56 minidsp-shd volumio[959]: verbose: New Socket.io Connection to 192.168.1.209 from 192.168.1.94 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Total Clients: 9 May 12 22:12:56 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 12 22:12:56 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 12 22:12:56 minidsp-shd volumio[959]: info: Discovery: Getting this device information May 12 22:12:56 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:12:56 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 12 22:12:59 minidsp-shd sudo[10273]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 12 22:12:59 minidsp-shd sudo[10273]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 22:12:59 minidsp-shd sudo[10273]: pam_unix(sudo:session): session closed for user root May 12 22:12:59 minidsp-shd sudo[10276]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 12 22:12:59 minidsp-shd sudo[10276]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 22:12:59 minidsp-shd sudo[10276]: pam_unix(sudo:session): session closed for user root May 12 22:12:59 minidsp-shd volumio[959]: verbose: New Socket.io Connection to 192.168.1.209 from 192.168.1.94 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Total Clients: 10 May 12 22:12:59 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 12 22:12:59 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 12 22:12:59 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetVisibleSources May 12 22:12:59 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 12 22:12:59 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:12:59 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 12 22:12:59 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 12 22:12:59 minidsp-shd volumio[959]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom May 12 22:12:59 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri May 12 22:12:59 minidsp-shd volumio[959]: info: Received Get System Info May 12 22:12:59 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 12 22:12:59 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 12 22:12:59 minidsp-shd volumio[959]: info: Discovery: Getting this device information May 12 22:12:59 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:12:59 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 12 22:12:59 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:12:59 minidsp-shd volumio[959]: info: Listing playlists May 12 22:12:59 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 12 22:12:59 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 12 22:12:59 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 12 22:13:00 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:13:00 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 12 22:13:00 minidsp-shd volumio[959]: info: Received Get System Info May 12 22:13:00 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 12 22:13:00 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 12 22:13:00 minidsp-shd volumio[959]: info: Discovery: Getting this device information May 12 22:13:00 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:13:00 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 12 22:13:01 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 12 22:13:01 minidsp-shd volumio[959]: info: Received Get System Info May 12 22:13:01 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 12 22:13:01 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 12 22:13:01 minidsp-shd volumio[959]: info: Discovery: Getting this device information May 12 22:13:01 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:13:01 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 12 22:13:02 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPlay May 12 22:13:02 minidsp-shd volumio[959]: info: CoreStateMachine::play index undefined May 12 22:13:02 minidsp-shd volumio[959]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 22:13:02 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:02 minidsp-shd volumio[959]: info: CoreStateMachine::startPlaybackTimer May 12 22:13:02 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:02 minidsp-shd volumio[959]: info: [1715548382135] ControllerQobuz::clearAddPlayTrack May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand stop May 12 22:13:02 minidsp-shd volumio[959]: info: sendMpdCommand stop took 2 milliseconds May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand clear May 12 22:13:02 minidsp-shd volumio[959]: info: May 12 22:13:02 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:02 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:02 minidsp-shd volumio[959]: info: sendMpdCommand clear took 2 milliseconds May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/61861999" May 12 22:13:02 minidsp-shd volumio[959]: error: updateQueue error: null May 12 22:13:02 minidsp-shd volumio[959]: info: ------------------------------ 4ms May 12 22:13:02 minidsp-shd volumio[959]: STREAMING PROXY: Handling url /?data=qobuz://song/61861999 May 12 22:13:02 minidsp-shd volumio[959]: info: May 12 22:13:02 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:02 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:02 minidsp-shd volumio[959]: info: May 12 22:13:02 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:02 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:02 minidsp-shd volumio[959]: info: Executing endpoint getStreamUrlqobuz May 12 22:13:02 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI May 12 22:13:02 minidsp-shd volumio[959]: info: Executing endpoint metavolumio May 12 22:13:02 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 12 22:13:02 minidsp-shd volumio[959]: info: Executing endpoint metavolumio May 12 22:13:02 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 12 22:13:02 minidsp-shd volumio[959]: info: Executing endpoint metavolumio May 12 22:13:02 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 12 22:13:02 minidsp-shd volumio[959]: info: getStreamUrl took 312 milliseconds May 12 22:13:02 minidsp-shd volumio[959]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1781393&eid=61861999&fmt=7&profile=raw&app_id=539451548&cid=1211282&etsp=1715551982&hmac=34hbH59fDH0AKXOGeesDNgynaSU May 12 22:13:02 minidsp-shd volumio[959]: STREAMING PROXY: Response: 200, length: 57251908 May 12 22:13:02 minidsp-shd volumio[959]: STREAMING PROXY: Client dropped request, destroying May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/61861999" May 12 22:13:02 minidsp-shd volumio[959]: error: updateQueue error: null May 12 22:13:02 minidsp-shd volumio[959]: error: updateQueue error: null May 12 22:13:02 minidsp-shd volumio[959]: info: May 12 22:13:02 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:02 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:02 minidsp-shd volumio[959]: info: ------------------------------ 403ms May 12 22:13:02 minidsp-shd volumio[959]: info: ------------------------------ 401ms May 12 22:13:02 minidsp-shd volumio[959]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/61861999" took 2 milliseconds May 12 22:13:02 minidsp-shd volumio[959]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand play May 12 22:13:02 minidsp-shd volumio[959]: info: May 12 22:13:02 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:02 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:02 minidsp-shd volumio[959]: STREAMING PROXY: Handling url /?data=qobuz://song/61861999 May 12 22:13:02 minidsp-shd volumio[959]: info: May 12 22:13:02 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:02 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:02 minidsp-shd volumio[959]: info: ------------------------------ 9ms May 12 22:13:02 minidsp-shd volumio[959]: info: sendMpdCommand play took 9 milliseconds May 12 22:13:02 minidsp-shd volumio[959]: info: ------------------------------ 6ms May 12 22:13:02 minidsp-shd volumio[959]: info: ------------------------------ 5ms May 12 22:13:02 minidsp-shd volumio[959]: info: Executing endpoint getStreamUrlqobuz May 12 22:13:02 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI May 12 22:13:02 minidsp-shd volumio[959]: info: getStreamUrl took 281 milliseconds May 12 22:13:02 minidsp-shd volumio[959]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1781393&eid=61861999&fmt=7&profile=raw&app_id=539451548&cid=1211282&etsp=1715551982&hmac=34hbH59fDH0AKXOGeesDNgynaSU May 12 22:13:02 minidsp-shd volumio[959]: STREAMING PROXY: Response: 200, length: 57251908 May 12 22:13:02 minidsp-shd volumio[959]: info: May 12 22:13:02 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:02 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:02 minidsp-shd volumio[959]: info: May 12 22:13:02 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:02 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:02 minidsp-shd volumio[959]: info: May 12 22:13:02 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:02 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:02 minidsp-shd volumio[959]: info: May 12 22:13:02 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:02 minidsp-shd volumio[959]: info: sendMpdCommand status took 10 milliseconds May 12 22:13:02 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:02 minidsp-shd volumio[959]: info: sendMpdCommand status took 8 milliseconds May 12 22:13:02 minidsp-shd volumio[959]: info: sendMpdCommand status took 6 milliseconds May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:02 minidsp-shd volumio[959]: info: May 12 22:13:02 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:02 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:02 minidsp-shd volumio[959]: info: May 12 22:13:02 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:02 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:02 minidsp-shd volumio[959]: info: sendMpdCommand status took 16 milliseconds May 12 22:13:02 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 14 milliseconds May 12 22:13:02 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 14 milliseconds May 12 22:13:02 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 13 milliseconds May 12 22:13:02 minidsp-shd volumio[959]: info: sendMpdCommand status took 10 milliseconds May 12 22:13:02 minidsp-shd volumio[959]: info: sendMpdCommand status took 7 milliseconds May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:02 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:02 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:02 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:02 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:02 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":314,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"61861999","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61861999","trackType":"qobuz"} May 12 22:13:02 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:02 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:02 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus stop May 12 22:13:02 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:02 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:02 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:02 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":314,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"61861999","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61861999","trackType":"qobuz"} May 12 22:13:02 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:02 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:02 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:02 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:02 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:02 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:02 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:02 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:02 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:02 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:02 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:02 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:02 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:02 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:02 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:02 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:02 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":314,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"61861999","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61861999","trackType":"qobuz"} May 12 22:13:02 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:02 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:02 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:02 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:02 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:02 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:02 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:02 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:02 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:02 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:02 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:02 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:02 minidsp-shd volumio[959]: info: ------------------------------ 88ms May 12 22:13:02 minidsp-shd volumio[959]: info: ------------------------------ 97ms May 12 22:13:03 minidsp-shd volumio[959]: info: ------------------------------ 96ms May 12 22:13:03 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 71 milliseconds May 12 22:13:03 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 70 milliseconds May 12 22:13:03 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 70 milliseconds May 12 22:13:03 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:03 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:03 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:03 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:03 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:03 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:03 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":314,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"61861999","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61861999","trackType":"qobuz"} May 12 22:13:03 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:03 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:03 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:03 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:03 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:03 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:03 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:03 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:03 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:03 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:03 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:03 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:03 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:03 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:03 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:03 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":320,"duration":314,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1530 Kbps","isStreaming":false,"title":"61861999","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61861999","trackType":"qobuz"} May 12 22:13:03 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:03 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:03 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:03 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:03 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:03 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:03 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:03 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:03 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:03 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:03 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:03 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:03 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:03 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:03 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:03 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:03 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":314,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1451 Kbps","isStreaming":false,"title":"61861999","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61861999","trackType":"qobuz"} May 12 22:13:03 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:03 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:03 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:03 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:03 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:03 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:03 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:03 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:03 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:03 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:03 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:03 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:03 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:03 minidsp-shd volumio[959]: info: ------------------------------ 161ms May 12 22:13:03 minidsp-shd volumio[959]: info: ------------------------------ 153ms May 12 22:13:03 minidsp-shd volumio[959]: info: ------------------------------ 151ms May 12 22:13:03 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:13:03 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:13:03 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:13:03 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:13:03 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:13:03 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:13:03 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:13:03 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:13:03 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:13:03 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:13:05 minidsp-shd volumio[959]: info: Executing endpoint metavolumio May 12 22:13:05 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 12 22:13:05 minidsp-shd volumio[959]: info: Executing endpoint metavolumio May 12 22:13:05 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 12 22:13:05 minidsp-shd volumio[959]: info: Executing endpoint metavolumio May 12 22:13:05 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 12 22:13:05 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:13:05 minidsp-shd volumio[959]: info: msSurfaceDial volumioupdatevolume callback: {"vol":73,"dbVolume":-35,"mute":false,"disableVolumeControl":false} May 12 22:13:05 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:05 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:05 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:05 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:05 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:05 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume May 12 22:13:05 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 73 May 12 22:13:05 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:13:05 minidsp-shd volumio[959]: info: msSurfaceDial volumioupdatevolume callback: {"vol":72,"dbVolume":-36,"mute":false,"disableVolumeControl":false} May 12 22:13:05 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:05 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:05 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:05 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:05 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:05 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume May 12 22:13:05 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:05 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:05 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:05 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:06 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPause May 12 22:13:06 minidsp-shd volumio[959]: info: CoreStateMachine::pause May 12 22:13:06 minidsp-shd volumio[959]: info: CoreStateMachine::stPlaybackTimer May 12 22:13:06 minidsp-shd volumio[959]: info: CoreStateMachine::servicePause May 12 22:13:06 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:06 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePause May 12 22:13:06 minidsp-shd volumio[959]: info: [1715548386202] ControllerQobuz::pause May 12 22:13:06 minidsp-shd volumio[959]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 22:13:06 minidsp-shd volumio[959]: info: ControllerMpd::pause May 12 22:13:06 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand pause May 12 22:13:06 minidsp-shd volumio[959]: info: sendMpdCommand pause took 2 milliseconds May 12 22:13:06 minidsp-shd volumio[959]: info: May 12 22:13:06 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:06 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:06 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:06 minidsp-shd volumio[959]: info: May 12 22:13:06 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:06 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:06 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:06 minidsp-shd volumio[959]: info: May 12 22:13:06 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:06 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:06 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:06 minidsp-shd volumio[959]: info: sendMpdCommand status took 9 milliseconds May 12 22:13:06 minidsp-shd volumio[959]: info: sendMpdCommand status took 6 milliseconds May 12 22:13:06 minidsp-shd volumio[959]: info: sendMpdCommand status took 4 milliseconds May 12 22:13:06 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:06 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:06 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:06 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:06 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:06 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:06 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 5 milliseconds May 12 22:13:06 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 5 milliseconds May 12 22:13:06 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 5 milliseconds May 12 22:13:06 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:06 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:06 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:06 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:06 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:06 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:06 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":4605,"duration":314,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1317 Kbps","isStreaming":false,"title":"61861999","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61861999","trackType":"qobuz"} May 12 22:13:06 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:06 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService pause May 12 22:13:06 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus pause May 12 22:13:06 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:06 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:06 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:06 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:06 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:06 minidsp-shd volumio[959]: info: CoreStateMachine::stPlaybackTimer May 12 22:13:06 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:06 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:06 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:06 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":4605,"duration":314,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1317 Kbps","isStreaming":false,"title":"61861999","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61861999","trackType":"qobuz"} May 12 22:13:06 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:06 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService pause May 12 22:13:06 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus pause May 12 22:13:06 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:06 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:06 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:06 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:06 minidsp-shd volumio[959]: info: CoreStateMachine::stPlaybackTimer May 12 22:13:06 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:06 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:06 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:06 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":4605,"duration":314,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1317 Kbps","isStreaming":false,"title":"61861999","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61861999","trackType":"qobuz"} May 12 22:13:06 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:06 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService pause May 12 22:13:06 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus pause May 12 22:13:06 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:06 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:06 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:06 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:06 minidsp-shd volumio[959]: info: CoreStateMachine::stPlaybackTimer May 12 22:13:06 minidsp-shd volumio[959]: info: ------------------------------ 68ms May 12 22:13:06 minidsp-shd volumio[959]: info: ------------------------------ 65ms May 12 22:13:06 minidsp-shd volumio[959]: info: ------------------------------ 62ms May 12 22:13:06 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:06 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:06 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:06 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:06 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:06 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:06 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:06 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:06 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:06 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:06 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:06 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:07 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetQueue May 12 22:13:07 minidsp-shd volumio[959]: info: CoreStateMachine::getQueue May 12 22:13:07 minidsp-shd volumio[959]: info: CorePlayQueue::getQueue May 12 22:13:08 minidsp-shd volumio[959]: STREAMING PROXY: Client dropped request, destroying May 12 22:13:09 minidsp-shd volumio[959]: error: Failed request for metavolumio API May 12 22:13:12 minidsp-shd volumio[959]: error: Failed request for metavolumio API May 12 22:13:12 minidsp-shd volumio[959]: error: Failed request for metavolumio API May 12 22:13:12 minidsp-shd volumio[959]: error: Failed request for metavolumio API May 12 22:13:14 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri May 12 22:13:15 minidsp-shd volumio[959]: info: handleBrowseUri took 344 milliseconds May 12 22:13:15 minidsp-shd volumio[959]: info: Preload queue cleared May 12 22:13:15 minidsp-shd volumio[959]: info: Executing endpoint getSimilarAlbums May 12 22:13:15 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums May 12 22:13:15 minidsp-shd volumio[959]: info: Executing endpoint metavolumio May 12 22:13:15 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 12 22:13:15 minidsp-shd volumio[959]: info: Executing endpoint metavolumio May 12 22:13:15 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 12 22:13:17 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 12 22:13:17 minidsp-shd volumio[959]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 12 22:13:17 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 12 22:13:17 minidsp-shd volumio[959]: info: Received Get System Version May 12 22:13:17 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 12 22:13:17 minidsp-shd volumio[959]: info: Received Get System Info May 12 22:13:17 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 12 22:13:17 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 12 22:13:17 minidsp-shd volumio[959]: info: Discovery: Getting this device information May 12 22:13:17 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:13:17 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 12 22:13:18 minidsp-shd volumio[959]: info: Preload queue cleared May 12 22:13:18 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioAddQueueItems May 12 22:13:18 minidsp-shd volumio[959]: info: CoreStateMachine::addQueueItems May 12 22:13:18 minidsp-shd volumio[959]: info: CorePlayQueue::addQueueItems May 12 22:13:18 minidsp-shd volumio[959]: info: Preload queue cleared May 12 22:13:18 minidsp-shd volumio[959]: info: Adding Item to queue: qobuz://song/17131183 May 12 22:13:18 minidsp-shd volumio[959]: info: Using cached record of: qobuz://song/17131183 May 12 22:13:18 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushQueue May 12 22:13:18 minidsp-shd volumio[959]: info: CorePlayQueue::saveQueue May 12 22:13:18 minidsp-shd volumio[959]: info: CoreStateMachine::updateTrackBlock May 12 22:13:18 minidsp-shd volumio[959]: info: CorePlayQueue::getTrackBlock May 12 22:13:18 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPlay May 12 22:13:18 minidsp-shd volumio[959]: info: CoreStateMachine::play index 18 May 12 22:13:18 minidsp-shd volumio[959]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 22:13:18 minidsp-shd volumio[959]: info: CoreStateMachine::stop May 12 22:13:18 minidsp-shd volumio[959]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 22:13:18 minidsp-shd volumio[959]: info: CoreStateMachine::updateTrackBlock May 12 22:13:18 minidsp-shd volumio[959]: info: CorePlayQueue::getTrackBlock May 12 22:13:18 minidsp-shd volumio[959]: info: CoreStateMachine::stPlaybackTimer May 12 22:13:18 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:18 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:18 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:18 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:18 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:18 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:18 minidsp-shd volumio[959]: info: CoreStateMachine::serviceStop May 12 22:13:18 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:18 minidsp-shd volumio[959]: info: CoreCommandRouter::serviceStop May 12 22:13:18 minidsp-shd volumio[959]: info: [1715548398515] ControllerQobuz::stop May 12 22:13:18 minidsp-shd volumio[959]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 22:13:18 minidsp-shd volumio[959]: info: ControllerMpd::stop May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand stop May 12 22:13:18 minidsp-shd volumio[959]: info: May 12 22:13:18 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:18 minidsp-shd volumio[959]: info: sendMpdCommand stop took 16 milliseconds May 12 22:13:18 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:18 minidsp-shd volumio[959]: info: CoreStateMachine::play index undefined May 12 22:13:18 minidsp-shd volumio[959]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 22:13:18 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:18 minidsp-shd volumio[959]: info: CoreStateMachine::startPlaybackTimer May 12 22:13:18 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:18 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetVisibleSources May 12 22:13:18 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 12 22:13:18 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 12 22:13:18 minidsp-shd volumio[959]: info: [1715548398534] ControllerQobuz::clearAddPlayTrack May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand stop May 12 22:13:18 minidsp-shd volumio[959]: info: May 12 22:13:18 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:18 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:18 minidsp-shd volumio[959]: info: May 12 22:13:18 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:18 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:18 minidsp-shd volumio[959]: info: sendMpdCommand status took 14 milliseconds May 12 22:13:18 minidsp-shd volumio[959]: info: sendMpdCommand stop took 10 milliseconds May 12 22:13:18 minidsp-shd volumio[959]: info: sendMpdCommand status took 7 milliseconds May 12 22:13:18 minidsp-shd volumio[959]: info: sendMpdCommand status took 7 milliseconds May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand clear May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:18 minidsp-shd volumio[959]: info: May 12 22:13:18 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:18 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:18 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 6 milliseconds May 12 22:13:18 minidsp-shd volumio[959]: info: sendMpdCommand clear took 5 milliseconds May 12 22:13:18 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 6 milliseconds May 12 22:13:18 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 6 milliseconds May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/17131183" May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:18 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:18 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:18 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:18 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:18 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:18 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:18 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:18 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:18 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:18 minidsp-shd volumio[959]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd May 12 22:13:18 minidsp-shd volumio[959]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 12 22:13:18 minidsp-shd volumio[959]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 12 22:13:18 minidsp-shd volumio[959]: STREAMING PROXY: Handling url /?data=qobuz://song/17131183 May 12 22:13:18 minidsp-shd volumio[959]: info: ------------------------------ 51ms May 12 22:13:18 minidsp-shd volumio[959]: info: ------------------------------ 44ms May 12 22:13:18 minidsp-shd volumio[959]: info: ------------------------------ 42ms May 12 22:13:18 minidsp-shd volumio[959]: info: May 12 22:13:18 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:18 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:18 minidsp-shd volumio[959]: info: May 12 22:13:18 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:18 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:18 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:18 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:18 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:18 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:18 minidsp-shd volumio[959]: error: updateQueue error: null May 12 22:13:18 minidsp-shd volumio[959]: info: ------------------------------ 47ms May 12 22:13:18 minidsp-shd volumio[959]: info: Executing endpoint getStreamUrlqobuz May 12 22:13:18 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI May 12 22:13:18 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:18 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:18 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:18 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:18 minidsp-shd volumio[959]: info: getStreamUrl took 276 milliseconds May 12 22:13:18 minidsp-shd volumio[959]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1781393&eid=17131183&fmt=7&profile=raw&app_id=539451548&cid=1211282&etsp=1715551998&hmac=_vP3fi4CU8nurNPGC_3phIgQP_o May 12 22:13:18 minidsp-shd volumio[959]: STREAMING PROXY: Response: 200, length: 165841360 May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/17131183" May 12 22:13:18 minidsp-shd volumio[959]: error: updateQueue error: null May 12 22:13:18 minidsp-shd volumio[959]: error: updateQueue error: null May 12 22:13:18 minidsp-shd volumio[959]: info: May 12 22:13:18 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:18 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:18 minidsp-shd volumio[959]: info: ------------------------------ 333ms May 12 22:13:18 minidsp-shd volumio[959]: info: ------------------------------ 332ms May 12 22:13:18 minidsp-shd volumio[959]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/17131183" took 4 milliseconds May 12 22:13:18 minidsp-shd volumio[959]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 22:13:18 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand play May 12 22:13:18 minidsp-shd volumio[959]: STREAMING PROXY: Client dropped request, destroying May 12 22:13:18 minidsp-shd volumio[959]: info: May 12 22:13:18 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:18 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:18 minidsp-shd volumio[959]: info: May 12 22:13:18 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:18 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:18 minidsp-shd volumio[959]: info: ------------------------------ 10ms May 12 22:13:18 minidsp-shd volumio[959]: STREAMING PROXY: Handling url /?data=qobuz://song/17131183 May 12 22:13:18 minidsp-shd volumio[959]: info: sendMpdCommand play took 9 milliseconds May 12 22:13:18 minidsp-shd volumio[959]: info: ------------------------------ 5ms May 12 22:13:18 minidsp-shd volumio[959]: info: ------------------------------ 3ms May 12 22:13:18 minidsp-shd volumio[959]: info: Executing endpoint getStreamUrlqobuz May 12 22:13:18 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI May 12 22:13:19 minidsp-shd volumio[959]: info: getStreamUrl took 311 milliseconds May 12 22:13:19 minidsp-shd volumio[959]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1781393&eid=17131183&fmt=7&profile=raw&app_id=539451548&cid=1211282&etsp=1715551999&hmac=HIunM7gNN882jrnkHt9JAuqC4vw May 12 22:13:19 minidsp-shd volumio[959]: STREAMING PROXY: Response: 200, length: 165841360 May 12 22:13:19 minidsp-shd volumio[959]: info: May 12 22:13:19 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:19 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:19 minidsp-shd volumio[959]: info: May 12 22:13:19 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:19 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:19 minidsp-shd volumio[959]: info: May 12 22:13:19 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:19 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:19 minidsp-shd volumio[959]: info: May 12 22:13:19 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:19 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:19 minidsp-shd volumio[959]: info: sendMpdCommand status took 15 milliseconds May 12 22:13:19 minidsp-shd volumio[959]: info: sendMpdCommand status took 11 milliseconds May 12 22:13:19 minidsp-shd volumio[959]: info: sendMpdCommand status took 11 milliseconds May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:19 minidsp-shd volumio[959]: info: May 12 22:13:19 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:19 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:19 minidsp-shd volumio[959]: info: May 12 22:13:19 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:19 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:19 minidsp-shd volumio[959]: info: sendMpdCommand status took 22 milliseconds May 12 22:13:19 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 13 milliseconds May 12 22:13:19 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 13 milliseconds May 12 22:13:19 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 12 milliseconds May 12 22:13:19 minidsp-shd volumio[959]: info: sendMpdCommand status took 9 milliseconds May 12 22:13:19 minidsp-shd volumio[959]: info: sendMpdCommand status took 7 milliseconds May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:19 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:19 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:19 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":494,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:19 minidsp-shd volumio[959]: verbose: CURRENT POSITION 18 May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus stop May 12 22:13:19 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:19 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:19 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":494,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:19 minidsp-shd volumio[959]: verbose: CURRENT POSITION 18 May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:19 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:19 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:19 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:19 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":494,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:19 minidsp-shd volumio[959]: verbose: CURRENT POSITION 18 May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:19 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:19 minidsp-shd volumio[959]: info: ------------------------------ 100ms May 12 22:13:19 minidsp-shd volumio[959]: info: ------------------------------ 113ms May 12 22:13:19 minidsp-shd volumio[959]: info: ------------------------------ 110ms May 12 22:13:19 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 80 milliseconds May 12 22:13:19 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 78 milliseconds May 12 22:13:19 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 79 milliseconds May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:19 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:19 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:19 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:19 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1097,"duration":494,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2336 Kbps","isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:19 minidsp-shd volumio[959]: verbose: CURRENT POSITION 18 May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:19 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:19 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:19 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:19 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1118,"duration":494,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2333 Kbps","isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:19 minidsp-shd volumio[959]: verbose: CURRENT POSITION 18 May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:19 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:19 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:19 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:19 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1118,"duration":494,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2343 Kbps","isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:19 minidsp-shd volumio[959]: verbose: CURRENT POSITION 18 May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:19 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:19 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:19 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:19 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:19 minidsp-shd volumio[959]: info: ------------------------------ 190ms May 12 22:13:19 minidsp-shd volumio[959]: info: ------------------------------ 176ms May 12 22:13:19 minidsp-shd volumio[959]: info: ------------------------------ 175ms May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:19 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:21 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetState May 12 22:13:21 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioSeek May 12 22:13:21 minidsp-shd volumio[959]: info: CoreStateMachine::seek May 12 22:13:21 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:21 minidsp-shd volumio[959]: info: TRACKBLOCK {"uri":"qobuz://song/17131183","service":"qobuz","name":"\"Adina credimi...Fra lieti concenti\"","title":"\"Adina credimi...Fra lieti concenti\"","album":"Donizetti: L'Elisir d'Amore","type":"track","tracknumber":17,"volumeNumber":1,"albumart":"https://static.qobuz.com/images/covers/80/65/0002894786580_600.jpg","duration":493,"explicit":false,"artist":"Luciano Pavarotti","artistUri":"qobuz://artist/16292","albumUri":"qobuz://album/0002894786580","audioQuality":"","tagImage":""} May 12 22:13:21 minidsp-shd volumio[959]: info: CoreStateMachine::startPlaybackTimer May 12 22:13:21 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:21 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetVisibleSources May 12 22:13:21 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 12 22:13:21 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 12 22:13:21 minidsp-shd volumio[959]: info: [1715548401965] ControllerQobuz::seek May 12 22:13:21 minidsp-shd volumio[959]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 22:13:21 minidsp-shd volumio[959]: info: ControllerMpd::seek May 12 22:13:21 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:21 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:21 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:21 minidsp-shd volumio[959]: STREAMING PROXY: Client dropped request, destroying May 12 22:13:21 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:21 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:21 minidsp-shd volumio[959]: STREAMING PROXY: Handling url /?data=qobuz://song/17131183 May 12 22:13:21 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:21 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:21 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:21 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:22 minidsp-shd volumio[959]: info: Executing endpoint getStreamUrlqobuz May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI May 12 22:13:22 minidsp-shd volumio[959]: info: getStreamUrl took 265 milliseconds May 12 22:13:22 minidsp-shd volumio[959]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1781393&eid=17131183&fmt=7&profile=raw&app_id=539451548&cid=1211282&etsp=1715552002&hmac=mtZcw-B3zZsgZcoDc1tu3oqS3Ag May 12 22:13:22 minidsp-shd volumio[959]: STREAMING PROXY: Got range request: bytes=8338222- May 12 22:13:22 minidsp-shd volumio[959]: STREAMING PROXY: Response: 206, length: 157503138 May 12 22:13:22 minidsp-shd volumio[959]: error: null May 12 22:13:22 minidsp-shd volumio[959]: info: May 12 22:13:22 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:22 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:22 minidsp-shd volumio[959]: info: May 12 22:13:22 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:22 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:22 minidsp-shd volumio[959]: info: May 12 22:13:22 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:22 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:22 minidsp-shd volumio[959]: info: sendMpdCommand status took 10 milliseconds May 12 22:13:22 minidsp-shd volumio[959]: info: sendMpdCommand status took 7 milliseconds May 12 22:13:22 minidsp-shd volumio[959]: info: sendMpdCommand status took 5 milliseconds May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:22 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 6 milliseconds May 12 22:13:22 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 5 milliseconds May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:22 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:22 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:22 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":26000,"duration":494,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2734 Kbps","isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:22 minidsp-shd volumio[959]: verbose: CURRENT POSITION 18 May 12 22:13:22 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:22 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:22 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:22 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:22 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:22 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:22 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:22 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:22 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:22 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:22 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:22 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":26000,"duration":494,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2734 Kbps","isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:22 minidsp-shd volumio[959]: verbose: CURRENT POSITION 18 May 12 22:13:22 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:22 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:22 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:22 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:22 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:22 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:22 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:22 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:22 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:22 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:22 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:22 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":26000,"duration":494,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"2734 Kbps","isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:22 minidsp-shd volumio[959]: verbose: CURRENT POSITION 18 May 12 22:13:22 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:22 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:22 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:22 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:22 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:22 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:22 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:22 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:22 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:22 minidsp-shd volumio[959]: info: ------------------------------ 109ms May 12 22:13:22 minidsp-shd volumio[959]: info: ------------------------------ 106ms May 12 22:13:22 minidsp-shd volumio[959]: info: ------------------------------ 105ms May 12 22:13:22 minidsp-shd volumio[959]: error: Failed request for metavolumio API May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioSeek May 12 22:13:22 minidsp-shd volumio[959]: info: CoreStateMachine::seek May 12 22:13:22 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:22 minidsp-shd volumio[959]: info: TRACKBLOCK {"uri":"qobuz://song/17131183","service":"qobuz","name":"\"Adina credimi...Fra lieti concenti\"","title":"\"Adina credimi...Fra lieti concenti\"","album":"Donizetti: L'Elisir d'Amore","type":"track","tracknumber":17,"volumeNumber":1,"albumart":"https://static.qobuz.com/images/covers/80/65/0002894786580_600.jpg","duration":493,"explicit":false,"artist":"Luciano Pavarotti","artistUri":"qobuz://artist/16292","albumUri":"qobuz://album/0002894786580","audioQuality":"","tagImage":""} May 12 22:13:22 minidsp-shd volumio[959]: info: CoreStateMachine::startPlaybackTimer May 12 22:13:22 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioGetVisibleSources May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 12 22:13:22 minidsp-shd volumio[959]: info: [1715548402621] ControllerQobuz::seek May 12 22:13:22 minidsp-shd volumio[959]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 22:13:22 minidsp-shd volumio[959]: info: ControllerMpd::seek May 12 22:13:22 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:22 minidsp-shd volumio[959]: STREAMING PROXY: Client dropped request, destroying May 12 22:13:22 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:22 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:22 minidsp-shd volumio[959]: STREAMING PROXY: Handling url /?data=qobuz://song/17131183 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:22 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:22 minidsp-shd volumio[959]: info: Executing endpoint getStreamUrlqobuz May 12 22:13:22 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI May 12 22:13:22 minidsp-shd volumio[959]: info: getStreamUrl took 281 milliseconds May 12 22:13:22 minidsp-shd volumio[959]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1781393&eid=17131183&fmt=7&profile=raw&app_id=539451548&cid=1211282&etsp=1715552002&hmac=mtZcw-B3zZsgZcoDc1tu3oqS3Ag May 12 22:13:22 minidsp-shd volumio[959]: STREAMING PROXY: Got range request: bytes=31783407- May 12 22:13:22 minidsp-shd volumio[959]: STREAMING PROXY: Error proxying request: Error: socket hang up May 12 22:13:22 minidsp-shd volumio[959]: STREAMING PROXY: Client dropped request, destroying May 12 22:13:22 minidsp-shd volumio[959]: error: [5@0] {seek} Decoder failed to seek May 12 22:13:22 minidsp-shd volumio[959]: info: May 12 22:13:22 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:22 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:22 minidsp-shd volumio[959]: info: May 12 22:13:22 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:22 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:22 minidsp-shd volumio[959]: info: May 12 22:13:22 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:22 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:22 minidsp-shd volumio[959]: info: May 12 22:13:22 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:22 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand clearerror May 12 22:13:22 minidsp-shd volumio[959]: info: sendMpdCommand status took 13 milliseconds May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand clearerror May 12 22:13:22 minidsp-shd volumio[959]: info: sendMpdCommand status took 12 milliseconds May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand clearerror May 12 22:13:22 minidsp-shd volumio[959]: info: sendMpdCommand status took 11 milliseconds May 12 22:13:22 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:23 minidsp-shd volumio[959]: info: May 12 22:13:23 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:23 minidsp-shd volumio[959]: info: May 12 22:13:23 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand clearerror May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand status took 24 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand clearerror took 19 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand clearerror took 18 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand clearerror took 16 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 12 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 12 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand status took 9 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand status took 6 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 18 May 12 22:13:23 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:23 minidsp-shd volumio[959]: verbose: CURRENT POSITION 18 May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService stop May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::stPlaybackTimer May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:23 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:23 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService stop May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus stop May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: No code May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:23 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:23 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService stop May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus stop May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: No code May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: ------------------------------ 105ms May 12 22:13:23 minidsp-shd volumio[959]: info: ------------------------------ 104ms May 12 22:13:23 minidsp-shd volumio[959]: info: ------------------------------ 102ms May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand clearerror took 88 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 84 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 84 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 84 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:23 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:23 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService stop May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus stop May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: No code May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:23 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:23 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService stop May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus stop May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: No code May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:23 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:23 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService stop May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus stop May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: No code May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: ------------------------------ 182ms May 12 22:13:23 minidsp-shd volumio[959]: info: ------------------------------ 167ms May 12 22:13:23 minidsp-shd volumio[959]: info: ------------------------------ 167ms May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioSeek May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::seek May 12 22:13:23 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:23 minidsp-shd volumio[959]: info: TRACKBLOCK {"uri":"qobuz://song/61861999","service":"qobuz","name":"Thank You (R.J. Reynolds)","title":"Thank You (R.J. Reynolds)","album":"Roadhouses & Automobiles","type":"track","tracknumber":2,"volumeNumber":1,"albumart":"https://static.qobuz.com/images/covers/gc/0l/yjjutf5bf0lgc_600.jpg","duration":313,"explicit":false,"artist":"Chris Jones","artistUri":"qobuz://artist/265697","albumUri":"qobuz://album/yjjutf5bf0lgc","audioQuality":"","tagImage":""} May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::startPlaybackTimer May 12 22:13:23 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:23 minidsp-shd volumio[959]: info: [1715548403316] ControllerQobuz::seek May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::seek May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: STREAMING PROXY: Handling url /?data=qobuz://song/17131183 May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: error: null May 12 22:13:23 minidsp-shd volumio[959]: info: Executing endpoint getStreamUrlqobuz May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: info: getStreamUrl took 323 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1781393&eid=17131183&fmt=7&profile=raw&app_id=539451548&cid=1211282&etsp=1715552003&hmac=ikKR8GnsudkYn6_I-eftnYU4wmw May 12 22:13:23 minidsp-shd volumio[959]: STREAMING PROXY: Response: 200, length: 165841360 May 12 22:13:23 minidsp-shd volumio[959]: info: May 12 22:13:23 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:23 minidsp-shd volumio[959]: STREAMING PROXY: Client dropped request, destroying May 12 22:13:23 minidsp-shd volumio[959]: info: May 12 22:13:23 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:23 minidsp-shd volumio[959]: info: May 12 22:13:23 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:23 minidsp-shd volumio[959]: STREAMING PROXY: Handling url /?data=qobuz://song/17131183 May 12 22:13:23 minidsp-shd volumio[959]: info: May 12 22:13:23 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand status took 9 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand status took 7 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand status took 5 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:23 minidsp-shd volumio[959]: info: May 12 22:13:23 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:23 minidsp-shd volumio[959]: info: May 12 22:13:23 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand status took 10 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 7 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 7 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 6 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand status took 5 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand status took 3 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:23 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:23 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":145000,"duration":494,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:23 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus stop May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:23 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:23 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":145000,"duration":494,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:23 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:23 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:23 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:23 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":145000,"duration":494,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:23 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:23 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: ------------------------------ 53ms May 12 22:13:23 minidsp-shd volumio[959]: info: ------------------------------ 58ms May 12 22:13:23 minidsp-shd volumio[959]: info: ------------------------------ 56ms May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 42 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 41 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 42 milliseconds May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:23 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:23 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:23 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":145000,"duration":494,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:23 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:23 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:23 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:23 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":145000,"duration":494,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:23 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:23 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:23 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:23 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":145000,"duration":494,"samplerate":"96 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"17131183","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/17131183","trackType":"qobuz"} May 12 22:13:23 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:23 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:23 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:23 minidsp-shd volumio[959]: info: ------------------------------ 93ms May 12 22:13:23 minidsp-shd volumio[959]: info: ------------------------------ 87ms May 12 22:13:23 minidsp-shd volumio[959]: info: ------------------------------ 86ms May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: info: Executing endpoint getStreamUrlqobuz May 12 22:13:23 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:23 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:24 minidsp-shd volumio[959]: info: getStreamUrl took 343 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1781393&eid=17131183&fmt=7&profile=raw&app_id=539451548&cid=1211282&etsp=1715552004&hmac=acbJ4BOv2ndFjIm1w95EiC4Sn5s May 12 22:13:24 minidsp-shd volumio[959]: STREAMING PROXY: Got range request: bytes=47546505- May 12 22:13:24 minidsp-shd volumio[959]: STREAMING PROXY: Error proxying request: Error: socket hang up May 12 22:13:24 minidsp-shd volumio[959]: STREAMING PROXY: Client dropped request, destroying May 12 22:13:24 minidsp-shd volumio[959]: info: May 12 22:13:24 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:24 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:24 minidsp-shd volumio[959]: info: May 12 22:13:24 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:24 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:24 minidsp-shd volumio[959]: info: May 12 22:13:24 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:24 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:24 minidsp-shd volumio[959]: info: sendMpdCommand status took 4 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: info: sendMpdCommand status took 4 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: info: sendMpdCommand status took 2 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:24 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:24 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:24 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:24 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:24 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:24 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:24 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:24 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 0 May 12 22:13:24 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 12 22:13:24 minidsp-shd volumio[959]: verbose: CURRENT POSITION 0 May 12 22:13:24 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService stop May 12 22:13:24 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:24 minidsp-shd volumio[959]: info: CoreStateMachine::play index undefined May 12 22:13:24 minidsp-shd volumio[959]: info: CoreStateMachine::setConsumeUpdateService undefined May 12 22:13:24 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:24 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:24 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:24 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:24 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:24 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:24 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:24 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:24 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:24 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:24 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:24 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:24 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:24 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:24 minidsp-shd volumio[959]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd May 12 22:13:24 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:24 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:24 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:24 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:24 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:24 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:24 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:24 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:24 minidsp-shd volumio[959]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received mpd May 12 22:13:24 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:24 minidsp-shd volumio[959]: info: CoreStateMachine::startPlaybackTimer May 12 22:13:24 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:24 minidsp-shd volumio[959]: info: [1715548404257] ControllerQobuz::clearAddPlayTrack May 12 22:13:24 minidsp-shd volumio[959]: info: ------------------------------ 62ms May 12 22:13:24 minidsp-shd volumio[959]: info: ------------------------------ 61ms May 12 22:13:24 minidsp-shd volumio[959]: info: ------------------------------ 60ms May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand stop May 12 22:13:24 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:24 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:24 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:24 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:24 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:24 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:24 minidsp-shd volumio[959]: info: sendMpdCommand stop took 11 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand clear May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:24 minidsp-shd volumio[959]: info: May 12 22:13:24 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:24 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:24 minidsp-shd volumio[959]: info: sendMpdCommand clear took 8 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/61862002" May 12 22:13:24 minidsp-shd volumio[959]: STREAMING PROXY: Handling url /?data=qobuz://song/61862002 May 12 22:13:24 minidsp-shd volumio[959]: info: May 12 22:13:24 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:24 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:24 minidsp-shd volumio[959]: info: May 12 22:13:24 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:24 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:24 minidsp-shd volumio[959]: error: updateQueue error: null May 12 22:13:24 minidsp-shd volumio[959]: info: ------------------------------ 13ms May 12 22:13:24 minidsp-shd volumio[959]: info: Executing endpoint getStreamUrlqobuz May 12 22:13:24 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:24 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:24 minidsp-shd volumio[959]: info: getStreamUrl took 271 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1781393&eid=61862002&fmt=7&profile=raw&app_id=539451548&cid=1211282&etsp=1715552004&hmac=sJbbwZuKHEnhD4Ns-zmALXoTVMA May 12 22:13:24 minidsp-shd volumio[959]: STREAMING PROXY: Response: 200, length: 43682455 May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/61862002" May 12 22:13:24 minidsp-shd volumio[959]: error: updateQueue error: null May 12 22:13:24 minidsp-shd volumio[959]: error: updateQueue error: null May 12 22:13:24 minidsp-shd volumio[959]: info: May 12 22:13:24 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:24 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:24 minidsp-shd volumio[959]: info: ------------------------------ 328ms May 12 22:13:24 minidsp-shd volumio[959]: info: ------------------------------ 326ms May 12 22:13:24 minidsp-shd volumio[959]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/61862002" took 4 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: STREAMING PROXY: Client dropped request, destroying May 12 22:13:24 minidsp-shd volumio[959]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand play May 12 22:13:24 minidsp-shd volumio[959]: STREAMING PROXY: Handling url /?data=qobuz://song/61862002 May 12 22:13:24 minidsp-shd volumio[959]: info: May 12 22:13:24 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:24 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:24 minidsp-shd volumio[959]: info: May 12 22:13:24 minidsp-shd volumio[959]: ---------------------------- MPD announces system playlist update May 12 22:13:24 minidsp-shd volumio[959]: info: Ignoring MPD Status Update May 12 22:13:24 minidsp-shd volumio[959]: info: ------------------------------ 15ms May 12 22:13:24 minidsp-shd volumio[959]: info: sendMpdCommand play took 11 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: info: ------------------------------ 7ms May 12 22:13:24 minidsp-shd volumio[959]: info: ------------------------------ 5ms May 12 22:13:24 minidsp-shd volumio[959]: info: Executing endpoint getStreamUrlqobuz May 12 22:13:24 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI May 12 22:13:24 minidsp-shd volumio[959]: info: getStreamUrl took 271 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1781393&eid=61862002&fmt=7&profile=raw&app_id=539451548&cid=1211282&etsp=1715552004&hmac=sJbbwZuKHEnhD4Ns-zmALXoTVMA May 12 22:13:24 minidsp-shd volumio[959]: STREAMING PROXY: Response: 200, length: 43682455 May 12 22:13:24 minidsp-shd volumio[959]: info: May 12 22:13:24 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:24 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:24 minidsp-shd volumio[959]: info: May 12 22:13:24 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:24 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:24 minidsp-shd volumio[959]: info: May 12 22:13:24 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:24 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:24 minidsp-shd volumio[959]: info: May 12 22:13:24 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:24 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:24 minidsp-shd volumio[959]: info: sendMpdCommand status took 16 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: info: sendMpdCommand status took 11 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: info: sendMpdCommand status took 8 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:24 minidsp-shd volumio[959]: info: May 12 22:13:24 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:24 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:24 minidsp-shd volumio[959]: info: May 12 22:13:24 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:24 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:24 minidsp-shd volumio[959]: info: sendMpdCommand status took 20 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 15 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 15 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 14 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: info: sendMpdCommand status took 10 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: info: sendMpdCommand status took 7 milliseconds May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:24 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:25 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:25 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:25 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:25 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:25 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:25 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:25 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:25 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":226,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"61862002","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61862002","trackType":"qobuz"} May 12 22:13:25 minidsp-shd volumio[959]: verbose: CURRENT POSITION 1 May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus stop May 12 22:13:25 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:25 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:25 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":226,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1471 Kbps","isStreaming":false,"title":"61862002","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61862002","trackType":"qobuz"} May 12 22:13:25 minidsp-shd volumio[959]: verbose: CURRENT POSITION 1 May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:25 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:25 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:25 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:25 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":226,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1301 Kbps","isStreaming":false,"title":"61862002","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61862002","trackType":"qobuz"} May 12 22:13:25 minidsp-shd volumio[959]: verbose: CURRENT POSITION 1 May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:25 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:25 minidsp-shd volumio[959]: info: ------------------------------ 105ms May 12 22:13:25 minidsp-shd volumio[959]: info: ------------------------------ 117ms May 12 22:13:25 minidsp-shd volumio[959]: info: ------------------------------ 113ms May 12 22:13:25 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 83 milliseconds May 12 22:13:25 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 79 milliseconds May 12 22:13:25 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 79 milliseconds May 12 22:13:25 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:25 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:25 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:25 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:25 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:25 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":226,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1203 Kbps","isStreaming":false,"title":"61862002","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61862002","trackType":"qobuz"} May 12 22:13:25 minidsp-shd volumio[959]: verbose: CURRENT POSITION 1 May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:25 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:25 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:25 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:25 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":226,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1203 Kbps","isStreaming":false,"title":"61862002","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61862002","trackType":"qobuz"} May 12 22:13:25 minidsp-shd volumio[959]: verbose: CURRENT POSITION 1 May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:25 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:25 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:25 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:25 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":226,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1203 Kbps","isStreaming":false,"title":"61862002","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61862002","trackType":"qobuz"} May 12 22:13:25 minidsp-shd volumio[959]: verbose: CURRENT POSITION 1 May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService play May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus play May 12 22:13:25 minidsp-shd volumio[959]: info: Received an update from plugin. extracting info from payload May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:25 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:25 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:25 minidsp-shd volumio[959]: info: ------------------------------ 191ms May 12 22:13:25 minidsp-shd volumio[959]: info: ------------------------------ 181ms May 12 22:13:25 minidsp-shd volumio[959]: info: ------------------------------ 178ms May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:25 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:25 minidsp-shd volumio[959]: info: Executing endpoint metavolumio May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 12 22:13:25 minidsp-shd volumio[959]: info: Executing endpoint metavolumio May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 12 22:13:25 minidsp-shd volumio[959]: info: Executing endpoint metavolumio May 12 22:13:25 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 12 22:13:28 minidsp-shd volumio[959]: STREAMING PROXY: Client dropped request, destroying May 12 22:13:29 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPause May 12 22:13:29 minidsp-shd volumio[959]: info: CoreStateMachine::pause May 12 22:13:29 minidsp-shd volumio[959]: info: CoreStateMachine::stPlaybackTimer May 12 22:13:29 minidsp-shd volumio[959]: info: CoreStateMachine::servicePause May 12 22:13:29 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:29 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePause May 12 22:13:29 minidsp-shd volumio[959]: info: [1715548409244] ControllerQobuz::pause May 12 22:13:29 minidsp-shd volumio[959]: info: CoreStateMachine::setConsumeUpdateService mpd May 12 22:13:29 minidsp-shd volumio[959]: info: ControllerMpd::pause May 12 22:13:29 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand pause May 12 22:13:29 minidsp-shd volumio[959]: info: sendMpdCommand pause took 2 milliseconds May 12 22:13:29 minidsp-shd volumio[959]: info: May 12 22:13:29 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:29 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:29 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:29 minidsp-shd volumio[959]: info: May 12 22:13:29 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:29 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:29 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:29 minidsp-shd volumio[959]: info: May 12 22:13:29 minidsp-shd volumio[959]: ---------------------------- MPD announces state update: player May 12 22:13:29 minidsp-shd volumio[959]: info: ControllerMpd::getState May 12 22:13:29 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand status May 12 22:13:29 minidsp-shd volumio[959]: info: sendMpdCommand status took 6 milliseconds May 12 22:13:29 minidsp-shd volumio[959]: info: sendMpdCommand status took 3 milliseconds May 12 22:13:29 minidsp-shd volumio[959]: info: sendMpdCommand status took 3 milliseconds May 12 22:13:29 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:29 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:29 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:29 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:29 minidsp-shd volumio[959]: verbose: ControllerMpd::parseState May 12 22:13:29 minidsp-shd volumio[959]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 22:13:29 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 3 milliseconds May 12 22:13:29 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 3 milliseconds May 12 22:13:29 minidsp-shd volumio[959]: info: sendMpdCommand playlistinfo took 3 milliseconds May 12 22:13:29 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:29 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:29 minidsp-shd volumio[959]: verbose: ControllerMpd::parseTrackInfo May 12 22:13:29 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:29 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:29 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:29 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5611,"duration":226,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1363 Kbps","isStreaming":false,"title":"61862002","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61862002","trackType":"qobuz"} May 12 22:13:29 minidsp-shd volumio[959]: verbose: CURRENT POSITION 1 May 12 22:13:29 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService pause May 12 22:13:29 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus pause May 12 22:13:29 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:29 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 12 22:13:29 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:29 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:29 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:29 minidsp-shd volumio[959]: info: CoreStateMachine::stPlaybackTimer May 12 22:13:29 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:29 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:29 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:29 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5611,"duration":226,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1363 Kbps","isStreaming":false,"title":"61862002","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61862002","trackType":"qobuz"} May 12 22:13:29 minidsp-shd volumio[959]: verbose: CURRENT POSITION 1 May 12 22:13:29 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService pause May 12 22:13:29 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus pause May 12 22:13:29 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:29 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:29 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:29 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:29 minidsp-shd volumio[959]: info: CoreStateMachine::stPlaybackTimer May 12 22:13:29 minidsp-shd volumio[959]: info: ControllerMpd::pushState May 12 22:13:29 minidsp-shd volumio[959]: info: CoreCommandRouter::servicePushState May 12 22:13:29 minidsp-shd volumio[959]: info: CorePlayQueue::getTrack 1 May 12 22:13:29 minidsp-shd volumio[959]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5611,"duration":226,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1363 Kbps","isStreaming":false,"title":"61862002","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/61862002","trackType":"qobuz"} May 12 22:13:29 minidsp-shd volumio[959]: verbose: CURRENT POSITION 1 May 12 22:13:29 minidsp-shd volumio[959]: info: CoreStateMachine::syncState stateService pause May 12 22:13:29 minidsp-shd volumio[959]: info: CoreStateMachine::syncState currentStatus pause May 12 22:13:29 minidsp-shd volumio[959]: info: CoreStateMachine::pushState May 12 22:13:29 minidsp-shd volumio[959]: info: CoreCommandRouter::volumioPushState May 12 22:13:29 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output update for this device May 12 22:13:29 minidsp-shd volumio[959]: info: MRS: Pushing multiroomSync output May 12 22:13:29 minidsp-shd volumio[959]: info: CoreStateMachine::stPlaybackTimer May 12 22:13:29 minidsp-shd volumio[959]: info: ------------------------------ 40ms May 12 22:13:29 minidsp-shd volumio[959]: info: ------------------------------ 38ms May 12 22:13:29 minidsp-shd volumio[959]: info: ------------------------------ 37ms May 12 22:13:29 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:29 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:29 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:29 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:29 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:29 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:29 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:29 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:29 minidsp-shd volumio[959]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 May 12 22:13:29 minidsp-shd volumio[959]: SPOTIFY: SPOTIFY VOLUME 73 May 12 22:13:29 minidsp-shd volumio[959]: SPOTIFY: VOLUMIO VOLUME 72 May 12 22:13:29 minidsp-shd volumio[959]: SPOTIFY: DELTA VOLUME ENOUGH: false May 12 22:13:32 minidsp-shd volumio[959]: error: Failed request for metavolumio API May 12 22:13:32 minidsp-shd volumio[959]: error: Failed request for metavolumio API May 12 22:13:32 minidsp-shd volumio[959]: error: Failed request for metavolumio API May 12 22:13:35 minidsp-shd volumio[959]: info: Executing endpoint metavolumio May 12 22:13:35 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 12 22:13:35 minidsp-shd volumio[959]: info: Executing endpoint metavolumio May 12 22:13:35 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 12 22:13:42 minidsp-shd volumio[959]: error: Failed request for metavolumio API May 12 22:13:44 minidsp-shd volumio[959]: Searching all installed plugins May 12 22:13:44 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 12 22:13:44 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: , search May 12 22:13:44 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: mpd , search May 12 22:13:44 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search May 12 22:13:44 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: last_100 , search May 12 22:13:44 minidsp-shd volumio[959]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 May 12 22:13:44 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: webradio , search May 12 22:13:44 minidsp-shd volumio[959]: info: CoreCommandRouter::executeOnPlugin: calmradio , search May 12 22:13:44 minidsp-shd volumio[959]: info: [1715548424092] ControllerCalmRadio::searchCategories May 12 22:13:44 minidsp-shd volumio[959]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 12 22:13:44 minidsp-shd volumio[959]: TypeError: Cannot read property 'cats' of undefined May 12 22:13:44 minidsp-shd volumio[959]: at ControllerCalmRadio.searchCategories (/data/plugins/music_service/calmradio/index.js:615:42) May 12 22:13:44 minidsp-shd volumio[959]: at ControllerCalmRadio.search (/data/plugins/music_service/calmradio/index.js:665:28) May 12 22:13:44 minidsp-shd volumio[959]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1077:32) May 12 22:13:44 minidsp-shd volumio[959]: at CoreMusicLibrary.searchOnPlugin (/volumio/app/musiclibrary.js:668:44) May 12 22:13:44 minidsp-shd volumio[959]: at CoreMusicLibrary.search (/volumio/app/musiclibrary.js:455:27) May 12 22:13:44 minidsp-shd volumio[959]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:457:44) May 12 22:13:44 minidsp-shd volumio[959]: at Socket.emit (events.js:400:28) May 12 22:13:44 minidsp-shd volumio[959]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 May 12 22:13:44 minidsp-shd volumio[959]: at processTicksAndRejections (internal/process/task_queues.js:77:11) May 12 22:13:44 minidsp-shd volumio[959]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 12 22:13:44 minidsp-shd sudo[10340]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-12 22:12 May 12 22:13:44 minidsp-shd sudo[10340]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="17fcb754ddd6bd152b01008c46cc4ba1ca48bf35" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="281cefcd7a302aa7cfba569185cf7aae19b8c376" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 22 Mar 2024 03:00:28 PM CET" VOLUMIO_VERSION="3.608" VOLUMIO_HARDWARE="nanopineo2" VOLUMIO_DEVICENAME="NanoPi Neo2" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="29ccfe8a9cff19911db4b736879ac117"