-- Logs begin at Sun 2025-03-02 13:00:05 CET, end at Sun 2025-03-02 13:10:37 CET. -- Mar 02 13:09:00 lounge go-librespot[3168]: time="2025-03-02T13:09:00+01:00" level=trace msg="received accesspoint ping" Mar 02 13:09:00 lounge go-librespot[3168]: time="2025-03-02T13:09:00+01:00" level=trace msg="received accesspoint pong ack" Mar 02 13:09:00 lounge go-librespot[3168]: time="2025-03-02T13:09:00+01:00" level=trace msg="sent dealer ping" Mar 02 13:09:00 lounge go-librespot[3168]: time="2025-03-02T13:09:00+01:00" level=trace msg="received dealer pong" Mar 02 13:09:04 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: multiroom , enableAudioOutput Mar 02 13:09:04 lounge volumio[948]: info: MRS: Setting this device as multiroomSync server Mar 02 13:09:04 lounge volumio[948]: info: MRS: Setting another device as multiroomSync client Mar 02 13:09:04 lounge volumio[948]: info: MRS: Setting this device as Server Mar 02 13:09:04 lounge volumio[948]: info: Mar 02 13:09:04 lounge volumio[948]: [1740917344660] ---------------------------- MRS: Setting Multiroom Server Mar 02 13:09:04 lounge volumio[948]: info: MRS: Pushing multiroomSync output Mar 02 13:09:04 lounge volumio[948]: info: Enabled audio output: 8f3c0a81-d44e-494e-a879-2f46bf100928 Mar 02 13:09:04 lounge volumio[948]: info: MRS: STARTING SNAPCLIENT Mar 02 13:09:04 lounge volumio[948]: info: MRS: Updating multiroomSync output Mar 02 13:09:04 lounge volumio[948]: info: MRS: STOPPING SNAPCLIENT Mar 02 13:09:04 lounge sudo[4130]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumioSnapclient Mar 02 13:09:04 lounge sudo[4130]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 13:09:04 lounge systemd[1]: Starting Snapcast client... Mar 02 13:09:04 lounge volumio[948]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 02 13:09:04 lounge snapclient[4133]: daemon started Mar 02 13:09:04 lounge systemd[1]: Started Snapcast client. Mar 02 13:09:04 lounge sudo[4130]: pam_unix(sudo:session): session closed for user root Mar 02 13:09:04 lounge volumio[948]: info: MRS: SNAPCLIENT STARTED Mar 02 13:09:05 lounge volumio[948]: info: MRS: STARTING SNAPSERVER Mar 02 13:09:05 lounge volumio[948]: info: MRS: enable multiroom server output Mar 02 13:09:05 lounge volumio[948]: info: MRS: Set multiroom target PCM to volumioMultiRoom Mar 02 13:09:05 lounge volumio[948]: info: Changed audio target for /tmp/multiroom/server/switch.target to volumioMultiRoom Mar 02 13:09:05 lounge volumio[948]: info: MRS: Set multiroom target PCM to volumioLocalPlayback Mar 02 13:09:05 lounge volumio[948]: info: Changed audio target for /tmp/multiroom/client/switch.target to volumioLocalPlayback Mar 02 13:09:05 lounge volumio[948]: info: MRS: Snap server restart Mar 02 13:09:05 lounge sudo[4137]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumioSnapserver Mar 02 13:09:05 lounge sudo[4137]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 02 13:09:05 lounge systemd[1]: Starting Snapcast server... Mar 02 13:09:05 lounge volumio[948]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 02 13:09:05 lounge snapserver[4139]: Settings file: "/var/lib/snapserver/server.json" Mar 02 13:09:05 lounge snapserver[4139]: pipe:///tmp/multiroom/server/fifo?name=Radio&sampleformat=48000:16:2&codec=flac Mar 02 13:09:05 lounge snapserver[4139]: 2025-03-02 13-09-05 [Notice] Settings file: "/var/lib/snapserver/server.json" Mar 02 13:09:05 lounge snapserver[4140]: daemon started Mar 02 13:09:05 lounge systemd[1]: Started Snapcast server. Mar 02 13:09:05 lounge sudo[4137]: pam_unix(sudo:session): session closed for user root Mar 02 13:09:05 lounge volumio[948]: info: MRS: SNAPSERVER STARTED Mar 02 13:09:05 lounge go-librespot[3168]: time="2025-03-02T13:09:05+01:00" level=debug msg="fetched chunk 12/14, size: 524288" uri="spotify:track:4nb5Y4lJWwSccQRiFsHHcL" Mar 02 13:09:05 lounge volumio[948]: info: camilladsp spawned new process with pid 4144, instance 1, run: true Mar 02 13:09:06 lounge snapclient[4133]: Connected to 192.168.0.48 Mar 02 13:09:06 lounge snapserver[4140]: StreamServer::NewConnection: ::ffff:192.168.0.48 Mar 02 13:09:06 lounge volumio[948]: info: FusionDsp - ---- read samplerate, raw: 48000,S32_LE,2,32 Mar 02 13:09:06 lounge volumio[948]: info: FusionDsp - ---- read samplerate from file: 48000 Mar 02 13:09:06 lounge volumio[948]: info: camilladsp stopping service pid 4144... Mar 02 13:09:06 lounge volumio[948]: info: camilladsp service terminated, instance 1 Mar 02 13:09:06 lounge volumio[948]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 02 13:09:06 lounge volumio[948]: info: camilladsp service started and running in background, instance 1 Mar 02 13:09:06 lounge volumio[948]: info: FusionDsp - ---- read samplerate, raw: 48000,S32_LE,2,32 Mar 02 13:09:06 lounge volumio[948]: info: FusionDsp - ---- read samplerate from file: 48000 Mar 02 13:09:06 lounge volumio[948]: info: FusionDsp - If filter freq >samplerate/2 then disable it Mar 02 13:09:06 lounge volumio[948]: error: FusionDsp - WebSocket error: [object Object] Mar 02 13:09:06 lounge volumio[948]: info: camilladsp spawned new process with pid 4165, instance 1, run: true Mar 02 13:09:06 lounge volumio[948]: info: MRS: Updating multiroomSync output Mar 02 13:09:07 lounge snapserver[4140]: StreamServer::NewConnection: ::ffff:192.168.0.108 Mar 02 13:09:13 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 02 13:09:13 lounge volumio[948]: info: Setting Remote Device Volume: http://192.168.0.108 Mar 02 13:09:13 lounge volumio[948]: info: Done setting volume on: Mar 02 13:09:13 lounge volumio[948]: info: MRS: Updating multiroomSync output Mar 02 13:09:13 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 02 13:09:13 lounge volumio[948]: info: Setting Remote Device Volume: http://192.168.0.108 Mar 02 13:09:13 lounge volumio[948]: info: Done setting volume on: Mar 02 13:09:13 lounge volumio[948]: info: MRS: Updating multiroomSync output Mar 02 13:09:15 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 02 13:09:15 lounge volumio[948]: info: Setting Remote Device Volume: http://192.168.0.48 Mar 02 13:09:15 lounge volumio[948]: info: Mar 02 13:09:15 lounge volumio[948]: ---------------------------- Client requests Volume 55 Mar 02 13:09:15 lounge volumio[948]: info: VolumeController::SetAlsaVolume55 Mar 02 13:09:15 lounge volumio[948]: info: CoreStateMachine::pushState Mar 02 13:09:15 lounge volumio[948]: info: CorePlayQueue::getTrack 1 Mar 02 13:09:15 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 13:09:15 lounge volumio[948]: info: CoreCommandRouter::volumioPushState Mar 02 13:09:15 lounge volumio[948]: info: MRS: Pushing multiroomSync output update for this device Mar 02 13:09:15 lounge volumio[948]: info: MRS: Pushing multiroomSync output Mar 02 13:09:15 lounge volumio[948]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Mar 02 13:09:15 lounge volumio[948]: SPOTIFY: SPOTIFY VOLUME 61 Mar 02 13:09:15 lounge volumio[948]: SPOTIFY: VOLUMIO VOLUME 55 Mar 02 13:09:15 lounge volumio[948]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 02 13:09:15 lounge volumio[948]: info: Setting Spotify Volume from Volumio: 55 Mar 02 13:09:15 lounge volumio[948]: info: Done setting volume on: Mar 02 13:09:16 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 02 13:09:16 lounge volumio[948]: info: Setting Remote Device Volume: http://192.168.0.108 Mar 02 13:09:16 lounge volumio[948]: info: Done setting volume on: Mar 02 13:09:16 lounge volumio[948]: info: MRS: Updating multiroomSync output Mar 02 13:09:16 lounge volumio[948]: SPOTIFY: SETTING SPOTIFY VOLUME 55 Mar 02 13:09:16 lounge volumio[948]: info: Sending Spotify command with payload to local API: /player/volume Mar 02 13:09:16 lounge go-librespot[3168]: time="2025-03-02T13:09:16+01:00" level=debug msg="update volume to 36044/65535" Mar 02 13:09:16 lounge volumio[948]: info: MRS: Updating multiroomSync output Mar 02 13:09:18 lounge go-librespot[3168]: time="2025-03-02T13:09:18+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 02 13:09:18 lounge go-librespot[3168]: time="2025-03-02T13:09:18+01:00" level=trace msg="emitting websocket event: volume" Mar 02 13:09:18 lounge volumio[948]: SPOTIFY: received: {"type":"volume","data":{"value":55,"max":100}} Mar 02 13:09:18 lounge volumio[948]: SPOTIFY: RECEIVED SPOTIFY VOLUME 55 Mar 02 13:09:18 lounge volumio[948]: SPOTIFY: received: {"type":"volume","data":{"value":55,"max":100}} Mar 02 13:09:18 lounge volumio[948]: SPOTIFY: RECEIVED SPOTIFY VOLUME 55 Mar 02 13:09:18 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 02 13:09:18 lounge volumio[948]: info: Setting Remote Device Volume: http://192.168.0.108 Mar 02 13:09:18 lounge volumio[948]: info: Done setting volume on: Mar 02 13:09:18 lounge volumio[948]: info: MRS: Updating multiroomSync output Mar 02 13:09:18 lounge go-librespot[3168]: time="2025-03-02T13:09:18+01:00" level=debug msg="fetched chunk 13/14, size: 524288" uri="spotify:track:4nb5Y4lJWwSccQRiFsHHcL" Mar 02 13:09:19 lounge volumio[948]: info: MRS: Updating multiroomSync output Mar 02 13:09:21 lounge volumio[948]: info: MRS: Updating multiroomSync output Mar 02 13:09:30 lounge go-librespot[3168]: time="2025-03-02T13:09:30+01:00" level=debug msg="fetched chunk 14/14, size: 473700" uri="spotify:track:4nb5Y4lJWwSccQRiFsHHcL" Mar 02 13:09:30 lounge go-librespot[3168]: time="2025-03-02T13:09:30+01:00" level=trace msg="sent dealer ping" Mar 02 13:09:30 lounge go-librespot[3168]: time="2025-03-02T13:09:30+01:00" level=trace msg="received dealer pong" Mar 02 13:09:32 lounge volumio[948]: error: [LastFM] plugin is not authenticated, please retry Mar 02 13:09:42 lounge volumio[948]: info: MRS: Updating multiroomSync output Mar 02 13:10:00 lounge go-librespot[3168]: time="2025-03-02T13:10:00+01:00" level=trace msg="sent dealer ping" Mar 02 13:10:00 lounge go-librespot[3168]: time="2025-03-02T13:10:00+01:00" level=trace msg="received dealer pong" Mar 02 13:10:14 lounge volumio[948]: info: CorePlayQueue::getTrack 1 Mar 02 13:10:14 lounge volumio[948]: info: CorePlayQueue::getTrack 2 Mar 02 13:10:14 lounge volumio[948]: info: Prefetching next song Mar 02 13:10:14 lounge volumio[948]: info: [1740917414274] ControllerSpotify::prefetch Mar 02 13:10:14 lounge volumio[948]: info: Sending Spotify command with payload to local API: /player/add_to_queue Mar 02 13:10:14 lounge go-librespot[3168]: time="2025-03-02T13:10:14+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 02 13:10:14 lounge go-librespot[3168]: time="2025-03-02T13:10:14+01:00" level=debug msg="prefetching next track" uri="spotify:track:5bsWIPw0w09vT2lDV2nDQw" Mar 02 13:10:14 lounge go-librespot[3168]: time="2025-03-02T13:10:14+01:00" level=debug msg="selected format OGG_VORBIS_320 (446301e8ea18a055cb1bba09c0238627fe9440d9)" uri="spotify:track:5bsWIPw0w09vT2lDV2nDQw" Mar 02 13:10:14 lounge go-librespot[3168]: time="2025-03-02T13:10:14+01:00" level=debug msg="requested aes key for file 446301e8ea18a055cb1bba09c0238627fe9440d9, gid: 5bsWIPw0w09vT2lDV2nDQw" Mar 02 13:10:15 lounge go-librespot[3168]: time="2025-03-02T13:10:15+01:00" level=debug msg="fetched first chunk of 26, total size is 13152748 bytes" uri="spotify:track:5bsWIPw0w09vT2lDV2nDQw" Mar 02 13:10:15 lounge go-librespot[3168]: time="2025-03-02T13:10:15+01:00" level=info msg="prefetched track \"All I Got\" (duration: 304390ms)" uri="spotify:track:5bsWIPw0w09vT2lDV2nDQw" Mar 02 13:10:15 lounge go-librespot[3168]: time="2025-03-02T13:10:15+01:00" level=debug msg="fetched chunk 1/25, size: 524288" uri="spotify:track:5bsWIPw0w09vT2lDV2nDQw" Mar 02 13:10:15 lounge go-librespot[3168]: time="2025-03-02T13:10:15+01:00" level=debug msg="fetched chunk 3/25, size: 524288" uri="spotify:track:5bsWIPw0w09vT2lDV2nDQw" Mar 02 13:10:15 lounge go-librespot[3168]: time="2025-03-02T13:10:15+01:00" level=debug msg="fetched chunk 2/25, size: 524288" uri="spotify:track:5bsWIPw0w09vT2lDV2nDQw" Mar 02 13:10:16 lounge go-librespot[3168]: time="2025-03-02T13:10:16+01:00" level=trace msg="emitting websocket event: not_playing" Mar 02 13:10:16 lounge go-librespot[3168]: time="2025-03-02T13:10:16+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5bsWIPw0w09vT2lDV2nDQw" Mar 02 13:10:16 lounge volumio[948]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:4nb5Y4lJWwSccQRiFsHHcL","play_origin":"go-librespot"}} Mar 02 13:10:16 lounge volumio[948]: error: Failed to decode event: not_playing Mar 02 13:10:16 lounge volumio[948]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:4nb5Y4lJWwSccQRiFsHHcL","play_origin":"go-librespot"}} Mar 02 13:10:16 lounge volumio[948]: error: Failed to decode event: not_playing Mar 02 13:10:17 lounge go-librespot[3168]: time="2025-03-02T13:10:17+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 02 13:10:17 lounge go-librespot[3168]: time="2025-03-02T13:10:17+01:00" level=trace msg="emitting websocket event: will_play" Mar 02 13:10:17 lounge go-librespot[3168]: time="2025-03-02T13:10:17+01:00" level=info msg="loaded track \"All I Got\" (paused: false, position: 0ms, duration: 304390ms, prefetched: true)" uri="spotify:track:5bsWIPw0w09vT2lDV2nDQw" Mar 02 13:10:17 lounge volumio[948]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5bsWIPw0w09vT2lDV2nDQw","play_origin":"go-librespot"}} Mar 02 13:10:17 lounge volumio[948]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5bsWIPw0w09vT2lDV2nDQw","play_origin":"go-librespot"}} Mar 02 13:10:17 lounge go-librespot[3168]: time="2025-03-02T13:10:17+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 02 13:10:17 lounge go-librespot[3168]: time="2025-03-02T13:10:17+01:00" level=trace msg="scheduling prefetch in 275s" Mar 02 13:10:17 lounge go-librespot[3168]: time="2025-03-02T13:10:17+01:00" level=trace msg="emitting websocket event: metadata" Mar 02 13:10:17 lounge volumio[948]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5bsWIPw0w09vT2lDV2nDQw","name":"All I Got","artist_names":["Miss Monique"],"album_name":"All I Got","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02ef2be9db9d147647ea7c0367","position":0,"duration":304390,"release_date":"year:2022 month:7 day:1","track_number":1,"disc_number":1}} Mar 02 13:10:17 lounge volumio[948]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5bsWIPw0w09vT2lDV2nDQw","name":"All I Got","artist_names":["Miss Monique"],"album_name":"All I Got","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02ef2be9db9d147647ea7c0367","position":0,"duration":304390,"release_date":"year:2022 month:7 day:1","track_number":1,"disc_number":1}} Mar 02 13:10:17 lounge go-librespot[3168]: time="2025-03-02T13:10:17+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 02 13:10:17 lounge go-librespot[3168]: time="2025-03-02T13:10:17+01:00" level=trace msg="emitting websocket event: playing" Mar 02 13:10:17 lounge volumio[948]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5bsWIPw0w09vT2lDV2nDQw","play_origin":"go-librespot"}} Mar 02 13:10:17 lounge volumio[948]: SPOTIFY: PUSH STATE SPOTIFY Mar 02 13:10:17 lounge volumio[948]: SPOTIFY: {"status":"play","service":"spop","title":"All I Got","artist":"Miss Monique","album":"All I Got","albumart":"https://i.scdn.co/image/ab67616d00001e02ef2be9db9d147647ea7c0367","uri":"spotify:track:5bsWIPw0w09vT2lDV2nDQw","trackType":"spotify","seek":1000,"duration":304,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 13:10:17 lounge volumio[948]: info: CoreCommandRouter::servicePushState Mar 02 13:10:17 lounge volumio[948]: info: CorePlayQueue::getTrack 1 Mar 02 13:10:17 lounge volumio[948]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"All I Got","artist":"Miss Monique","album":"All I Got","albumart":"https://i.scdn.co/image/ab67616d00001e02ef2be9db9d147647ea7c0367","uri":"spotify:track:5bsWIPw0w09vT2lDV2nDQw","trackType":"spotify","seek":1000,"duration":304,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 13:10:17 lounge volumio[948]: verbose: CURRENT POSITION 1 Mar 02 13:10:17 lounge volumio[948]: info: CoreStateMachine::syncState stateService play Mar 02 13:10:17 lounge volumio[948]: info: CoreStateMachine::syncState currentStatus play Mar 02 13:10:17 lounge volumio[948]: info: Received an update from plugin. extracting info from payload Mar 02 13:10:17 lounge volumio[948]: info: CoreStateMachine::pushState Mar 02 13:10:17 lounge volumio[948]: info: CorePlayQueue::getTrack 1 Mar 02 13:10:17 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 13:10:17 lounge volumio[948]: info: CoreCommandRouter::volumioPushState Mar 02 13:10:17 lounge volumio[948]: info: MRS: Pushing multiroomSync output update for this device Mar 02 13:10:17 lounge volumio[948]: info: MRS: Pushing multiroomSync output Mar 02 13:10:17 lounge volumio[948]: info: CoreStateMachine::pushState Mar 02 13:10:17 lounge volumio[948]: info: CorePlayQueue::getTrack 1 Mar 02 13:10:17 lounge volumio[948]: info: CoreCommandRouter::volumioPushState Mar 02 13:10:17 lounge volumio[948]: info: MRS: Pushing multiroomSync output update for this device Mar 02 13:10:17 lounge volumio[948]: info: MRS: Pushing multiroomSync output Mar 02 13:10:17 lounge volumio[948]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5bsWIPw0w09vT2lDV2nDQw","play_origin":"go-librespot"}} Mar 02 13:10:17 lounge volumio[948]: SPOTIFY: PUSH STATE SPOTIFY Mar 02 13:10:17 lounge volumio[948]: SPOTIFY: {"status":"play","service":"spop","title":"All I Got","artist":"Miss Monique","album":"All I Got","albumart":"https://i.scdn.co/image/ab67616d00001e02ef2be9db9d147647ea7c0367","uri":"spotify:track:5bsWIPw0w09vT2lDV2nDQw","trackType":"spotify","seek":1000,"duration":304,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 13:10:17 lounge volumio[948]: info: CoreCommandRouter::servicePushState Mar 02 13:10:17 lounge volumio[948]: info: CorePlayQueue::getTrack 1 Mar 02 13:10:17 lounge volumio[948]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"All I Got","artist":"Miss Monique","album":"All I Got","albumart":"https://i.scdn.co/image/ab67616d00001e02ef2be9db9d147647ea7c0367","uri":"spotify:track:5bsWIPw0w09vT2lDV2nDQw","trackType":"spotify","seek":1000,"duration":304,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 13:10:17 lounge volumio[948]: verbose: CURRENT POSITION 1 Mar 02 13:10:17 lounge volumio[948]: info: CoreStateMachine::syncState stateService play Mar 02 13:10:17 lounge volumio[948]: info: CoreStateMachine::syncState currentStatus play Mar 02 13:10:17 lounge volumio[948]: info: Received an update from plugin. extracting info from payload Mar 02 13:10:17 lounge volumio[948]: info: CoreStateMachine::pushState Mar 02 13:10:17 lounge volumio[948]: info: CorePlayQueue::getTrack 1 Mar 02 13:10:17 lounge volumio[948]: info: CoreCommandRouter::volumioPushState Mar 02 13:10:17 lounge volumio[948]: info: MRS: Pushing multiroomSync output update for this device Mar 02 13:10:17 lounge volumio[948]: info: MRS: Pushing multiroomSync output Mar 02 13:10:17 lounge volumio[948]: info: CoreStateMachine::pushState Mar 02 13:10:17 lounge volumio[948]: info: CorePlayQueue::getTrack 1 Mar 02 13:10:17 lounge volumio[948]: info: CoreCommandRouter::volumioPushState Mar 02 13:10:17 lounge volumio[948]: info: MRS: Pushing multiroomSync output update for this device Mar 02 13:10:17 lounge volumio[948]: info: MRS: Pushing multiroomSync output Mar 02 13:10:17 lounge volumio[948]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Mar 02 13:10:17 lounge volumio[948]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Mar 02 13:10:17 lounge volumio[948]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Mar 02 13:10:17 lounge volumio[948]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Mar 02 13:10:18 lounge volumio[948]: SPOTIFY: PUSH STATE SPOTIFY Mar 02 13:10:18 lounge volumio[948]: SPOTIFY: {"status":"play","service":"spop","title":"All I Got","artist":"Miss Monique","album":"All I Got","albumart":"https://i.scdn.co/image/ab67616d00001e02ef2be9db9d147647ea7c0367","uri":"spotify:track:5bsWIPw0w09vT2lDV2nDQw","trackType":"spotify","seek":1000,"duration":304,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 13:10:18 lounge volumio[948]: info: CoreCommandRouter::servicePushState Mar 02 13:10:18 lounge volumio[948]: info: CorePlayQueue::getTrack 1 Mar 02 13:10:18 lounge volumio[948]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"All I Got","artist":"Miss Monique","album":"All I Got","albumart":"https://i.scdn.co/image/ab67616d00001e02ef2be9db9d147647ea7c0367","uri":"spotify:track:5bsWIPw0w09vT2lDV2nDQw","trackType":"spotify","seek":1000,"duration":304,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 13:10:18 lounge volumio[948]: verbose: CURRENT POSITION 1 Mar 02 13:10:18 lounge volumio[948]: info: CoreStateMachine::syncState stateService play Mar 02 13:10:18 lounge volumio[948]: info: CoreStateMachine::syncState currentStatus play Mar 02 13:10:18 lounge volumio[948]: info: Received an update from plugin. extracting info from payload Mar 02 13:10:18 lounge volumio[948]: info: CoreStateMachine::pushState Mar 02 13:10:18 lounge volumio[948]: info: CorePlayQueue::getTrack 1 Mar 02 13:10:18 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 13:10:18 lounge volumio[948]: info: CoreCommandRouter::volumioPushState Mar 02 13:10:18 lounge volumio[948]: info: MRS: Pushing multiroomSync output update for this device Mar 02 13:10:18 lounge volumio[948]: info: MRS: Pushing multiroomSync output Mar 02 13:10:18 lounge volumio[948]: info: CoreStateMachine::pushState Mar 02 13:10:18 lounge volumio[948]: info: CorePlayQueue::getTrack 1 Mar 02 13:10:18 lounge volumio[948]: info: CoreCommandRouter::volumioPushState Mar 02 13:10:18 lounge volumio[948]: info: MRS: Pushing multiroomSync output update for this device Mar 02 13:10:18 lounge volumio[948]: info: MRS: Pushing multiroomSync output Mar 02 13:10:18 lounge volumio[948]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Mar 02 13:10:18 lounge volumio[948]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Mar 02 13:10:18 lounge volumio[948]: SPOTIFY: PUSH STATE SPOTIFY Mar 02 13:10:18 lounge volumio[948]: SPOTIFY: {"status":"play","service":"spop","title":"All I Got","artist":"Miss Monique","album":"All I Got","albumart":"https://i.scdn.co/image/ab67616d00001e02ef2be9db9d147647ea7c0367","uri":"spotify:track:5bsWIPw0w09vT2lDV2nDQw","trackType":"spotify","seek":1000,"duration":304,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 13:10:18 lounge volumio[948]: info: CoreCommandRouter::servicePushState Mar 02 13:10:18 lounge volumio[948]: info: CorePlayQueue::getTrack 1 Mar 02 13:10:18 lounge volumio[948]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"All I Got","artist":"Miss Monique","album":"All I Got","albumart":"https://i.scdn.co/image/ab67616d00001e02ef2be9db9d147647ea7c0367","uri":"spotify:track:5bsWIPw0w09vT2lDV2nDQw","trackType":"spotify","seek":1000,"duration":304,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 02 13:10:18 lounge volumio[948]: verbose: CURRENT POSITION 1 Mar 02 13:10:18 lounge volumio[948]: info: CoreStateMachine::syncState stateService play Mar 02 13:10:18 lounge volumio[948]: info: CoreStateMachine::syncState currentStatus play Mar 02 13:10:18 lounge volumio[948]: info: Received an update from plugin. extracting info from payload Mar 02 13:10:18 lounge volumio[948]: info: CoreStateMachine::pushState Mar 02 13:10:18 lounge volumio[948]: info: CorePlayQueue::getTrack 1 Mar 02 13:10:18 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 13:10:18 lounge volumio[948]: info: CoreCommandRouter::volumioPushState Mar 02 13:10:18 lounge volumio[948]: info: MRS: Pushing multiroomSync output update for this device Mar 02 13:10:18 lounge volumio[948]: info: MRS: Pushing multiroomSync output Mar 02 13:10:18 lounge volumio[948]: info: CoreStateMachine::pushState Mar 02 13:10:18 lounge volumio[948]: info: CorePlayQueue::getTrack 1 Mar 02 13:10:18 lounge volumio[948]: info: CoreCommandRouter::volumioPushState Mar 02 13:10:18 lounge volumio[948]: info: MRS: Pushing multiroomSync output update for this device Mar 02 13:10:18 lounge volumio[948]: info: MRS: Pushing multiroomSync output Mar 02 13:10:18 lounge volumio[948]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Mar 02 13:10:18 lounge volumio[948]: info: CoreStateMachine::startPlaybackTimer Mar 02 13:10:18 lounge volumio[948]: info: CorePlayQueue::getTrack 2 Mar 02 13:10:18 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 02 13:10:18 lounge volumio[948]: info: CURURI: music-library Mar 02 13:10:18 lounge volumio[948]: error: Failed LSINFO: null Mar 02 13:10:19 lounge volumio[948]: info: Preload queue cleared Mar 02 13:10:19 lounge volumio[948]: info: CoreStateMachine::pushState Mar 02 13:10:19 lounge volumio[948]: info: CorePlayQueue::getTrack 2 Mar 02 13:10:19 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 02 13:10:19 lounge volumio[948]: info: CoreCommandRouter::volumioPushState Mar 02 13:10:19 lounge volumio[948]: info: MRS: Pushing multiroomSync output update for this device Mar 02 13:10:19 lounge volumio[948]: info: MRS: Pushing multiroomSync output Mar 02 13:10:19 lounge volumio[948]: info: [LastFM] Current track has sufficient metadata: title (All I Got) and artist (Miss Monique) passed on explicitly Mar 02 13:10:19 lounge volumio[948]: error: [LastFM] plugin is not authenticated, please retry, or track info could not be determined (very rare) Mar 02 13:10:19 lounge volumio[948]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Mar 02 13:10:19 lounge volumio[948]: info: MRS: Updating multiroomSync output Mar 02 13:10:21 lounge volumio[948]: info: Executing endpoint metavolumio Mar 02 13:10:21 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 02 13:10:21 lounge volumio[948]: info: Executing endpoint metavolumio Mar 02 13:10:21 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 02 13:10:21 lounge volumio[948]: info: Executing endpoint metavolumio Mar 02 13:10:21 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 02 13:10:27 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Mar 02 13:10:27 lounge volumio[948]: info: CURURI: music-library Mar 02 13:10:27 lounge volumio[948]: error: Failed LSINFO: null Mar 02 13:10:27 lounge volumio[948]: info: Preload queue cleared Mar 02 13:10:28 lounge go-librespot[3168]: time="2025-03-02T13:10:28+01:00" level=debug msg="fetched chunk 4/25, size: 524288" uri="spotify:track:5bsWIPw0w09vT2lDV2nDQw" Mar 02 13:10:30 lounge go-librespot[3168]: time="2025-03-02T13:10:30+01:00" level=trace msg="sent dealer ping" Mar 02 13:10:30 lounge go-librespot[3168]: time="2025-03-02T13:10:30+01:00" level=trace msg="received dealer pong" Mar 02 13:10:31 lounge volumio[948]: info: CoreCommandRouter::volumioGetState Mar 02 13:10:31 lounge volumio[948]: info: CorePlayQueue::getTrack 2 Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 02 13:10:33 lounge volumio[948]: info: Retrieving Cloud Streaming UI Mar 02 13:10:33 lounge volumio[948]: info: Getting Tidal Cloud Configuration Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 02 13:10:33 lounge volumio[948]: info: Getting Qobuz Cloud Configuration Mar 02 13:10:33 lounge volumio[948]: info: Asking plugin for UI Config Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 02 13:10:33 lounge volumio[948]: info: Getting Spotify Cloud Configuration Mar 02 13:10:33 lounge volumio[948]: info: Asking plugin for UI Config Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 02 13:10:33 lounge volumio[948]: info: Saving Spotify Acccount Mar 02 13:10:33 lounge volumio[948]: info: Got it Mar 02 13:10:33 lounge volumio[948]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Mar 02 13:10:33 lounge volumio[948]: info: Got Tidal Cloud Configuration Mar 02 13:10:33 lounge volumio[948]: info: Got it Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::volumioGetBrowseSources Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::volumioGetBrowseSources Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::volumioGetBrowseSources Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Mar 02 13:10:33 lounge volumio[948]: info: Executing endpoint metavolumio Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 02 13:10:33 lounge volumio[948]: info: Executing endpoint metavolumio Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 02 13:10:33 lounge volumio[948]: info: Executing endpoint metavolumio Mar 02 13:10:33 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 02 13:10:37 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Mar 02 13:10:37 lounge volumio[948]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Mar 02 13:10:37 lounge volumio[948]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 02 13:10:37 lounge volumio[948]: Error: dns service error: unknown Mar 02 13:10:37 lounge volumio[948]: at MDNSService.on_resolver_done (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:19:30) Mar 02 13:10:37 lounge volumio[948]: at SocketWatcher.MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { Mar 02 13:10:37 lounge volumio[948]: errorCode: -65537 Mar 02 13:10:37 lounge volumio[948]: } Mar 02 13:10:37 lounge volumio[948]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 02 13:10:37 lounge sudo[4444]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-02 13:09 Mar 02 13:10:37 lounge sudo[4444]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"