-- Logs begin at Wed 2024-10-16 11:54:32 PDT, end at Wed 2024-10-16 16:02:40 PDT. -- Oct 16 16:01:03 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 16:01:03 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 16:01:03 musicpi volumio[1048]: info: Discovery: Getting this device information Oct 16 16:01:03 musicpi volumio[1048]: info: CoreCommandRouter::volumioGetState Oct 16 16:01:03 musicpi volumio[1048]: info: CorePlayQueue::getTrack 0 Oct 16 16:01:03 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 16:01:10 musicpi sudo[13595]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 16:01:10 musicpi sudo[13595]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:01:10 musicpi sudo[13595]: pam_unix(sudo:session): session closed for user root Oct 16 16:01:10 musicpi sudo[13598]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 16:01:10 musicpi sudo[13598]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:01:10 musicpi sudo[13598]: pam_unix(sudo:session): session closed for user root Oct 16 16:01:10 musicpi sudo[13601]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 16:01:10 musicpi sudo[13601]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:01:10 musicpi sudo[13601]: pam_unix(sudo:session): session closed for user root Oct 16 16:01:10 musicpi sudo[13604]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 16:01:10 musicpi sudo[13604]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:01:10 musicpi sudo[13604]: pam_unix(sudo:session): session closed for user root Oct 16 16:01:10 musicpi volumio[1048]: verbose: New Socket.io Connection to 10.0.0.164 from 10.0.0.182 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.0.1 Safari/605.1.15 Engine version: 3 Transport: polling Total Clients: 14 Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::volumioGetVisibleSources Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::volumioGetState Oct 16 16:01:10 musicpi volumio[1048]: info: CorePlayQueue::getTrack 0 Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 16 16:01:10 musicpi volumio[1048]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 16 16:01:10 musicpi volumio[1048]: info: Received Get System Info Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 16:01:10 musicpi volumio[1048]: info: Discovery: Getting this device information Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::volumioGetState Oct 16 16:01:10 musicpi volumio[1048]: info: CorePlayQueue::getTrack 0 Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::volumioGetState Oct 16 16:01:10 musicpi volumio[1048]: info: CorePlayQueue::getTrack 0 Oct 16 16:01:10 musicpi volumio[1048]: info: Listing playlists Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 16 16:01:10 musicpi sudo[13607]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 16 16:01:10 musicpi sudo[13607]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:01:10 musicpi sudo[13607]: pam_unix(sudo:session): session closed for user root Oct 16 16:01:10 musicpi sudo[13610]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 16 16:01:10 musicpi sudo[13610]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:01:10 musicpi sudo[13610]: pam_unix(sudo:session): session closed for user root Oct 16 16:01:10 musicpi volumio[1048]: verbose: New Socket.io Connection to 10.0.0.164 from 10.0.0.182 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.0.1 Safari/605.1.15 Engine version: 3 Transport: polling Total Clients: 15 Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::volumioGetVisibleSources Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::volumioGetState Oct 16 16:01:10 musicpi volumio[1048]: info: CorePlayQueue::getTrack 0 Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 16 16:01:10 musicpi volumio[1048]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 16 16:01:10 musicpi volumio[1048]: info: Received Get System Info Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 16:01:10 musicpi volumio[1048]: info: Discovery: Getting this device information Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::volumioGetState Oct 16 16:01:10 musicpi volumio[1048]: info: CorePlayQueue::getTrack 0 Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::volumioGetState Oct 16 16:01:10 musicpi volumio[1048]: info: CorePlayQueue::getTrack 0 Oct 16 16:01:10 musicpi volumio[1048]: info: Listing playlists Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 16 16:01:10 musicpi volumio[1048]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 16 16:01:11 musicpi volumio[1048]: info: CoreCommandRouter::volumioGetState Oct 16 16:01:11 musicpi volumio[1048]: info: CorePlayQueue::getTrack 0 Oct 16 16:01:12 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 16 16:01:12 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 16:01:12 musicpi volumio[1048]: info: Received Get System Info Oct 16 16:01:12 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 16:01:12 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 16:01:12 musicpi volumio[1048]: info: Discovery: Getting this device information Oct 16 16:01:12 musicpi volumio[1048]: info: CoreCommandRouter::volumioGetState Oct 16 16:01:12 musicpi volumio[1048]: info: CorePlayQueue::getTrack 0 Oct 16 16:01:12 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 16:01:13 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 16:01:13 musicpi volumio[1048]: info: Received Get System Info Oct 16 16:01:13 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 16:01:13 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 16:01:13 musicpi volumio[1048]: info: Discovery: Getting this device information Oct 16 16:01:13 musicpi volumio[1048]: info: CoreCommandRouter::volumioGetState Oct 16 16:01:13 musicpi volumio[1048]: info: CorePlayQueue::getTrack 0 Oct 16 16:01:13 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 16:01:13 musicpi volumio[1048]: info: Executing endpoint metavolumio Oct 16 16:01:13 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 16 16:01:13 musicpi volumio[1048]: info: Executing endpoint metavolumio Oct 16 16:01:13 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 16 16:01:13 musicpi volumio[1048]: info: Executing endpoint metavolumio Oct 16 16:01:13 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 16 16:01:15 musicpi volumio[1048]: info: CoreCommandRouter::volumioPlay Oct 16 16:01:15 musicpi volumio[1048]: info: CoreStateMachine::play index undefined Oct 16 16:01:15 musicpi volumio[1048]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 16:01:15 musicpi volumio[1048]: info: CorePlayQueue::getTrack 0 Oct 16 16:01:15 musicpi volumio[1048]: info: CoreStateMachine::startPlaybackTimer Oct 16 16:01:15 musicpi volumio[1048]: info: CorePlayQueue::getTrack 0 Oct 16 16:01:15 musicpi volumio[1048]: info: [1729119675701] ControllerSpotify::clearAddPlayTrack Oct 16 16:01:15 musicpi volumio[1048]: info: Sending Spotify command with payload to local API: /player/play Oct 16 16:01:15 musicpi go-librespot[12599]: time="2024-10-16T16:01:15-07:00" level=debug msg="resolved context of track" uri="spotify:track:1TfqLAPs4K3s2rJMoCokcS" Oct 16 16:01:15 musicpi go-librespot[12599]: time="2024-10-16T16:01:15-07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1TfqLAPs4K3s2rJMoCokcS" Oct 16 16:01:15 musicpi go-librespot[12599]: time="2024-10-16T16:01:15-07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1TfqLAPs4K3s2rJMoCokcS" Oct 16 16:01:15 musicpi go-librespot[12599]: time="2024-10-16T16:01:15-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 16 16:01:15 musicpi go-librespot[12599]: time="2024-10-16T16:01:15-07:00" level=trace msg="emitting websocket event: will_play" Oct 16 16:01:15 musicpi volumio[1048]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1TfqLAPs4K3s2rJMoCokcS","play_origin":"go-librespot"}} Oct 16 16:01:15 musicpi volumio[1048]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1TfqLAPs4K3s2rJMoCokcS","play_origin":"go-librespot"}} Oct 16 16:01:15 musicpi go-librespot[12599]: time="2024-10-16T16:01:15-07:00" level=debug msg="selected format OGG_VORBIS_320 (57b5fb76a23bb5eeb8f8d7b90c6e1e6a203291c3)" uri="spotify:track:1TfqLAPs4K3s2rJMoCokcS" Oct 16 16:01:15 musicpi go-librespot[12599]: time="2024-10-16T16:01:15-07:00" level=debug msg="requested aes key for file 57b5fb76a23bb5eeb8f8d7b90c6e1e6a203291c3, gid: 1TfqLAPs4K3s2rJMoCokcS" Oct 16 16:01:16 musicpi go-librespot[12599]: time="2024-10-16T16:01:16-07:00" level=debug msg="fetched first chunk of 17, total size is 8580744 bytes" uri="spotify:track:1TfqLAPs4K3s2rJMoCokcS" Oct 16 16:01:16 musicpi go-librespot[12599]: time="2024-10-16T16:01:16-07:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:1TfqLAPs4K3s2rJMoCokcS" Oct 16 16:01:16 musicpi go-librespot[12599]: ALSA lib /home/pi/volumio-fifo-plugin/src/pcm_volumiofifo.c:753:(_snd_pcm_volumiofifo_open) Failed to open output fifo /tmp/fusiondspfifo Oct 16 16:01:16 musicpi go-librespot[12599]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Oct 16 16:01:16 musicpi go-librespot[12599]: time="2024-10-16T16:01:16-07:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed setting stream for spotify:track:1TfqLAPs4K3s2rJMoCokcS: ALSA error at snd_pcm_open: No such file or directory" Oct 16 16:01:16 musicpi volumio[1048]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Oct 16 16:01:16 musicpi go-librespot[12599]: time="2024-10-16T16:01:16-07:00" level=debug msg="fetched chunk 3/16, size: 524288" uri="spotify:track:1TfqLAPs4K3s2rJMoCokcS" Oct 16 16:01:16 musicpi go-librespot[12599]: time="2024-10-16T16:01:16-07:00" level=debug msg="fetched chunk 1/16, size: 524288" uri="spotify:track:1TfqLAPs4K3s2rJMoCokcS" Oct 16 16:01:16 musicpi go-librespot[12599]: time="2024-10-16T16:01:16-07:00" level=debug msg="fetched chunk 2/16, size: 524288" uri="spotify:track:1TfqLAPs4K3s2rJMoCokcS" Oct 16 16:01:16 musicpi volumio[1048]: error: error Oct 16 16:01:16 musicpi volumio[1048]: error: error Oct 16 16:01:20 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 16 16:01:22 musicpi volumio[1048]: info: CoreCommandRouter::volumioPrevious Oct 16 16:01:22 musicpi volumio[1048]: info: CoreStateMachine::previous Oct 16 16:01:26 musicpi volumio[1048]: info: CoreCommandRouter::volumioNext Oct 16 16:01:26 musicpi volumio[1048]: info: CoreStateMachine::next Oct 16 16:01:26 musicpi volumio[1048]: info: CoreStateMachine::stop Oct 16 16:01:26 musicpi volumio[1048]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 16:01:26 musicpi volumio[1048]: info: CoreStateMachine::play index undefined Oct 16 16:01:26 musicpi volumio[1048]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 16:01:26 musicpi volumio[1048]: info: CorePlayQueue::getTrack 1 Oct 16 16:01:26 musicpi volumio[1048]: info: CoreStateMachine::startPlaybackTimer Oct 16 16:01:26 musicpi volumio[1048]: info: CorePlayQueue::getTrack 1 Oct 16 16:01:26 musicpi volumio[1048]: info: [1729119686954] ControllerSpotify::clearAddPlayTrack Oct 16 16:01:26 musicpi volumio[1048]: info: Sending Spotify command with payload to local API: /player/play Oct 16 16:01:26 musicpi volumio[1048]: info: CoreStateMachine::updateTrackBlock Oct 16 16:01:26 musicpi volumio[1048]: info: CorePlayQueue::getTrackBlock Oct 16 16:01:27 musicpi go-librespot[12599]: time="2024-10-16T16:01:27-07:00" level=debug msg="resolved context of track" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:27 musicpi go-librespot[12599]: time="2024-10-16T16:01:27-07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:27 musicpi go-librespot[12599]: time="2024-10-16T16:01:27-07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:27 musicpi go-librespot[12599]: time="2024-10-16T16:01:27-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 16 16:01:27 musicpi go-librespot[12599]: time="2024-10-16T16:01:27-07:00" level=trace msg="emitting websocket event: will_play" Oct 16 16:01:27 musicpi volumio[1048]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5vmRQ3zELMLUQPo2FLQ76x","play_origin":"go-librespot"}} Oct 16 16:01:27 musicpi volumio[1048]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5vmRQ3zELMLUQPo2FLQ76x","play_origin":"go-librespot"}} Oct 16 16:01:27 musicpi go-librespot[12599]: time="2024-10-16T16:01:27-07:00" level=debug msg="selected format OGG_VORBIS_320 (9e8d1e870ec191534da038b2f6dc7639dcb0fa38)" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:27 musicpi go-librespot[12599]: time="2024-10-16T16:01:27-07:00" level=debug msg="requested aes key for file 9e8d1e870ec191534da038b2f6dc7639dcb0fa38, gid: 5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:27 musicpi go-librespot[12599]: time="2024-10-16T16:01:27-07:00" level=debug msg="fetched first chunk of 22, total size is 11429568 bytes" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:27 musicpi go-librespot[12599]: time="2024-10-16T16:01:27-07:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:27 musicpi go-librespot[12599]: ALSA lib /home/pi/volumio-fifo-plugin/src/pcm_volumiofifo.c:753:(_snd_pcm_volumiofifo_open) Failed to open output fifo /tmp/fusiondspfifo Oct 16 16:01:27 musicpi go-librespot[12599]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Oct 16 16:01:27 musicpi go-librespot[12599]: time="2024-10-16T16:01:27-07:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed setting stream for spotify:track:5vmRQ3zELMLUQPo2FLQ76x: ALSA error at snd_pcm_open: No such file or directory" Oct 16 16:01:27 musicpi volumio[1048]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Oct 16 16:01:27 musicpi go-librespot[12599]: time="2024-10-16T16:01:27-07:00" level=debug msg="fetched chunk 2/21, size: 524288" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:27 musicpi go-librespot[12599]: time="2024-10-16T16:01:27-07:00" level=debug msg="fetched chunk 1/21, size: 524288" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:27 musicpi go-librespot[12599]: time="2024-10-16T16:01:27-07:00" level=debug msg="fetched chunk 3/21, size: 524288" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:29 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 16 16:01:29 musicpi volumio[1048]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 16 16:01:29 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 16 16:01:29 musicpi volumio[1048]: info: Received Get System Version Oct 16 16:01:29 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 16 16:01:29 musicpi volumio[1048]: info: Received Get System Info Oct 16 16:01:29 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 16:01:29 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 16:01:29 musicpi volumio[1048]: info: Discovery: Getting this device information Oct 16 16:01:29 musicpi volumio[1048]: info: CoreCommandRouter::volumioGetState Oct 16 16:01:29 musicpi volumio[1048]: info: CorePlayQueue::getTrack 1 Oct 16 16:01:29 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 16:01:31 musicpi volumio[1048]: info: CoreCommandRouter::volumioPlay Oct 16 16:01:31 musicpi volumio[1048]: info: CoreStateMachine::play index undefined Oct 16 16:01:31 musicpi volumio[1048]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 16:01:31 musicpi volumio[1048]: info: CorePlayQueue::getTrack 1 Oct 16 16:01:31 musicpi volumio[1048]: info: CoreStateMachine::startPlaybackTimer Oct 16 16:01:31 musicpi volumio[1048]: info: CorePlayQueue::getTrack 1 Oct 16 16:01:31 musicpi volumio[1048]: info: [1729119691841] ControllerSpotify::clearAddPlayTrack Oct 16 16:01:31 musicpi volumio[1048]: info: Sending Spotify command with payload to local API: /player/play Oct 16 16:01:31 musicpi go-librespot[12599]: time="2024-10-16T16:01:31-07:00" level=debug msg="resolved context of track" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:31 musicpi go-librespot[12599]: time="2024-10-16T16:01:31-07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:31 musicpi go-librespot[12599]: time="2024-10-16T16:01:31-07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:31 musicpi go-librespot[12599]: time="2024-10-16T16:01:31-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 16 16:01:31 musicpi go-librespot[12599]: time="2024-10-16T16:01:31-07:00" level=trace msg="emitting websocket event: will_play" Oct 16 16:01:31 musicpi volumio[1048]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5vmRQ3zELMLUQPo2FLQ76x","play_origin":"go-librespot"}} Oct 16 16:01:31 musicpi volumio[1048]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5vmRQ3zELMLUQPo2FLQ76x","play_origin":"go-librespot"}} Oct 16 16:01:32 musicpi go-librespot[12599]: time="2024-10-16T16:01:32-07:00" level=debug msg="selected format OGG_VORBIS_320 (9e8d1e870ec191534da038b2f6dc7639dcb0fa38)" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:32 musicpi go-librespot[12599]: time="2024-10-16T16:01:32-07:00" level=debug msg="requested aes key for file 9e8d1e870ec191534da038b2f6dc7639dcb0fa38, gid: 5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:32 musicpi go-librespot[12599]: time="2024-10-16T16:01:32-07:00" level=debug msg="fetched first chunk of 22, total size is 11429568 bytes" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:32 musicpi go-librespot[12599]: time="2024-10-16T16:01:32-07:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:32 musicpi go-librespot[12599]: ALSA lib /home/pi/volumio-fifo-plugin/src/pcm_volumiofifo.c:753:(_snd_pcm_volumiofifo_open) Failed to open output fifo /tmp/fusiondspfifo Oct 16 16:01:32 musicpi go-librespot[12599]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Oct 16 16:01:32 musicpi go-librespot[12599]: time="2024-10-16T16:01:32-07:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed setting stream for spotify:track:5vmRQ3zELMLUQPo2FLQ76x: ALSA error at snd_pcm_open: No such file or directory" Oct 16 16:01:32 musicpi volumio[1048]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Oct 16 16:01:32 musicpi go-librespot[12599]: time="2024-10-16T16:01:32-07:00" level=debug msg="fetched chunk 1/21, size: 524288" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:32 musicpi go-librespot[12599]: time="2024-10-16T16:01:32-07:00" level=debug msg="fetched chunk 2/21, size: 524288" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:32 musicpi go-librespot[12599]: time="2024-10-16T16:01:32-07:00" level=debug msg="fetched chunk 3/21, size: 524288" uri="spotify:track:5vmRQ3zELMLUQPo2FLQ76x" Oct 16 16:01:33 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 16:01:33 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 16:01:33 musicpi volumio[1048]: info: Discovery: Getting this device information Oct 16 16:01:33 musicpi volumio[1048]: info: CoreCommandRouter::volumioGetState Oct 16 16:01:33 musicpi volumio[1048]: info: CorePlayQueue::getTrack 1 Oct 16 16:01:33 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 16:01:38 musicpi volumio[1048]: info: CoreCommandRouter::volumioGetQueue Oct 16 16:01:38 musicpi volumio[1048]: info: CoreStateMachine::getQueue Oct 16 16:01:38 musicpi volumio[1048]: info: CorePlayQueue::getQueue Oct 16 16:01:41 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 16 16:01:41 musicpi volumio[1048]: info: In handleBrowseUri, curUri=spotify/playlists Oct 16 16:01:42 musicpi volumio[1048]: info: Preload queue cleared Oct 16 16:01:54 musicpi volumio[1048]: error: [now-playing] API endpoint weather/fetchInfo returned error: Error: Could not access weather service: missing geographic coordinates. Oct 16 16:01:54 musicpi volumio[1048]: at WeatherAPI.fetchInfo (/data/plugins/user_interface/now_playing/dist/lib/api/WeatherAPI.js:106:19) Oct 16 16:01:54 musicpi volumio[1048]: at Object.api (/data/plugins/user_interface/now_playing/dist/app/Handler.js:115:37) Oct 16 16:01:54 musicpi volumio[1048]: at /data/plugins/user_interface/now_playing/dist/app/Router.js:47:13 Oct 16 16:01:54 musicpi volumio[1048]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Oct 16 16:01:54 musicpi volumio[1048]: at next (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/route.js:149:13) Oct 16 16:01:54 musicpi volumio[1048]: at Route.dispatch (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/route.js:119:3) Oct 16 16:01:54 musicpi volumio[1048]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Oct 16 16:01:54 musicpi volumio[1048]: at /data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:284:15 Oct 16 16:01:54 musicpi volumio[1048]: at param (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:365:14) Oct 16 16:01:54 musicpi volumio[1048]: at param (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:376:14) Oct 16 16:01:54 musicpi volumio[1048]: at Function.process_params (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:421:3) Oct 16 16:01:54 musicpi volumio[1048]: at next (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:280:10) Oct 16 16:01:54 musicpi volumio[1048]: at Function.handle (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:175:3) Oct 16 16:01:54 musicpi volumio[1048]: at router (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/index.js:47:12) Oct 16 16:01:54 musicpi volumio[1048]: at Layer.handle [as handle_request] (/data/plugins/user_interface/now_playing/node_modules/express/lib/router/layer.js:95:5) Oct 16 16:02:01 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 16 16:02:01 musicpi volumio[1048]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:3blt6iZnPaYo6DPjIQjdNg Oct 16 16:02:02 musicpi volumio[1048]: info: Preload queue cleared Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:3u1ggZA6C0h2waxIzpT8GE Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:2Uf9WTBWMA8S9Lh3k3Rui6 Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:7H5WVBQdSnJ1zmu8JoD6pg Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:5YHhxbtAAkOiIXqNBfYjZU Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:3kROc4cT1QMKyQdPd0Gbvm Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:3lhGAWwSFUkidmntbm3CnS Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:0RtIyGCAp35Hk2WYiTRHnH Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:3EnyKqEJFylT6vU1KF0YyE Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:0wBF8bhlK6w7efWIwiLPWJ Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:5xoUgPXbMNUmoHU0Enwtwq Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:5g0HSob4PEq7M8blV6y70i Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:5pVbLYTdihSKd8Kylfhwa7 Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:6JWddKPdqvDc2WkPEi9grC Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:0fYQdwOzZeIAeYVgrroLj1 Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:5PZK7nZBsKjSkXDszKrJ1W Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:29XbgaYB4Hs8vlLmpzkRgj Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:2becL3e8PY3QYLpvs5k9FU Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:2dHNRucvRwCVdwrfJecCkr Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:3qaSqrrevBrb84xl5JlptU Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:6nCFIb0seIECUijbDpYNDu Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:4qZe9OCrmgiv86vSujfYkn Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:0751ozQYIiLVQ9FRFhe55j Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:5o2UsVpnpQcDDRcuEPzGIm Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:0HzZB3Z6gIk3VOlS5WjT49 Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:2EtZFeLn9msgg4qJzT9Vql Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:6MLO0mKNsJ6opIC31CchnM Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:4wCsnvMyDboBxSDgipm2z0 Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:0UgHw2x3Nnocajvx62noEn Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:0JAQUGJudVlhRoAqqhVoYX Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:4dRqYKhLVujxiBXcq50YzG Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:4MUkX9MV0PazAf0VibU2JP Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:3APHT3KjbHi9OllkVQsuXF Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:4z86ZEcMLofosRyJMqBkIz Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:5JSF5Nhw9W6j9qt74rYTa7 Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:7v9Ne4758aGFfFc5avh89h Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:0Dkew1fJuIAnuoHXc8pMTm Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:1xDPUKoyQuIiea7Le9ZNgn Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:2sqtkSLyuo3hdpnp0gyVCq Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:3ZJZjjKFxTqVGJ8QIYKMjp Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:1B241LRKmK6qDDTZfUajmm Oct 16 16:02:02 musicpi volumio[1048]: info: Preloading song: spotify:track:0yc6Gst2xkRu0eMLeRMGCX Oct 16 16:02:02 musicpi volumio[1048]: info: Exploding uri spotify:track:3u1ggZA6C0h2waxIzpT8GE in service spop Oct 16 16:02:02 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:3u1ggZA6C0h2waxIzpT8GE Oct 16 16:02:02 musicpi volumio[1048]: info: Exploding uri spotify:track:2Uf9WTBWMA8S9Lh3k3Rui6 in service spop Oct 16 16:02:02 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:2Uf9WTBWMA8S9Lh3k3Rui6 Oct 16 16:02:02 musicpi volumio[1048]: info: Exploding uri spotify:track:7H5WVBQdSnJ1zmu8JoD6pg in service spop Oct 16 16:02:02 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:7H5WVBQdSnJ1zmu8JoD6pg Oct 16 16:02:02 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3u1ggZA6C0h2waxIzpT8GE","service":"spop","name":"Retrospect - Single Version","artist":"Vistas","album":"Retrospect - Single Version","type":"song","duration":204,"albumart":"https://i.scdn.co/image/ab67616d0000b2736445580c6e0085a2a42f596d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:02 musicpi volumio[1048]: info: Exploding uri spotify:track:5YHhxbtAAkOiIXqNBfYjZU in service spop Oct 16 16:02:02 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:5YHhxbtAAkOiIXqNBfYjZU Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2Uf9WTBWMA8S9Lh3k3Rui6","service":"spop","name":"Ooh La","artist":"The Kooks","album":"Inside In / Inside Out","type":"song","duration":208,"albumart":"https://i.scdn.co/image/ab67616d0000b27363a28c5ecb7b13e9b329fe47","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:3kROc4cT1QMKyQdPd0Gbvm in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:3kROc4cT1QMKyQdPd0Gbvm Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7H5WVBQdSnJ1zmu8JoD6pg","service":"spop","name":"Charlemagne","artist":"Blossoms","album":"Blossoms","type":"song","duration":166,"albumart":"https://i.scdn.co/image/ab67616d0000b273258d6688061ae2729981a417","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:3lhGAWwSFUkidmntbm3CnS in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:3lhGAWwSFUkidmntbm3CnS Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:0RtIyGCAp35Hk2WYiTRHnH in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:0RtIyGCAp35Hk2WYiTRHnH Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5YHhxbtAAkOiIXqNBfYjZU","service":"spop","name":"Moving to New York","artist":"The Wombats","album":"Proudly Present... A Guide to Love, Loss & Desperation (Special Edition)","type":"song","duration":210,"albumart":"https://i.scdn.co/image/ab67616d0000b27364e27be28006c90422c11587","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3kROc4cT1QMKyQdPd0Gbvm","service":"spop","name":"Saturday","artist":"Sam Fender","album":"Hypersonic Missiles","type":"song","duration":181,"albumart":"https://i.scdn.co/image/ab67616d0000b273afb4accd45527de5717afc9a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:3EnyKqEJFylT6vU1KF0YyE in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:3EnyKqEJFylT6vU1KF0YyE Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3lhGAWwSFUkidmntbm3CnS","service":"spop","name":"Before I Fall To Pieces","artist":"Razorlight","album":"Razorwhat? The Best Of Razorlight","type":"song","duration":203,"albumart":"https://i.scdn.co/image/ab67616d0000b273a4603283e67b3989cb10df29","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:0wBF8bhlK6w7efWIwiLPWJ in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:0wBF8bhlK6w7efWIwiLPWJ Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0RtIyGCAp35Hk2WYiTRHnH","service":"spop","name":"C'est La Vie","artist":"Stereophonics","album":"Keep the Village Alive (Deluxe)","type":"song","duration":220,"albumart":"https://i.scdn.co/image/ab67616d0000b2739c4f5071aa00f38f58422c67","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:5xoUgPXbMNUmoHU0Enwtwq in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:5xoUgPXbMNUmoHU0Enwtwq Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3EnyKqEJFylT6vU1KF0YyE","service":"spop","name":"I Predict A Riot","artist":"Kaiser Chiefs","album":"Souvenir : The Singles 2004 - 2012","type":"song","duration":232,"albumart":"https://i.scdn.co/image/ab67616d0000b273fbf677cc74cd86f65094d487","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:5g0HSob4PEq7M8blV6y70i in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:5g0HSob4PEq7M8blV6y70i Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0wBF8bhlK6w7efWIwiLPWJ","service":"spop","name":"Are You in Love With a Notion?","artist":"Courteeners","album":"Anna","type":"song","duration":254,"albumart":"https://i.scdn.co/image/ab67616d0000b2735ddcdd007c1e810a41db3d38","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:5pVbLYTdihSKd8Kylfhwa7 in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:5pVbLYTdihSKd8Kylfhwa7 Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:6JWddKPdqvDc2WkPEi9grC in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:6JWddKPdqvDc2WkPEi9grC Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5xoUgPXbMNUmoHU0Enwtwq","service":"spop","name":"She Moves In Her Own Way","artist":"The Kooks","album":"Inside In / Inside Out","type":"song","duration":169,"albumart":"https://i.scdn.co/image/ab67616d0000b27363a28c5ecb7b13e9b329fe47","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5g0HSob4PEq7M8blV6y70i","service":"spop","name":"Will We Talk?","artist":"Sam Fender","album":"Hypersonic Missiles","type":"song","duration":162,"albumart":"https://i.scdn.co/image/ab67616d0000b273afb4accd45527de5717afc9a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:0fYQdwOzZeIAeYVgrroLj1 in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:0fYQdwOzZeIAeYVgrroLj1 Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5pVbLYTdihSKd8Kylfhwa7","service":"spop","name":"There's A Reason Why (I Never Returned Your Calls)","artist":"Blossoms","album":"Cool Like You (Deluxe)","type":"song","duration":222,"albumart":"https://i.scdn.co/image/ab67616d0000b2732889f5b28a2acdf603bfcd8a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:5PZK7nZBsKjSkXDszKrJ1W in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:5PZK7nZBsKjSkXDszKrJ1W Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6JWddKPdqvDc2WkPEi9grC","service":"spop","name":"Have A Nice Day","artist":"Stereophonics","album":"Just Enough Education To Perform","type":"song","duration":205,"albumart":"https://i.scdn.co/image/ab67616d0000b273671c709e025a3ed8c956d115","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:29XbgaYB4Hs8vlLmpzkRgj in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:29XbgaYB4Hs8vlLmpzkRgj Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0fYQdwOzZeIAeYVgrroLj1","service":"spop","name":"Sit Down","artist":"James","album":"James: The Best Of","type":"song","duration":244,"albumart":"https://i.scdn.co/image/ab67616d0000b273843b79d87a70cb39adb69917","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:2becL3e8PY3QYLpvs5k9FU in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:2becL3e8PY3QYLpvs5k9FU Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5PZK7nZBsKjSkXDszKrJ1W","service":"spop","name":"Hard to Beat","artist":"Hard-Fi","album":"Stars Of CCTV","type":"song","duration":253,"albumart":"https://i.scdn.co/image/ab67616d0000b273004382bc4ed93d0ac65523fd","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:2dHNRucvRwCVdwrfJecCkr in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:2dHNRucvRwCVdwrfJecCkr Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:29XbgaYB4Hs8vlLmpzkRgj","service":"spop","name":"Naive","artist":"The Kooks","album":"Naïve","type":"song","duration":206,"albumart":"https://i.scdn.co/image/ab67616d0000b273c6aee2f5ba8712519f6bc441","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:3qaSqrrevBrb84xl5JlptU in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:3qaSqrrevBrb84xl5JlptU Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2becL3e8PY3QYLpvs5k9FU","service":"spop","name":"In The Morning","artist":"Razorlight","album":"In The Morning","type":"song","duration":224,"albumart":"https://i.scdn.co/image/ab67616d0000b273b17a373176af0e605e2ef3ba","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:6nCFIb0seIECUijbDpYNDu in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:6nCFIb0seIECUijbDpYNDu Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2dHNRucvRwCVdwrfJecCkr","service":"spop","name":"You're in Love With a Psycho","artist":"Kasabian","album":"You're in Love With a Psycho","type":"song","duration":217,"albumart":"https://i.scdn.co/image/ab67616d0000b27325668174d1ba4f382fa2f778","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:4qZe9OCrmgiv86vSujfYkn in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:4qZe9OCrmgiv86vSujfYkn Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3qaSqrrevBrb84xl5JlptU","service":"spop","name":"Dakota","artist":"Stereophonics","album":"Language.Sex.Violence.Other?","type":"song","duration":297,"albumart":"https://i.scdn.co/image/ab67616d0000b273ecdb914ea9cbbb31c5a6b71b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:0751ozQYIiLVQ9FRFhe55j in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:0751ozQYIiLVQ9FRFhe55j Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6nCFIb0seIECUijbDpYNDu","service":"spop","name":"Glasgow","artist":"The Snuts","album":"W.L. (Deluxe)","type":"song","duration":266,"albumart":"https://i.scdn.co/image/ab67616d0000b273214a0b7b069dd7557ba7910e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 16:02:03 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 16:02:03 musicpi volumio[1048]: info: Discovery: Getting this device information Oct 16 16:02:03 musicpi volumio[1048]: info: CoreCommandRouter::volumioGetState Oct 16 16:02:03 musicpi volumio[1048]: info: CorePlayQueue::getTrack 1 Oct 16 16:02:03 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:5o2UsVpnpQcDDRcuEPzGIm in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:5o2UsVpnpQcDDRcuEPzGIm Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4qZe9OCrmgiv86vSujfYkn","service":"spop","name":"Golden Skans","artist":"Klaxons","album":"2000s Indie Nostalgia","type":"song","duration":167,"albumart":"https://i.scdn.co/image/ab67616d0000b273078020d80a233ef85f43b65a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:03 musicpi volumio[1048]: info: Exploding uri spotify:track:0HzZB3Z6gIk3VOlS5WjT49 in service spop Oct 16 16:02:03 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:0HzZB3Z6gIk3VOlS5WjT49 Oct 16 16:02:04 musicpi volumio[1048]: info: Exploding uri spotify:track:2EtZFeLn9msgg4qJzT9Vql in service spop Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:2EtZFeLn9msgg4qJzT9Vql Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0751ozQYIiLVQ9FRFhe55j","service":"spop","name":"Glamorous Indie Rock & Roll","artist":"The Killers","album":"Hot Fuss","type":"song","duration":254,"albumart":"https://i.scdn.co/image/ab67616d0000b273ccdddd46119a4ff53eaf1f5d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5o2UsVpnpQcDDRcuEPzGIm","service":"spop","name":"Tokyo (Vampires & Wolves)","artist":"The Wombats","album":"The Wombats Proudly Present... This Modern Glitch","type":"song","duration":225,"albumart":"https://i.scdn.co/image/ab67616d0000b27367c138b47ef3788cd065c35a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:04 musicpi volumio[1048]: info: Exploding uri spotify:track:6MLO0mKNsJ6opIC31CchnM in service spop Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:6MLO0mKNsJ6opIC31CchnM Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0HzZB3Z6gIk3VOlS5WjT49","service":"spop","name":"Everything's Electric","artist":"Liam Gallagher","album":"C’MON YOU KNOW (Deluxe Edition)","type":"song","duration":216,"albumart":"https://i.scdn.co/image/ab67616d0000b273e36376a9c9d5b63ab8893476","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:04 musicpi volumio[1048]: info: Exploding uri spotify:track:4wCsnvMyDboBxSDgipm2z0 in service spop Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:4wCsnvMyDboBxSDgipm2z0 Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2EtZFeLn9msgg4qJzT9Vql","service":"spop","name":"Can't Stand Me Now","artist":"The Libertines","album":"The Libertines","type":"song","duration":203,"albumart":"https://i.scdn.co/image/ab67616d0000b273062515b0a2268faf7bdad20e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:04 musicpi volumio[1048]: info: Exploding uri spotify:track:0UgHw2x3Nnocajvx62noEn in service spop Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:0UgHw2x3Nnocajvx62noEn Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6MLO0mKNsJ6opIC31CchnM","service":"spop","name":"Call Me Out","artist":"Sea Girls","album":"Call Me Out","type":"song","duration":235,"albumart":"https://i.scdn.co/image/ab67616d0000b27341d48379d36b5d8494159ad4","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:04 musicpi volumio[1048]: info: Exploding uri spotify:track:0JAQUGJudVlhRoAqqhVoYX in service spop Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:0JAQUGJudVlhRoAqqhVoYX Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4wCsnvMyDboBxSDgipm2z0","service":"spop","name":"Farewell To The Fairground","artist":"White Lies","album":"To Lose My Life... (Bonus remix version)","type":"song","duration":256,"albumart":"https://i.scdn.co/image/ab67616d0000b273a5e8c52572e7bb4765c78f42","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:04 musicpi volumio[1048]: info: Exploding uri spotify:track:4dRqYKhLVujxiBXcq50YzG in service spop Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:4dRqYKhLVujxiBXcq50YzG Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0UgHw2x3Nnocajvx62noEn","service":"spop","name":"Living for the Weekend","artist":"Hard-Fi","album":"Stars Of CCTV","type":"song","duration":222,"albumart":"https://i.scdn.co/image/ab67616d0000b273004382bc4ed93d0ac65523fd","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:04 musicpi volumio[1048]: info: Exploding uri spotify:track:4MUkX9MV0PazAf0VibU2JP in service spop Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:4MUkX9MV0PazAf0VibU2JP Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0JAQUGJudVlhRoAqqhVoYX","service":"spop","name":"All My Friends Are Falling In Love","artist":"The Vaccines","album":"All My Friends Are Falling In Love","type":"song","duration":210,"albumart":"https://i.scdn.co/image/ab67616d0000b27385ae3ec17655219b6bfbbe49","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:04 musicpi volumio[1048]: info: Exploding uri spotify:track:3APHT3KjbHi9OllkVQsuXF in service spop Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:3APHT3KjbHi9OllkVQsuXF Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4dRqYKhLVujxiBXcq50YzG","service":"spop","name":"This Life","artist":"Vampire Weekend","album":"Father of the Bride","type":"song","duration":268,"albumart":"https://i.scdn.co/image/ab67616d0000b273a2b1d3e73c66663c01351bcf","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:04 musicpi volumio[1048]: info: Exploding uri spotify:track:4z86ZEcMLofosRyJMqBkIz in service spop Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:4z86ZEcMLofosRyJMqBkIz Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4MUkX9MV0PazAf0VibU2JP","service":"spop","name":"Ashes","artist":"Embrace","album":"Ashes","type":"song","duration":262,"albumart":"https://i.scdn.co/image/ab67616d0000b273e0bc6a816f591a0782e7780f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:04 musicpi volumio[1048]: info: Exploding uri spotify:track:5JSF5Nhw9W6j9qt74rYTa7 in service spop Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:5JSF5Nhw9W6j9qt74rYTa7 Oct 16 16:02:04 musicpi volumio[1048]: info: Exploding uri spotify:track:7v9Ne4758aGFfFc5avh89h in service spop Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:7v9Ne4758aGFfFc5avh89h Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3APHT3KjbHi9OllkVQsuXF","service":"spop","name":"Bohemian Like You","artist":"The Dandy Warhols","album":"Thirteen Tales From Urban Bohemia","type":"song","duration":211,"albumart":"https://i.scdn.co/image/ab67616d0000b2735f13db82827b6abb7e31a488","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4z86ZEcMLofosRyJMqBkIz","service":"spop","name":"Seventeen Going Under - Edit","artist":"Sam Fender","album":"Seventeen Going Under","type":"song","duration":237,"albumart":"https://i.scdn.co/image/ab67616d0000b273504b74c88ce63e33826c553b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:04 musicpi volumio[1048]: info: Exploding uri spotify:track:0Dkew1fJuIAnuoHXc8pMTm in service spop Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:0Dkew1fJuIAnuoHXc8pMTm Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5JSF5Nhw9W6j9qt74rYTa7","service":"spop","name":"Two Doors Down","artist":"Mystery Jets","album":"Twenty One","type":"song","duration":219,"albumart":"https://i.scdn.co/image/ab67616d0000b273239b127ed531aca91ca7d3ec","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:04 musicpi volumio[1048]: info: Exploding uri spotify:track:1xDPUKoyQuIiea7Le9ZNgn in service spop Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:1xDPUKoyQuIiea7Le9ZNgn Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7v9Ne4758aGFfFc5avh89h","service":"spop","name":"Let's Dance to Joy Division","artist":"The Wombats","album":"Proudly Present... A Guide to Love, Loss & Desperation","type":"song","duration":191,"albumart":"https://i.scdn.co/image/ab67616d0000b273506a7ea3d6224d687b72940c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:04 musicpi volumio[1048]: info: Exploding uri spotify:track:2sqtkSLyuo3hdpnp0gyVCq in service spop Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:track:2sqtkSLyuo3hdpnp0gyVCq Oct 16 16:02:04 musicpi volumio[1048]: info: Preload queue cleared Oct 16 16:02:04 musicpi volumio[1048]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 16 16:02:04 musicpi volumio[1048]: info: CoreStateMachine::ClearQueue Oct 16 16:02:04 musicpi volumio[1048]: info: CoreStateMachine::stop Oct 16 16:02:04 musicpi volumio[1048]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 16:02:04 musicpi volumio[1048]: info: CorePlayQueue::clearPlayQueue Oct 16 16:02:04 musicpi volumio[1048]: info: CorePlayQueue::saveQueue Oct 16 16:02:04 musicpi volumio[1048]: info: CoreCommandRouter::volumioPushQueue Oct 16 16:02:04 musicpi volumio[1048]: info: CoreStateMachine::addQueueItems Oct 16 16:02:04 musicpi volumio[1048]: info: CorePlayQueue::addQueueItems Oct 16 16:02:04 musicpi volumio[1048]: info: Preload queue cleared Oct 16 16:02:04 musicpi volumio[1048]: info: Adding Item to queue: spotify:user:spotify:playlist:3blt6iZnPaYo6DPjIQjdNg Oct 16 16:02:04 musicpi volumio[1048]: info: Exploding uri spotify:user:spotify:playlist:3blt6iZnPaYo6DPjIQjdNg in service spop Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: EXPLODING URI:spotify:user:spotify:playlist:3blt6iZnPaYo6DPjIQjdNg Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0Dkew1fJuIAnuoHXc8pMTm","service":"spop","name":"In the Morning","artist":"The Coral","album":"Singles Collection","type":"song","duration":153,"albumart":"https://i.scdn.co/image/ab67616d0000b273d1ef18ed6080229271fe4c31","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1xDPUKoyQuIiea7Le9ZNgn","service":"spop","name":"Somewhere Else","artist":"Razorlight","album":"Up All Night","type":"song","duration":196,"albumart":"https://i.scdn.co/image/ab67616d0000b273dd959dd9adfd375b32122053","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:04 musicpi volumio[1048]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2sqtkSLyuo3hdpnp0gyVCq","service":"spop","name":"Wetsuit","artist":"The Vaccines","album":"What Did You Expect from The Vaccines?","type":"song","duration":230,"albumart":"https://i.scdn.co/image/ab67616d0000b27373a8b8f4292ed4f6fb53b69c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 16 16:02:05 musicpi volumio[1048]: info: CoreCommandRouter::volumioPushQueue Oct 16 16:02:05 musicpi volumio[1048]: info: CorePlayQueue::saveQueue Oct 16 16:02:05 musicpi volumio[1048]: info: CoreStateMachine::updateTrackBlock Oct 16 16:02:05 musicpi volumio[1048]: info: CorePlayQueue::getTrackBlock Oct 16 16:02:05 musicpi volumio[1048]: info: CoreCommandRouter::volumioPlay Oct 16 16:02:05 musicpi volumio[1048]: info: CoreStateMachine::play index 0 Oct 16 16:02:05 musicpi volumio[1048]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 16:02:05 musicpi volumio[1048]: info: CoreStateMachine::stop Oct 16 16:02:05 musicpi volumio[1048]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 16:02:05 musicpi volumio[1048]: info: CoreStateMachine::play index undefined Oct 16 16:02:05 musicpi volumio[1048]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 16 16:02:05 musicpi volumio[1048]: info: CorePlayQueue::getTrack 0 Oct 16 16:02:05 musicpi volumio[1048]: info: CoreStateMachine::startPlaybackTimer Oct 16 16:02:05 musicpi volumio[1048]: info: CorePlayQueue::getTrack 0 Oct 16 16:02:05 musicpi volumio[1048]: info: [1729119725355] ControllerSpotify::clearAddPlayTrack Oct 16 16:02:05 musicpi volumio[1048]: info: Sending Spotify command with payload to local API: /player/play Oct 16 16:02:05 musicpi go-librespot[12599]: time="2024-10-16T16:02:05-07:00" level=debug msg="resolved context of track" uri="spotify:track:3u1ggZA6C0h2waxIzpT8GE" Oct 16 16:02:05 musicpi go-librespot[12599]: time="2024-10-16T16:02:05-07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:3u1ggZA6C0h2waxIzpT8GE" Oct 16 16:02:05 musicpi go-librespot[12599]: time="2024-10-16T16:02:05-07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3u1ggZA6C0h2waxIzpT8GE" Oct 16 16:02:05 musicpi go-librespot[12599]: time="2024-10-16T16:02:05-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 16 16:02:05 musicpi go-librespot[12599]: time="2024-10-16T16:02:05-07:00" level=trace msg="emitting websocket event: will_play" Oct 16 16:02:05 musicpi volumio[1048]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3u1ggZA6C0h2waxIzpT8GE","play_origin":"go-librespot"}} Oct 16 16:02:05 musicpi volumio[1048]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3u1ggZA6C0h2waxIzpT8GE","play_origin":"go-librespot"}} Oct 16 16:02:05 musicpi go-librespot[12599]: time="2024-10-16T16:02:05-07:00" level=debug msg="selected format OGG_VORBIS_320 (0ba77df9e8b8688eebff1e950e5f9e619bc80dbd)" uri="spotify:track:3u1ggZA6C0h2waxIzpT8GE" Oct 16 16:02:05 musicpi go-librespot[12599]: time="2024-10-16T16:02:05-07:00" level=debug msg="requested aes key for file 0ba77df9e8b8688eebff1e950e5f9e619bc80dbd, gid: 3u1ggZA6C0h2waxIzpT8GE" Oct 16 16:02:05 musicpi go-librespot[12599]: time="2024-10-16T16:02:05-07:00" level=debug msg="fetched first chunk of 18, total size is 8953896 bytes" uri="spotify:track:3u1ggZA6C0h2waxIzpT8GE" Oct 16 16:02:05 musicpi go-librespot[12599]: time="2024-10-16T16:02:05-07:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:3u1ggZA6C0h2waxIzpT8GE" Oct 16 16:02:05 musicpi go-librespot[12599]: ALSA lib /home/pi/volumio-fifo-plugin/src/pcm_volumiofifo.c:753:(_snd_pcm_volumiofifo_open) Failed to open output fifo /tmp/fusiondspfifo Oct 16 16:02:05 musicpi go-librespot[12599]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Oct 16 16:02:05 musicpi go-librespot[12599]: time="2024-10-16T16:02:05-07:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed setting stream for spotify:track:3u1ggZA6C0h2waxIzpT8GE: ALSA error at snd_pcm_open: No such file or directory" Oct 16 16:02:05 musicpi volumio[1048]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Oct 16 16:02:05 musicpi go-librespot[12599]: time="2024-10-16T16:02:05-07:00" level=debug msg="fetched chunk 3/17, size: 524288" uri="spotify:track:3u1ggZA6C0h2waxIzpT8GE" Oct 16 16:02:05 musicpi go-librespot[12599]: time="2024-10-16T16:02:05-07:00" level=debug msg="fetched chunk 2/17, size: 524288" uri="spotify:track:3u1ggZA6C0h2waxIzpT8GE" Oct 16 16:02:06 musicpi go-librespot[12599]: time="2024-10-16T16:02:06-07:00" level=debug msg="fetched chunk 1/17, size: 524288" uri="spotify:track:3u1ggZA6C0h2waxIzpT8GE" Oct 16 16:02:06 musicpi volumio[1048]: error: error Oct 16 16:02:06 musicpi volumio[1048]: error: error Oct 16 16:02:25 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 16 16:02:25 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 16 16:02:25 musicpi volumio[1048]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 16 16:02:33 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 16 16:02:33 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 16 16:02:33 musicpi volumio[1048]: info: Discovery: Getting this device information Oct 16 16:02:33 musicpi volumio[1048]: info: CoreCommandRouter::volumioGetState Oct 16 16:02:33 musicpi volumio[1048]: info: CorePlayQueue::getTrack 0 Oct 16 16:02:33 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 16 16:02:38 musicpi volumio[1048]: info: Enabling plugin fusiondsp Oct 16 16:02:38 musicpi volumio[1048]: info: Loading plugin "fusiondsp"... Oct 16 16:02:38 musicpi volumio[1048]: info: Applying required configuration parameters for plugin fusiondsp Oct 16 16:02:38 musicpi volumio[1048]: info: Preparing to generate the ALSA configuration file Oct 16 16:02:38 musicpi volumio[1048]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 16 16:02:38 musicpi volumio[1048]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Oct 16 16:02:38 musicpi volumio[1048]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Oct 16 16:02:38 musicpi volumio[1048]: info: Reading ALSA contributions from plugins. Oct 16 16:02:38 musicpi volumio[1048]: info: Asound.conf file unchanged, so no further update is needed Oct 16 16:02:38 musicpi volumio[1048]: info: Output device has changed, restarting MPD Oct 16 16:02:38 musicpi sudo[13709]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 16 16:02:38 musicpi sudo[13709]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:02:38 musicpi sudo[13709]: pam_unix(sudo:session): session closed for user root Oct 16 16:02:38 musicpi volumio[1048]: info: Output device has changed, restarting Shairport Sync Oct 16 16:02:38 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:38 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 16:02:38 musicpi sudo[13713]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 16 16:02:38 musicpi sudo[13713]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:02:38 musicpi systemd[1]: Stopping Music Player Daemon... Oct 16 16:02:38 musicpi systemd[1]: mpd.service: Succeeded. Oct 16 16:02:38 musicpi systemd[1]: Stopped Music Player Daemon. Oct 16 16:02:38 musicpi volumio[1048]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 16:02:38 musicpi volumio[1048]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 16 16:02:38 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:38 musicpi systemd[1]: Starting Music Player Daemon... Oct 16 16:02:38 musicpi vtcs[12797]: [2024-10-16 16:02:38.622] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE Oct 16 16:02:38 musicpi vtcs[12797]: [2024-10-16 16:02:38.622] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected Oct 16 16:02:38 musicpi volumio[1048]: info: PLUGIN START: fusiondsp Oct 16 16:02:38 musicpi sudo[13718]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 16 16:02:38 musicpi volumio[1048]: info: Loading i18n strings for locale en Oct 16 16:02:38 musicpi sudo[13718]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:02:38 musicpi sudo[13718]: pam_unix(sudo:session): session closed for user root Oct 16 16:02:38 musicpi sudo[13723]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 16 16:02:38 musicpi sudo[13723]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:02:38 musicpi volumio[1048]: info: Plugin peppyspectrum has duplicated i18n key APPLY. It is ignored. Oct 16 16:02:38 musicpi volumio[1048]: info: Plugin peppyspectrum has duplicated i18n key SAVE. It is ignored. Oct 16 16:02:38 musicpi volumio[1048]: info: Plugin peppyspectrum has duplicated i18n key CLICK_TO_UPDATE_LIST. It is ignored. Oct 16 16:02:38 musicpi volumio[1048]: info: Plugin peppyspectrum has duplicated i18n key LIST_SUCCESS_UPDATED. It is ignored. Oct 16 16:02:38 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Oct 16 16:02:38 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:38 musicpi volumio[1048]: info: FusionDsp - mixtype--------------------- Hardware Oct 16 16:02:38 musicpi volumio[1048]: info: Preparing to generate the ALSA configuration file Oct 16 16:02:38 musicpi volumio[1048]: info: Done. Oct 16 16:02:38 musicpi volumio[1048]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 16 16:02:38 musicpi volumio[1048]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Oct 16 16:02:38 musicpi volumio[1048]: info: The plugin peppyspectrum has an ALSA contribution file peppy_in.peppy_out.6.conf Oct 16 16:02:38 musicpi volumio[1048]: info: Reading ALSA contributions from plugins. Oct 16 16:02:38 musicpi volumio[1048]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 16 16:02:38 musicpi volumio[1048]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 16 16:02:38 musicpi sudo[13728]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 16 16:02:38 musicpi sudo[13728]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:02:38 musicpi systemd[1]: Stopping Volumio Tidal Connect Service... Oct 16 16:02:38 musicpi systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Oct 16 16:02:38 musicpi systemd[1]: vtcs.service: Succeeded. Oct 16 16:02:38 musicpi systemd[1]: Stopped Volumio Tidal Connect Service. Oct 16 16:02:38 musicpi sudo[13723]: pam_unix(sudo:session): session closed for user root Oct 16 16:02:38 musicpi sudo[13728]: pam_unix(sudo:session): session closed for user root Oct 16 16:02:38 musicpi volumio[1048]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 16 16:02:38 musicpi volumio[1048]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 16 16:02:38 musicpi volumio[1048]: info: MPD Permissions set Oct 16 16:02:38 musicpi volumio[1048]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 16 16:02:38 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:38 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:38 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:38 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:38 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:38 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:38 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:38 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:38 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 16:02:38 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: Starting Shairport Sync Oct 16 16:02:39 musicpi sudo[13737]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 16:02:39 musicpi sudo[13737]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: Asound.conf file unchanged, so no further update is needed Oct 16 16:02:39 musicpi volumio[1048]: info: Output device has changed, restarting MPD Oct 16 16:02:39 musicpi systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 16 16:02:39 musicpi systemd[1]: shairport-sync.service: Succeeded. Oct 16 16:02:39 musicpi systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 16 16:02:39 musicpi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 16 16:02:39 musicpi sudo[13737]: pam_unix(sudo:session): session closed for user root Oct 16 16:02:39 musicpi sudo[13741]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 16 16:02:39 musicpi sudo[13741]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:02:39 musicpi sudo[13741]: pam_unix(sudo:session): session closed for user root Oct 16 16:02:39 musicpi volumio[1048]: info: Output device has changed, restarting Shairport Sync Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 16:02:39 musicpi sudo[13746]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 16 16:02:39 musicpi sudo[13746]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:02:39 musicpi systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Oct 16 16:02:39 musicpi systemd[1]: mpd.service: Succeeded. Oct 16 16:02:39 musicpi systemd[1]: Stopped Music Player Daemon. Oct 16 16:02:39 musicpi volumio[1048]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 16 16:02:39 musicpi volumio[1048]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi systemd[1]: Starting Music Player Daemon... Oct 16 16:02:39 musicpi sudo[13751]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 16 16:02:39 musicpi sudo[13751]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:02:39 musicpi sudo[13751]: pam_unix(sudo:session): session closed for user root Oct 16 16:02:39 musicpi sudo[13756]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 16 16:02:39 musicpi sudo[13756]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:02:39 musicpi sudo[13756]: pam_unix(sudo:session): session closed for user root Oct 16 16:02:39 musicpi sudo[13762]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 16 16:02:39 musicpi sudo[13762]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:02:39 musicpi sudo[13762]: pam_unix(sudo:session): session closed for user root Oct 16 16:02:39 musicpi volumio[1048]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 16 16:02:39 musicpi volumio[1048]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 16 16:02:39 musicpi volumio[1048]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 16 16:02:39 musicpi volumio[1048]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 16 16:02:39 musicpi volumio[1048]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 16 16:02:39 musicpi volumio[1048]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 16 16:02:39 musicpi volumio[1048]: info: MPD Permissions set Oct 16 16:02:39 musicpi volumio[1048]: info: Shairport-Sync Started Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:39 musicpi volumio[1048]: info: Starting Shairport Sync Oct 16 16:02:40 musicpi sudo[13770]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 16 16:02:40 musicpi sudo[13770]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 16 16:02:40 musicpi systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 16 16:02:40 musicpi systemd[1]: shairport-sync.service: Succeeded. Oct 16 16:02:40 musicpi systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 16 16:02:40 musicpi volumio[1048]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 16 16:02:40 musicpi volumio[1048]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 16 16:02:40 musicpi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 16 16:02:40 musicpi sudo[13770]: pam_unix(sudo:session): session closed for user root Oct 16 16:02:40 musicpi volumio[1048]: info: Shairport-Sync Started Oct 16 16:02:40 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:40 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:40 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:40 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:40 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:40 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:40 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:40 musicpi volumio[1048]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 16 16:02:40 musicpi volumio[1048]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 16:02:40 musicpi volumio[1048]: TypeError: Cannot read property 'off' of undefined Oct 16 16:02:40 musicpi volumio[1048]: at FusionDsp.onStop (/data/plugins/audio_interface/fusiondsp/index.js:107:15) Oct 16 16:02:40 musicpi volumio[1048]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Oct 16 16:02:40 musicpi volumio[1048]: at PluginManager.disableAndStopPlugin (/volumio/app/pluginmanager.js:1883:8) Oct 16 16:02:40 musicpi volumio[1048]: at CoreCommandRouter.disableAndStopPlugin (/volumio/app/index.js:1537:29) Oct 16 16:02:40 musicpi volumio[1048]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1387:47) Oct 16 16:02:40 musicpi volumio[1048]: at Socket.emit (events.js:315:20) Oct 16 16:02:40 musicpi volumio[1048]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Oct 16 16:02:40 musicpi volumio[1048]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Oct 16 16:02:40 musicpi volumio[1048]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 16 16:02:40 musicpi mpd[13758]: Oct 16 16:02 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 16 16:02:40 musicpi systemd[1]: Started Music Player Daemon. Oct 16 16:02:40 musicpi sudo[13713]: pam_unix(sudo:session): session closed for user root Oct 16 16:02:40 musicpi sudo[13746]: pam_unix(sudo:session): session closed for user root Oct 16 16:02:40 musicpi sudo[13787]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-16 16:01 Oct 16 16:02:40 musicpi sudo[13787]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"