-- Logs begin at Thu 2019-02-14 10:11:59 GMT, end at Tue 2024-10-01 14:09:28 BST. -- Oct 01 14:08:08 boom-box volumio[977]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 01 14:08:08 boom-box volumio[977]: info: In handleBrowseUri, curUri=spotify Oct 01 14:08:08 boom-box volumio[977]: info: Preload queue cleared Oct 01 14:08:14 boom-box volumio[977]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Oct 01 14:08:14 boom-box volumio[977]: info: In handleBrowseUri, curUri=spotify/mytoptracks Oct 01 14:08:15 boom-box volumio[977]: info: Preload queue cleared Oct 01 14:08:15 boom-box volumio[977]: info: Preloading song: spotify:track:17VWTx7LD7liGlpnlGhUbn Oct 01 14:08:15 boom-box volumio[977]: info: Preloading song: spotify:track:18VWSOioe5ys5LF7XxSlUx Oct 01 14:08:15 boom-box volumio[977]: info: Preloading song: spotify:track:1GpzwuXL7m5u8c8jeks3hU Oct 01 14:08:15 boom-box volumio[977]: info: Preloading song: spotify:track:3IWtShbXdE9GnC4MYvH2cB Oct 01 14:08:15 boom-box volumio[977]: info: Preloading song: spotify:track:52IuMfbQa9aqRPz2oYPAI8 Oct 01 14:08:15 boom-box volumio[977]: info: Preloading song: spotify:track:6hTcuIQa0sxrrByu9wTD7s Oct 01 14:08:15 boom-box volumio[977]: info: Preloading song: spotify:track:758wEKVqfYopJIHYWdLVd4 Oct 01 14:08:15 boom-box volumio[977]: info: Preloading song: spotify:track:7KsvRoDsMl4hJx2fs5hS1d Oct 01 14:08:15 boom-box volumio[977]: info: Exploding uri spotify:track:17VWTx7LD7liGlpnlGhUbn in service spop Oct 01 14:08:15 boom-box volumio[977]: SPOTIFY: EXPLODING URI:spotify:track:17VWTx7LD7liGlpnlGhUbn Oct 01 14:08:15 boom-box volumio[977]: info: Exploding uri spotify:track:18VWSOioe5ys5LF7XxSlUx in service spop Oct 01 14:08:15 boom-box volumio[977]: SPOTIFY: EXPLODING URI:spotify:track:18VWSOioe5ys5LF7XxSlUx Oct 01 14:08:15 boom-box volumio[977]: info: Exploding uri spotify:track:1GpzwuXL7m5u8c8jeks3hU in service spop Oct 01 14:08:15 boom-box volumio[977]: SPOTIFY: EXPLODING URI:spotify:track:1GpzwuXL7m5u8c8jeks3hU Oct 01 14:08:15 boom-box volumio[977]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:17VWTx7LD7liGlpnlGhUbn","service":"spop","name":"Lady Marmalade","artist":"LaBelle","album":"Nightbirds","type":"song","duration":237,"albumart":"https://i.scdn.co/image/ab67616d0000b27331ae071f3db459be2501ea13","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 01 14:08:15 boom-box volumio[977]: info: Exploding uri spotify:track:3IWtShbXdE9GnC4MYvH2cB in service spop Oct 01 14:08:15 boom-box volumio[977]: SPOTIFY: EXPLODING URI:spotify:track:3IWtShbXdE9GnC4MYvH2cB Oct 01 14:08:15 boom-box volumio[977]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:18VWSOioe5ys5LF7XxSlUx","service":"spop","name":"Pyro","artist":"Kings of Leon","album":"Come Around Sundown (Expanded Edition)","type":"song","duration":250,"albumart":"https://i.scdn.co/image/ab67616d0000b273c186d778178f4315a2c72206","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 01 14:08:15 boom-box volumio[977]: info: Exploding uri spotify:track:52IuMfbQa9aqRPz2oYPAI8 in service spop Oct 01 14:08:15 boom-box volumio[977]: SPOTIFY: EXPLODING URI:spotify:track:52IuMfbQa9aqRPz2oYPAI8 Oct 01 14:08:15 boom-box volumio[977]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1GpzwuXL7m5u8c8jeks3hU","service":"spop","name":"Crazy On The Weekend","artist":"Sunhouse","album":"Crazy On The Weekend","type":"song","duration":125,"albumart":"https://i.scdn.co/image/ab67616d0000b273bf7eda88fbe96d23ee608113","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 01 14:08:15 boom-box volumio[977]: info: Exploding uri spotify:track:6hTcuIQa0sxrrByu9wTD7s in service spop Oct 01 14:08:15 boom-box volumio[977]: SPOTIFY: EXPLODING URI:spotify:track:6hTcuIQa0sxrrByu9wTD7s Oct 01 14:08:15 boom-box volumio[977]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3IWtShbXdE9GnC4MYvH2cB","service":"spop","name":"Where I Find My Heaven","artist":"Gigolo Aunts","album":"Where I Find My Heaven","type":"song","duration":204,"albumart":"https://i.scdn.co/image/ab67616d0000b273edfb068c14a1427d44616edd","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 01 14:08:15 boom-box volumio[977]: info: Exploding uri spotify:track:758wEKVqfYopJIHYWdLVd4 in service spop Oct 01 14:08:15 boom-box volumio[977]: SPOTIFY: EXPLODING URI:spotify:track:758wEKVqfYopJIHYWdLVd4 Oct 01 14:08:15 boom-box volumio[977]: info: Exploding uri spotify:track:7KsvRoDsMl4hJx2fs5hS1d in service spop Oct 01 14:08:15 boom-box volumio[977]: SPOTIFY: EXPLODING URI:spotify:track:7KsvRoDsMl4hJx2fs5hS1d Oct 01 14:08:15 boom-box volumio[977]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6hTcuIQa0sxrrByu9wTD7s","service":"spop","name":"Born to Run","artist":"Bruce Springsteen","album":"Born To Run","type":"song","duration":269,"albumart":"https://i.scdn.co/image/ab67616d0000b273503143a281a3f30268dcd9f9","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 01 14:08:15 boom-box volumio[977]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:52IuMfbQa9aqRPz2oYPAI8","service":"spop","name":"Express Yourself","artist":"N.W.A.","album":"Straight Outta Compton","type":"song","duration":265,"albumart":"https://i.scdn.co/image/ab67616d0000b273c79a70e8167cc1a4fab83781","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 01 14:08:15 boom-box volumio[977]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:758wEKVqfYopJIHYWdLVd4","service":"spop","name":"I Wanna Be Adored - Remastered 2009","artist":"The Stone Roses","album":"The Stone Roses","type":"song","duration":292,"albumart":"https://i.scdn.co/image/ab67616d0000b273cf1f6466a493eb73d6d9d280","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 01 14:08:15 boom-box volumio[977]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7KsvRoDsMl4hJx2fs5hS1d","service":"spop","name":"Lady Jane","artist":"Rotary Connection","album":"Rotary Connection","type":"song","duration":300,"albumart":"https://i.scdn.co/image/ab67616d0000b273ebca4d4c03a6228de245ce99","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Oct 01 14:08:22 boom-box volumio[977]: info: Preload queue cleared Oct 01 14:08:22 boom-box volumio[977]: info: CoreCommandRouter::volumioAddQueueItems Oct 01 14:08:22 boom-box volumio[977]: info: CoreStateMachine::addQueueItems Oct 01 14:08:22 boom-box volumio[977]: info: CorePlayQueue::addQueueItems Oct 01 14:08:22 boom-box volumio[977]: info: Preload queue cleared Oct 01 14:08:22 boom-box volumio[977]: info: Adding Item to queue: spotify:track:1ydGjYPl6SkTBwy6yhRCJT Oct 01 14:08:22 boom-box volumio[977]: info: Using cached record of: spotify:track:1ydGjYPl6SkTBwy6yhRCJT Oct 01 14:08:22 boom-box volumio[977]: info: CoreCommandRouter::volumioPushQueue Oct 01 14:08:22 boom-box volumio[977]: info: CorePlayQueue::saveQueue Oct 01 14:08:22 boom-box volumio[977]: info: CoreStateMachine::updateTrackBlock Oct 01 14:08:22 boom-box volumio[977]: info: CorePlayQueue::getTrackBlock Oct 01 14:08:22 boom-box volumio[977]: info: CoreCommandRouter::volumioPlay Oct 01 14:08:22 boom-box volumio[977]: info: CoreStateMachine::play index 6 Oct 01 14:08:22 boom-box volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 01 14:08:22 boom-box volumio[977]: info: CoreStateMachine::stop Oct 01 14:08:22 boom-box volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 01 14:08:22 boom-box volumio[977]: info: CoreStateMachine::play index undefined Oct 01 14:08:22 boom-box volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 01 14:08:22 boom-box volumio[977]: info: CorePlayQueue::getTrack 6 Oct 01 14:08:22 boom-box volumio[977]: info: CoreStateMachine::startPlaybackTimer Oct 01 14:08:22 boom-box volumio[977]: info: CorePlayQueue::getTrack 6 Oct 01 14:08:22 boom-box volumio[977]: info: CoreCommandRouter::volumioGetVisibleSources Oct 01 14:08:22 boom-box volumio[977]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 01 14:08:22 boom-box volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 01 14:08:22 boom-box volumio[977]: info: [1727788102036] ControllerSpotify::clearAddPlayTrack Oct 01 14:08:22 boom-box volumio[977]: info: Sending Spotify command with payload to local API: /player/play Oct 01 14:08:22 boom-box go-librespot[1252]: time="2024-10-01T14:08:22+01:00" level=debug msg="resolved context of track" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:22 boom-box go-librespot[1252]: time="2024-10-01T14:08:22+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:22 boom-box go-librespot[1252]: time="2024-10-01T14:08:22+01:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:22 boom-box go-librespot[1252]: time="2024-10-01T14:08:22+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 01 14:08:22 boom-box go-librespot[1252]: time="2024-10-01T14:08:22+01:00" level=trace msg="emitting websocket event: will_play" Oct 01 14:08:22 boom-box volumio[977]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1ydGjYPl6SkTBwy6yhRCJT","play_origin":"go-librespot"}} Oct 01 14:08:22 boom-box go-librespot[1252]: time="2024-10-01T14:08:22+01:00" level=debug msg="selected format OGG_VORBIS_320 (3414aa33aa5403139eb152b79e8d47c8b2e8accd)" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:22 boom-box go-librespot[1252]: time="2024-10-01T14:08:22+01:00" level=debug msg="requested aes key for file 3414aa33aa5403139eb152b79e8d47c8b2e8accd, gid: 1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:22 boom-box go-librespot[1252]: time="2024-10-01T14:08:22+01:00" level=debug msg="fetched first chunk of 32, total size is 16629016 bytes" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:22 boom-box go-librespot[1252]: time="2024-10-01T14:08:22+01:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:22 boom-box go-librespot[1252]: ALSA lib pcm_softvol.c:778:(softvol_load_control) Cannot open CTL hw:2 Oct 01 14:08:22 boom-box go-librespot[1252]: 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 01 14:08:22 boom-box go-librespot[1252]: time="2024-10-01T14:08:22+01:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed setting stream for spotify:track:1ydGjYPl6SkTBwy6yhRCJT: ALSA error at snd_pcm_open: No such file or directory" Oct 01 14:08:22 boom-box volumio[977]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Oct 01 14:08:22 boom-box kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Oct 01 14:08:22 boom-box go-librespot[1252]: time="2024-10-01T14:08:22+01:00" level=debug msg="fetched chunk 2/31, size: 524288" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:22 boom-box go-librespot[1252]: time="2024-10-01T14:08:22+01:00" level=debug msg="fetched chunk 3/31, size: 524288" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:22 boom-box go-librespot[1252]: time="2024-10-01T14:08:22+01:00" level=debug msg="fetched chunk 1/31, size: 524288" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:23 boom-box volumio[977]: info: CoreCommandRouter::volumioPlay Oct 01 14:08:23 boom-box volumio[977]: info: CoreStateMachine::play index undefined Oct 01 14:08:23 boom-box volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 01 14:08:23 boom-box volumio[977]: info: CorePlayQueue::getTrack 6 Oct 01 14:08:23 boom-box volumio[977]: info: CoreStateMachine::startPlaybackTimer Oct 01 14:08:23 boom-box volumio[977]: info: CorePlayQueue::getTrack 6 Oct 01 14:08:23 boom-box volumio[977]: info: CoreCommandRouter::volumioGetVisibleSources Oct 01 14:08:23 boom-box volumio[977]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 01 14:08:23 boom-box volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 01 14:08:23 boom-box volumio[977]: info: [1727788103052] ControllerSpotify::clearAddPlayTrack Oct 01 14:08:23 boom-box volumio[977]: info: Sending Spotify command with payload to local API: /player/play Oct 01 14:08:23 boom-box go-librespot[1252]: time="2024-10-01T14:08:23+01:00" level=debug msg="resolved context of track" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:23 boom-box go-librespot[1252]: time="2024-10-01T14:08:23+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:23 boom-box go-librespot[1252]: time="2024-10-01T14:08:23+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:23 boom-box go-librespot[1252]: time="2024-10-01T14:08:23+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 01 14:08:23 boom-box go-librespot[1252]: time="2024-10-01T14:08:23+01:00" level=trace msg="emitting websocket event: will_play" Oct 01 14:08:23 boom-box volumio[977]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1ydGjYPl6SkTBwy6yhRCJT","play_origin":"go-librespot"}} Oct 01 14:08:23 boom-box go-librespot[1252]: time="2024-10-01T14:08:23+01:00" level=debug msg="selected format OGG_VORBIS_320 (3414aa33aa5403139eb152b79e8d47c8b2e8accd)" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:23 boom-box go-librespot[1252]: time="2024-10-01T14:08:23+01:00" level=debug msg="requested aes key for file 3414aa33aa5403139eb152b79e8d47c8b2e8accd, gid: 1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:23 boom-box go-librespot[1252]: time="2024-10-01T14:08:23+01:00" level=debug msg="fetched first chunk of 32, total size is 16629016 bytes" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:23 boom-box go-librespot[1252]: time="2024-10-01T14:08:23+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:23 boom-box go-librespot[1252]: ALSA lib pcm_softvol.c:778:(softvol_load_control) Cannot open CTL hw:2 Oct 01 14:08:23 boom-box go-librespot[1252]: 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 01 14:08:23 boom-box go-librespot[1252]: time="2024-10-01T14:08:23+01:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed setting stream for spotify:track:1ydGjYPl6SkTBwy6yhRCJT: ALSA error at snd_pcm_open: No such file or directory" Oct 01 14:08:23 boom-box volumio[977]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Oct 01 14:08:23 boom-box kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Oct 01 14:08:23 boom-box go-librespot[1252]: time="2024-10-01T14:08:23+01:00" level=debug msg="fetched chunk 3/31, size: 524288" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:23 boom-box go-librespot[1252]: time="2024-10-01T14:08:23+01:00" level=debug msg="fetched chunk 1/31, size: 524288" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:23 boom-box go-librespot[1252]: time="2024-10-01T14:08:23+01:00" level=debug msg="fetched chunk 2/31, size: 524288" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:24 boom-box volumio[977]: info: CoreCommandRouter::volumioPlay Oct 01 14:08:24 boom-box volumio[977]: info: CoreStateMachine::play index undefined Oct 01 14:08:24 boom-box volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 01 14:08:24 boom-box volumio[977]: info: CorePlayQueue::getTrack 6 Oct 01 14:08:24 boom-box volumio[977]: info: CoreStateMachine::startPlaybackTimer Oct 01 14:08:24 boom-box volumio[977]: info: CorePlayQueue::getTrack 6 Oct 01 14:08:24 boom-box volumio[977]: info: CoreCommandRouter::volumioGetVisibleSources Oct 01 14:08:24 boom-box volumio[977]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 01 14:08:24 boom-box volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 01 14:08:24 boom-box volumio[977]: info: [1727788104431] ControllerSpotify::clearAddPlayTrack Oct 01 14:08:24 boom-box volumio[977]: info: Sending Spotify command with payload to local API: /player/play Oct 01 14:08:24 boom-box go-librespot[1252]: time="2024-10-01T14:08:24+01:00" level=debug msg="resolved context of track" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:24 boom-box go-librespot[1252]: time="2024-10-01T14:08:24+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:24 boom-box go-librespot[1252]: time="2024-10-01T14:08:24+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:24 boom-box go-librespot[1252]: time="2024-10-01T14:08:24+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 01 14:08:24 boom-box go-librespot[1252]: time="2024-10-01T14:08:24+01:00" level=trace msg="emitting websocket event: will_play" Oct 01 14:08:24 boom-box volumio[977]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1ydGjYPl6SkTBwy6yhRCJT","play_origin":"go-librespot"}} Oct 01 14:08:24 boom-box go-librespot[1252]: time="2024-10-01T14:08:24+01:00" level=debug msg="selected format OGG_VORBIS_320 (3414aa33aa5403139eb152b79e8d47c8b2e8accd)" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:24 boom-box go-librespot[1252]: time="2024-10-01T14:08:24+01:00" level=debug msg="requested aes key for file 3414aa33aa5403139eb152b79e8d47c8b2e8accd, gid: 1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:24 boom-box go-librespot[1252]: time="2024-10-01T14:08:24+01:00" level=debug msg="fetched first chunk of 32, total size is 16629016 bytes" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:24 boom-box go-librespot[1252]: time="2024-10-01T14:08:24+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:24 boom-box go-librespot[1252]: ALSA lib pcm_softvol.c:778:(softvol_load_control) Cannot open CTL hw:2 Oct 01 14:08:24 boom-box go-librespot[1252]: 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 01 14:08:24 boom-box kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Oct 01 14:08:24 boom-box go-librespot[1252]: time="2024-10-01T14:08:24+01:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed setting stream for spotify:track:1ydGjYPl6SkTBwy6yhRCJT: ALSA error at snd_pcm_open: No such file or directory" Oct 01 14:08:24 boom-box volumio[977]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Oct 01 14:08:25 boom-box go-librespot[1252]: time="2024-10-01T14:08:25+01:00" level=debug msg="fetched chunk 3/31, size: 524288" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:25 boom-box go-librespot[1252]: time="2024-10-01T14:08:25+01:00" level=debug msg="fetched chunk 1/31, size: 524288" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:25 boom-box go-librespot[1252]: time="2024-10-01T14:08:25+01:00" level=debug msg="fetched chunk 2/31, size: 524288" uri="spotify:track:1ydGjYPl6SkTBwy6yhRCJT" Oct 01 14:08:33 boom-box volumio[977]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 01 14:08:33 boom-box volumio[977]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 01 14:08:41 boom-box volumiologrotate[645]: ls: cannot access '/var/log/samba/log.wb-BOOM': No such file or directory Oct 01 14:08:41 boom-box volumiologrotate[645]: ls: cannot access 'BOX': No such file or directory Oct 01 14:08:50 boom-box volumio[977]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 01 14:09:17 boom-box volumio[977]: info: CALLMETHOD: user_interface touch_display saveScaleConf [object Object] Oct 01 14:09:17 boom-box volumio[977]: info: CoreCommandRouter::executeOnPlugin: touch_display , saveScaleConf Oct 01 14:09:19 boom-box volumio[977]: info: CALLMETHOD: user_interface touch_display saveScaleConf [object Object] Oct 01 14:09:19 boom-box volumio[977]: info: CoreCommandRouter::executeOnPlugin: touch_display , saveScaleConf Oct 01 14:09:19 boom-box sudo[2528]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sed -i -e s/factor=.* /factor=0.85 / /opt/volumiokiosk.sh Oct 01 14:09:19 boom-box sudo[2528]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 14:09:19 boom-box sudo[2528]: pam_unix(sudo:session): session closed for user root Oct 01 14:09:19 boom-box sudo[2536]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-kiosk.service Oct 01 14:09:19 boom-box sudo[2536]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 14:09:19 boom-box startx[1249]: xinit: connection to X server lost Oct 01 14:09:19 boom-box startx[1249]: [1B blob data] Oct 01 14:09:19 boom-box systemd[1]: Stopping Volumio Kiosk... Oct 01 14:09:19 boom-box volumio[977]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 01 14:09:20 boom-box startx[1249]: waiting for X server to shut down (II) Server terminated successfully (0). Closing log file. Oct 01 14:09:20 boom-box sudo[2546]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sed -i -e s/factor=.* /factor=0.85 / /opt/volumiokiosk.sh Oct 01 14:09:20 boom-box sudo[2546]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 14:09:20 boom-box sudo[2546]: pam_unix(sudo:session): session closed for user root Oct 01 14:09:20 boom-box sudo[2549]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-kiosk.service Oct 01 14:09:20 boom-box sudo[2549]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 01 14:09:20 boom-box volumio[977]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 01 14:09:21 boom-box startx[1249]: . Oct 01 14:09:21 boom-box startx[1249]: xinit: unexpected signal 15 Oct 01 14:09:21 boom-box systemd[1]: volumio-kiosk.service: Main process exited, code=exited, status=1/FAILURE Oct 01 14:09:21 boom-box systemd[1]: volumio-kiosk.service: Failed with result 'exit-code'. Oct 01 14:09:21 boom-box systemd[1]: Stopped Volumio Kiosk. Oct 01 14:09:21 boom-box volumio[977]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 01 14:09:21 boom-box systemd[1]: Started Volumio Kiosk. Oct 01 14:09:21 boom-box sudo[2549]: pam_unix(sudo:session): session closed for user root Oct 01 14:09:21 boom-box sudo[2536]: pam_unix(sudo:session): session closed for user root Oct 01 14:09:21 boom-box volumio[977]: info: touch_display: systemctl restart volumio-kiosk.service succeeded. Oct 01 14:09:21 boom-box volumio[977]: info: touch_display: Volumio Kiosk restarted. Oct 01 14:09:22 boom-box volumio[977]: info: touch_display: systemctl restart volumio-kiosk.service succeeded. Oct 01 14:09:22 boom-box volumio[977]: info: touch_display: Volumio Kiosk restarted. Oct 01 14:09:22 boom-box volumio[977]: info: touch_display: X display number found: Oct 01 14:09:22 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:22 boom-box startx[2554]: X.Org X Server 1.20.4 Oct 01 14:09:22 boom-box startx[2554]: X Protocol Version 11, Revision 0 Oct 01 14:09:22 boom-box startx[2554]: Build Operating System: Linux 5.4.0-109-generic armv8l Raspbian Oct 01 14:09:22 boom-box startx[2554]: Current Operating System: Linux boom-box 6.1.69-v7+ #1710 SMP Thu Dec 21 13:14:13 GMT 2023 armv7l Oct 01 14:09:22 boom-box startx[2554]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 snd_bcm2835.enable_headphones=1 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=800 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=UUID=0c3a77ec-ae84-4f1b-8028-c61cc251ffe5 imgfile=/volumio_current.sqsh bootpart=UUID=41CA-9A8B datapart=UUID=0324d53a-d066-482b-b659-eb98af2b49e7 uuidconfig=cmdline.txt pcie_aspm=off pci=pcie_bus_safe rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Oct 01 14:09:22 boom-box startx[2554]: Build Date: 04 April 2023 07:50:56AM Oct 01 14:09:22 boom-box startx[2554]: xorg-server 2:1.20.4-1+rpt4+deb10u9 (https://www.debian.org/support) Oct 01 14:09:22 boom-box startx[2554]: Current version of pixman: 0.36.0 Oct 01 14:09:22 boom-box startx[2554]: Before reporting problems, check http://wiki.x.org Oct 01 14:09:22 boom-box startx[2554]: to make sure that you have the latest version. Oct 01 14:09:22 boom-box startx[2554]: Markers: (--) probed, (**) from config file, (==) default setting, Oct 01 14:09:22 boom-box startx[2554]: (++) from command line, (!!) notice, (II) informational, Oct 01 14:09:22 boom-box startx[2554]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Oct 01 14:09:22 boom-box startx[2554]: (==) Log file: "/var/log/Xorg.0.log", Time: Tue Oct 1 14:09:22 2024 Oct 01 14:09:22 boom-box startx[2554]: (==) Using config directory: "/etc/X11/xorg.conf.d" Oct 01 14:09:22 boom-box startx[2554]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Oct 01 14:09:22 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:22 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:22 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:22 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:22 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:22 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:22 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:22 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:22 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:22 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:22 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:22 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:22 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:23 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:24 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:25 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:26 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:26 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:26 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:26 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:26 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:26 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:26 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:26 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:26 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:26 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:26 boom-box volumio[977]: info: touch_display: X display number found: 0 Oct 01 14:09:26 boom-box volumio[977]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Oct 01 14:09:26 boom-box volumio[977]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Oct 01 14:09:26 boom-box volumio[977]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 01 14:09:26 boom-box volumio[977]: Error: connect EISCONN /tmp/.X11-unix/X0 Oct 01 14:09:26 boom-box volumio[977]: at PipeConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Oct 01 14:09:26 boom-box volumio[977]: errno: -106, Oct 01 14:09:26 boom-box volumio[977]: code: 'EISCONN', Oct 01 14:09:26 boom-box volumio[977]: syscall: 'connect', Oct 01 14:09:26 boom-box volumio[977]: address: '/tmp/.X11-unix/X0' Oct 01 14:09:26 boom-box volumio[977]: } Oct 01 14:09:26 boom-box volumio[977]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 01 14:09:28 boom-box sudo[2935]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-01 14:08 Oct 01 14:09:28 boom-box sudo[2935]: 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"