-- Logs begin at Sat 2025-06-21 16:36:58 MDT, end at Sat 2025-06-21 16:41:15 MDT. -- Jun 21 16:40:18 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:18-06:00" level=trace msg="sent dealer ping" Jun 21 16:40:18 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:18-06:00" level=trace msg="received dealer pong" Jun 21 16:40:41 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:41-06:00" level=debug msg="handling resume player command from 04ee301e2b0b6843e7299719a9a2ddeadbc2708c" Jun 21 16:40:41 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:41-06:00" level=trace msg="seek to 34605ms (diff: 44ms, samples: 1526080, bytes: 1183949)" uri="spotify:track:38s4sbLZood2eUTelSO3ow" Jun 21 16:40:41 minidsp-shd go-librespot[1425]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:257:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 22050, but target_pcm volumioOutput has buffer size 4096 Jun 21 16:40:41 minidsp-shd go-librespot[1425]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:268:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 22050, but target_pcm volumioOutput has buffer size 4096 Jun 21 16:40:41 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:41-06:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" Jun 21 16:40:41 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:41-06:00" level=debug msg="resume track at 34561ms" Jun 21 16:40:41 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:41-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 21 16:40:41 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:41-06:00" level=trace msg="scheduling prefetch in 160s" Jun 21 16:40:41 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:41-06:00" level=debug msg="sending successful reply for dealer request" Jun 21 16:40:41 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:41-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 21 16:40:41 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:41-06:00" level=trace msg="emitting websocket event: playing" Jun 21 16:40:41 minidsp-shd volumio[784]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:38s4sbLZood2eUTelSO3ow","play_origin":"album"}} Jun 21 16:40:41 minidsp-shd volumio[784]: SPOTIFY: PUSH STATE SPOTIFY Jun 21 16:40:41 minidsp-shd volumio[784]: SPOTIFY: {"status":"play","service":"spop","title":"Peer Gynt Suite No. 1, Op. 46: I. Morning Mood","artist":"Edvard Grieg, David Parry, London Philharmonic Orchestra","album":"The 50 Greatest Pieces of Classical Music","albumart":"https://i.scdn.co/image/ab67616d00001e0276206bd8de3a477aafd7ba83","uri":"spotify:track:38s4sbLZood2eUTelSO3ow","trackType":"spotify","seek":15000,"duration":224,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 21 16:40:41 minidsp-shd volumio[784]: info: CoreCommandRouter::servicePushState Jun 21 16:40:41 minidsp-shd volumio[784]: info: CoreStateMachine::pushState Jun 21 16:40:41 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 21 16:40:41 minidsp-shd volumio[784]: info: CoreCommandRouter::volumioPushState Jun 21 16:40:41 minidsp-shd volumio[784]: info: MRS: Pushing multiroomSync output update for this device Jun 21 16:40:41 minidsp-shd volumio[784]: info: MRS: Pushing multiroomSync output Jun 21 16:40:42 minidsp-shd go-librespot[1425]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:912:(_snd_pcm_volumioswitch_advance) PCM volumioMultiRoomServer cannot write to target PCM volumioOutput as it has failed its update check. Jun 21 16:40:42 minidsp-shd volumio[784]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Jun 21 16:40:42 minidsp-shd volumio[784]: SPOTIFY: PUSH STATE SPOTIFY Jun 21 16:40:42 minidsp-shd volumio[784]: SPOTIFY: {"status":"play","service":"spop","title":"Peer Gynt Suite No. 1, Op. 46: I. Morning Mood","artist":"Edvard Grieg, David Parry, London Philharmonic Orchestra","album":"The 50 Greatest Pieces of Classical Music","albumart":"https://i.scdn.co/image/ab67616d00001e0276206bd8de3a477aafd7ba83","uri":"spotify:track:38s4sbLZood2eUTelSO3ow","trackType":"spotify","seek":15000,"duration":224,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 21 16:40:42 minidsp-shd volumio[784]: info: CoreCommandRouter::servicePushState Jun 21 16:40:42 minidsp-shd volumio[784]: info: CoreStateMachine::pushState Jun 21 16:40:42 minidsp-shd volumio[784]: info: CoreCommandRouter::volumioPushState Jun 21 16:40:42 minidsp-shd volumio[784]: info: MRS: Pushing multiroomSync output update for this device Jun 21 16:40:42 minidsp-shd volumio[784]: info: MRS: Pushing multiroomSync output Jun 21 16:40:42 minidsp-shd volumio[784]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Jun 21 16:40:42 minidsp-shd go-librespot[1425]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:912:(_snd_pcm_volumioswitch_advance) PCM volumioMultiRoomServer cannot write to target PCM volumioOutput as it has failed its update check. Jun 21 16:40:42 minidsp-shd go-librespot[1425]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:912:(_snd_pcm_volumioswitch_advance) PCM volumioMultiRoomServer cannot write to target PCM volumioOutput as it has failed its update check. Jun 21 16:40:43 minidsp-shd go-librespot[1425]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:912:(_snd_pcm_volumioswitch_advance) PCM volumioMultiRoomServer cannot write to target PCM volumioOutput as it has failed its update check. Jun 21 16:40:43 minidsp-shd go-librespot[1425]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:912:(_snd_pcm_volumioswitch_advance) PCM volumioMultiRoomServer cannot write to target PCM volumioOutput as it has failed its update check. Jun 21 16:40:43 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:43-06:00" level=debug msg="handling pause player command from 04ee301e2b0b6843e7299719a9a2ddeadbc2708c" Jun 21 16:40:43 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:43-06:00" level=debug msg="pause track at 38236ms" Jun 21 16:40:43 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:43-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 21 16:40:43 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:43-06:00" level=debug msg="sending successful reply for dealer request" Jun 21 16:40:43 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:43-06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 21 16:40:43 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:43-06:00" level=trace msg="emitting websocket event: paused" Jun 21 16:40:43 minidsp-shd volumio[784]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:38s4sbLZood2eUTelSO3ow","play_origin":"album"}} Jun 21 16:40:43 minidsp-shd volumio[784]: SPOTIFY: PUSH STATE SPOTIFY Jun 21 16:40:43 minidsp-shd volumio[784]: SPOTIFY: {"status":"pause","service":"spop","title":"Peer Gynt Suite No. 1, Op. 46: I. Morning Mood","artist":"Edvard Grieg, David Parry, London Philharmonic Orchestra","album":"The 50 Greatest Pieces of Classical Music","albumart":"https://i.scdn.co/image/ab67616d00001e0276206bd8de3a477aafd7ba83","uri":"spotify:track:38s4sbLZood2eUTelSO3ow","trackType":"spotify","seek":16000,"duration":224,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 21 16:40:43 minidsp-shd volumio[784]: info: CoreCommandRouter::servicePushState Jun 21 16:40:43 minidsp-shd volumio[784]: info: CoreStateMachine::pushState Jun 21 16:40:43 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 21 16:40:43 minidsp-shd volumio[784]: info: CoreCommandRouter::volumioPushState Jun 21 16:40:43 minidsp-shd volumio[784]: info: MRS: Pushing multiroomSync output update for this device Jun 21 16:40:43 minidsp-shd volumio[784]: info: MRS: Pushing multiroomSync output Jun 21 16:40:43 minidsp-shd volumio[784]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72 Jun 21 16:40:48 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:48-06:00" level=trace msg="received accesspoint ping" Jun 21 16:40:48 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:48-06:00" level=trace msg="received accesspoint pong ack" Jun 21 16:40:48 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:48-06:00" level=trace msg="sent dealer ping" Jun 21 16:40:48 minidsp-shd go-librespot[1425]: time="2025-06-21T16:40:48-06:00" level=trace msg="received dealer pong" Jun 21 16:40:51 minidsp-shd volumio[784]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 21 16:40:51 minidsp-shd volumio[784]: xcb_connection_has_error() returned true Jun 21 16:40:51 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jun 21 16:40:51 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 21 16:40:51 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 21 16:40:51 minidsp-shd volumio[784]: xcb_connection_has_error() returned true Jun 21 16:40:51 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 21 16:40:51 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 21 16:40:51 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 21 16:40:51 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 21 16:40:51 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 21 16:40:51 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 21 16:40:51 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 21 16:40:51 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jun 21 16:40:51 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 21 16:40:58 minidsp-shd volumio[784]: info: CoreCommandRouter::volumioGetState Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 21 16:40:59 minidsp-shd volumio[784]: info: Retrieving Cloud Streaming UI Jun 21 16:40:59 minidsp-shd volumio[784]: info: Getting Tidal Cloud Configuration Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 21 16:40:59 minidsp-shd volumio[784]: info: Getting Qobuz Cloud Configuration Jun 21 16:40:59 minidsp-shd volumio[784]: info: Asking plugin for UI Config Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 21 16:40:59 minidsp-shd volumio[784]: info: Getting Spotify Cloud Configuration Jun 21 16:40:59 minidsp-shd volumio[784]: info: Asking plugin for UI Config Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 21 16:40:59 minidsp-shd volumio[784]: info: Saving Spotify Acccount Jun 21 16:40:59 minidsp-shd volumio[784]: info: Got it Jun 21 16:40:59 minidsp-shd volumio[784]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jun 21 16:40:59 minidsp-shd volumio[784]: info: Got Tidal Cloud Configuration Jun 21 16:40:59 minidsp-shd volumio[784]: info: Got it Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::volumioGetBrowseSources Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::volumioGetBrowseSources Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::volumioGetBrowseSources Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 21 16:40:59 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jun 21 16:41:00 minidsp-shd volumio[784]: info: Executing endpoint metavolumio Jun 21 16:41:00 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 21 16:41:00 minidsp-shd volumio[784]: info: Executing endpoint metavolumio Jun 21 16:41:00 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 21 16:41:00 minidsp-shd volumio[784]: info: Executing endpoint metavolumio Jun 21 16:41:00 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 21 16:41:03 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 21 16:41:06 minidsp-shd volumio[784]: info: Disabling MyMusic plugin upnp Jun 21 16:41:06 minidsp-shd sudo[1557]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Jun 21 16:41:06 minidsp-shd sudo[1557]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 16:41:06 minidsp-shd systemd[1]: Stopping UPnP Renderer front-end to MPD... Jun 21 16:41:06 minidsp-shd volumio[784]: error: Upnp client error: Error: This socket has been ended by the other party Jun 21 16:41:06 minidsp-shd volumio[784]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 21 16:41:07 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 21 16:41:11 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jun 21 16:41:14 minidsp-shd volumio[784]: info: Enabling MyMusic plugin upnp Jun 21 16:41:14 minidsp-shd volumio[784]: info: Enabling plugin upnp Jun 21 16:41:14 minidsp-shd volumio[784]: info: Loading plugin "upnp"... Jun 21 16:41:14 minidsp-shd volumio[784]: info: [1750545674444] Starting Upmpd Daemon Jun 21 16:41:14 minidsp-shd volumio[784]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 21 16:41:14 minidsp-shd volumio[784]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 21 16:41:14 minidsp-shd volumio[784]: Error: listen EADDRINUSE: address already in use :::6599 Jun 21 16:41:14 minidsp-shd volumio[784]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) Jun 21 16:41:14 minidsp-shd volumio[784]: at listenInCluster (net.js:1379:12) Jun 21 16:41:14 minidsp-shd volumio[784]: at Server.listen (net.js:1465:7) Jun 21 16:41:14 minidsp-shd volumio[784]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Jun 21 16:41:14 minidsp-shd volumio[784]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Jun 21 16:41:14 minidsp-shd volumio[784]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Jun 21 16:41:14 minidsp-shd volumio[784]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jun 21 16:41:14 minidsp-shd volumio[784]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { Jun 21 16:41:14 minidsp-shd volumio[784]: code: 'EADDRINUSE', Jun 21 16:41:14 minidsp-shd volumio[784]: errno: -98, Jun 21 16:41:14 minidsp-shd volumio[784]: syscall: 'listen', Jun 21 16:41:14 minidsp-shd volumio[784]: address: '::', Jun 21 16:41:14 minidsp-shd volumio[784]: port: 6599 Jun 21 16:41:14 minidsp-shd volumio[784]: } Jun 21 16:41:14 minidsp-shd volumio[784]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 21 16:41:15 minidsp-shd sudo[1569]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-21 16:40 Jun 21 16:41:15 minidsp-shd sudo[1569]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="17fcb754ddd6bd152b01008c46cc4ba1ca48bf35" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="281cefcd7a302aa7cfba569185cf7aae19b8c376" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 22 Mar 2024 03:13:25 PM CET" VOLUMIO_VERSION="3.608" VOLUMIO_HARDWARE="nanopineo3" VOLUMIO_DEVICENAME="Nanopi Neo3" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="18533ba33f8f92d7e7e459bb30f70beb"