-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Thu 2025-05-22 21:56:22 CEST. -- May 22 21:55:00 spotifyrpi volumio[824]: info: Starting Streaming Service Transparent Proxy May 22 21:55:00 spotifyrpi volumio[824]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 22 21:55:00 spotifyrpi volumio[824]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 22 21:55:00 spotifyrpi volumio[824]: info: Streaming services startup May 22 21:55:00 spotifyrpi volumio[824]: info: Starting Streaming Daemon May 22 21:55:00 spotifyrpi volumio[824]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 22 21:55:00 spotifyrpi volumio[824]: info: Getting Spotify volume May 22 21:55:00 spotifyrpi volumio[824]: info: Spotify volume: 100 May 22 21:55:00 spotifyrpi sudo[1425]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 22 21:55:00 spotifyrpi sudo[1425]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 21:55:00 spotifyrpi volumio[824]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 May 22 21:55:01 spotifyrpi sudo[1425]: pam_unix(sudo:session): session closed for user root May 22 21:55:01 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:55:01 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:55:01 spotifyrpi volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 22 21:55:01 spotifyrpi volumio[824]: error: Cannot start Volumio Streaming Daemon May 22 21:55:01 spotifyrpi volumio[824]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 22 21:55:01 spotifyrpi volumio[824]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 22 21:55:01 spotifyrpi volumio[824]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN May 22 21:55:01 spotifyrpi systemd[1]: systemd-hostnamed.service: Succeeded. May 22 21:55:02 spotifyrpi volumio[824]: STREAMING PROXY: Starting server on port 3245 May 22 21:55:02 spotifyrpi volumio[824]: Node JS runtime: 14 May 22 21:55:02 spotifyrpi volumio[824]: info: MyVolumio token set successfully May 22 21:55:02 spotifyrpi volumio[824]: info: MYVOLUMIO: Adding device May 22 21:55:02 spotifyrpi volumio[824]: info: MYVOLUMIO: Evaluating Server May 22 21:55:03 spotifyrpi volumio[824]: info: MyVolumio status changed May 22 21:55:03 spotifyrpi volumio[824]: info: Streaming services startup May 22 21:55:03 spotifyrpi volumio[824]: info: Starting Streaming Daemon May 22 21:55:03 spotifyrpi volumio[824]: info: Removing browser output: myVolumio user plan is not superstar May 22 21:55:03 spotifyrpi volumio[824]: info: Removing audio output: May 22 21:55:03 spotifyrpi volumio[824]: info: Stoppping Tunnel 1 May 22 21:55:03 spotifyrpi sudo[1466]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 22 21:55:03 spotifyrpi sudo[1466]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 21:55:03 spotifyrpi sudo[1468]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service May 22 21:55:03 spotifyrpi sudo[1468]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 21:55:03 spotifyrpi sudo[1466]: pam_unix(sudo:session): session closed for user root May 22 21:55:03 spotifyrpi sudo[1468]: pam_unix(sudo:session): session closed for user root May 22 21:55:03 spotifyrpi volumio[824]: info: Remote SSH Stopped May 22 21:55:03 spotifyrpi volumio[824]: error: Cannot start Volumio Streaming Daemon May 22 21:55:03 spotifyrpi volumio[824]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 22 21:55:03 spotifyrpi volumio[824]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 22 21:55:03 spotifyrpi volumio[824]: info: Setting Geolocation for MyVolumio to eu7 May 22 21:55:03 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 21:55:03 spotifyrpi volumio[824]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} May 22 21:55:04 spotifyrpi volumio[824]: info: Updating MyVolumio device info May 22 21:55:04 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 21:55:05 spotifyrpi volumio[824]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 May 22 21:55:05 spotifyrpi volumio[824]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} May 22 21:55:05 spotifyrpi volumio[1213]: ...................................................................................................................++++ May 22 21:55:06 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 22 21:55:06 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 22 21:55:06 spotifyrpi volumio[1213]: .......++++ May 22 21:55:06 spotifyrpi volumio[1213]: e is 65537 (0x010001) May 22 21:55:06 spotifyrpi volumio[1213]: writing RSA key May 22 21:55:07 spotifyrpi volumio[824]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 May 22 21:55:07 spotifyrpi volumio[824]: info: MYVOLUMIO: Adding device May 22 21:55:07 spotifyrpi volumio[824]: info: MYVOLUMIO: Evaluating Server May 22 21:55:08 spotifyrpi volumio[824]: info: Setting Geolocation for MyVolumio to eu6 May 22 21:55:08 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 21:55:08 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 21:55:08 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 21:55:08 spotifyrpi volumio[824]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} May 22 21:55:09 spotifyrpi volumio[824]: info: Updating MyVolumio device info May 22 21:55:09 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 21:55:09 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 21:55:09 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 21:55:09 spotifyrpi volumio[824]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 May 22 21:55:10 spotifyrpi volumio[824]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetVisibleSources May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:55:10 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 22 21:55:10 spotifyrpi volumio[824]: info: Received Get System Info May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 21:55:10 spotifyrpi volumio[824]: info: Discovery: Getting this device information May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:55:10 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:55:10 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:55:10 spotifyrpi volumio[824]: info: Listing playlists May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 22 21:55:10 spotifyrpi volumio[824]: info: Received Get System Info May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 21:55:10 spotifyrpi volumio[824]: info: Discovery: Getting this device information May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:55:10 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetVisibleSources May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:55:10 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 22 21:55:10 spotifyrpi volumio[824]: info: Received Get System Info May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 21:55:10 spotifyrpi volumio[824]: info: Discovery: Getting this device information May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:55:10 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:55:10 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:55:10 spotifyrpi volumio[824]: info: Listing playlists May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 22 21:55:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 22 21:55:11 spotifyrpi systemd[1]: systemd-timedated.service: Succeeded. May 22 21:55:12 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 22 21:55:12 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 22 21:55:12 spotifyrpi volumio[824]: info: Received Get System Info May 22 21:55:12 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 21:55:12 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 21:55:12 spotifyrpi volumio[824]: info: Discovery: Getting this device information May 22 21:55:12 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:55:12 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:55:12 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 21:55:13 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 22 21:55:13 spotifyrpi volumio[824]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 May 22 21:55:13 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:55:13 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:55:15 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 22 21:55:15 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 21:55:15 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 22 21:55:16 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 22 21:55:16 spotifyrpi volumio-remote-updater[584]: No test mode May 22 21:55:16 spotifyrpi volumio-remote-updater[584]: No alpha test mode May 22 21:55:16 spotifyrpi volumio[824]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 22 21:55:16 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 22 21:55:17 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 22 21:55:18 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 21:55:18 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 21:55:18 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 22 21:55:18 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 22 21:55:18 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 22 21:55:18 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetBrowseSources May 22 21:55:18 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 22 21:55:19 spotifyrpi go-librespot[1150]: time="2025-05-22T21:55:19+02:00" level=trace msg="sent dealer ping" May 22 21:55:19 spotifyrpi go-librespot[1150]: time="2025-05-22T21:55:19+02:00" level=trace msg="received dealer pong" May 22 21:55:20 spotifyrpi volumio[824]: error: MyVolumio Plugin failed to authenticate in a timely fashion May 22 21:55:20 spotifyrpi volumio[824]: info: Completed starting MyVolumio Plugin May 22 21:55:20 spotifyrpi volumio[824]: [Metrics] CommandRouter: 44s 173.58ms May 22 21:55:20 spotifyrpi volumio[824]: info: CoreCommandRouter::volumiosetStartupVolume May 22 21:55:20 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 22 21:55:20 spotifyrpi volumio[824]: info: VolumeController:: Setting startup Volume 100 May 22 21:55:20 spotifyrpi volumio[824]: info: VolumeController::SetAlsaVolume100 May 22 21:55:20 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 22 21:55:20 spotifyrpi volumio[824]: info: CoreCommandRouter::Close All Modals sent May 22 21:55:20 spotifyrpi volumio[824]: info: CoreCommandRouter::Close All Modals sent May 22 21:55:20 spotifyrpi volumio[824]: info: CoreStateMachine::pushState May 22 21:55:20 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:55:20 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioPushState May 22 21:55:20 spotifyrpi volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 22 21:55:21 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 22 21:55:21 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 22 21:55:21 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 22 21:55:24 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 22 21:55:24 spotifyrpi volumio[824]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 22 21:55:25 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 22 21:55:25 spotifyrpi volumio[824]: info: Received Get System Version May 22 21:55:25 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 22 21:55:25 spotifyrpi volumio[824]: info: Received Get System Info May 22 21:55:25 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 21:55:25 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 21:55:25 spotifyrpi volumio[824]: info: Discovery: Getting this device information May 22 21:55:25 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:55:25 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:55:25 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 21:55:27 spotifyrpi volumio[824]: info: BOOT COMPLETED May 22 21:55:37 spotifyrpi ntpd[791]: Soliciting pool server 194.50.19.204 May 22 21:55:38 spotifyrpi ntpd[791]: Soliciting pool server 212.132.97.26 May 22 21:55:38 spotifyrpi ntpd[791]: Soliciting pool server 141.144.246.224 May 22 21:55:39 spotifyrpi ntpd[791]: Soliciting pool server 128.140.37.196 May 22 21:55:39 spotifyrpi ntpd[791]: Soliciting pool server 176.9.157.155 May 22 21:55:39 spotifyrpi ntpd[791]: Soliciting pool server 213.172.105.106 May 22 21:55:40 spotifyrpi ntpd[791]: Soliciting pool server 178.63.67.56 May 22 21:55:40 spotifyrpi ntpd[791]: Soliciting pool server 178.215.228.24 May 22 21:55:40 spotifyrpi ntpd[791]: Soliciting pool server 148.251.54.81 May 22 21:55:40 spotifyrpi ntpd[791]: Soliciting pool server 194.50.19.117 May 22 21:55:41 spotifyrpi ntpd[791]: Soliciting pool server 158.180.28.150 May 22 21:55:41 spotifyrpi ntpd[791]: Soliciting pool server 94.130.35.4 May 22 21:55:41 spotifyrpi ntpd[791]: Soliciting pool server 144.76.66.156 May 22 21:55:42 spotifyrpi ntpd[791]: Soliciting pool server 51.75.67.47 May 22 21:55:42 spotifyrpi ntpd[791]: Soliciting pool server 2a02:c207:2127:4427::1 May 22 21:55:42 spotifyrpi ntpd[791]: Soliciting pool server 49.13.14.46 May 22 21:55:43 spotifyrpi ntpd[791]: Soliciting pool server 93.241.86.156 May 22 21:55:45 spotifyrpi ntpd[791]: receive: Unexpected origin timestamp 0xebd9ffc0.44e0d35b does not match aorg 0000000000.00000000 from server@49.13.14.46 xmt 0xebd9ffc1.58125abe May 22 21:55:45 spotifyrpi ntpd[791]: receive: Unexpected origin timestamp 0xebd9ffc0.44ee0fd8 does not match aorg 0000000000.00000000 from server@176.9.157.155 xmt 0xebd9ffc1.5828b48f May 22 21:55:45 spotifyrpi ntpd[791]: receive: Unexpected origin timestamp 0xebd9ffc0.44e944d7 does not match aorg 0000000000.00000000 from server@178.63.67.56 xmt 0xebd9ffc1.588b1a1c May 22 21:55:50 spotifyrpi go-librespot[1150]: time="2025-05-22T21:55:50+02:00" level=trace msg="sent dealer ping" May 22 21:55:51 spotifyrpi go-librespot[1150]: time="2025-05-22T21:55:51+02:00" level=trace msg="received dealer pong" May 22 21:56:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 21:56:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 21:56:10 spotifyrpi volumio[824]: info: Discovery: Getting this device information May 22 21:56:10 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:56:10 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 21:56:10 spotifyrpi volumio[824]: verbose: New Socket.io Connection to 192.168.178.80:3000 from 192.168.178.30 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 May 22 21:56:10 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:56:10 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 22 21:56:10 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 22 21:56:11 spotifyrpi volumio[824]: verbose: New Socket.io Connection to 192.168.178.80 from 192.168.178.30 UA: Mozilla/5.0 (Linux; Android 15; SM-S938B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 May 22 21:56:11 spotifyrpi volumio[824]: verbose: New Socket.io Connection to 192.168.178.80 from 192.168.178.30 UA: Mozilla/5.0 (Linux; Android 15; SM-S938B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 May 22 21:56:11 spotifyrpi volumio[824]: verbose: New Socket.io Connection to 192.168.178.80 from 192.168.178.30 UA: Mozilla/5.0 (Linux; Android 15; SM-S938B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 May 22 21:56:11 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 22 21:56:11 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetVisibleSources May 22 21:56:11 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 22 21:56:11 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:56:11 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:11 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 22 21:56:11 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 22 21:56:11 spotifyrpi volumio[824]: info: Received Get System Info May 22 21:56:11 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 21:56:11 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 21:56:11 spotifyrpi volumio[824]: info: Discovery: Getting this device information May 22 21:56:11 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:56:11 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:11 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 21:56:11 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:56:11 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:11 spotifyrpi volumio[824]: info: Listing playlists May 22 21:56:11 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetQueue May 22 21:56:11 spotifyrpi volumio[824]: info: CoreStateMachine::getQueue May 22 21:56:11 spotifyrpi volumio[824]: info: CorePlayQueue::getQueue May 22 21:56:11 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 22 21:56:12 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:56:12 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:12 spotifyrpi volumio[824]: verbose: New Socket.io Connection to 192.168.178.80:3000 from 192.168.178.30 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 11 May 22 21:56:12 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:56:12 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:12 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 22 21:56:12 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 22 21:56:12 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:56:12 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:12 spotifyrpi sudo[1834]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 22 21:56:12 spotifyrpi sudo[1834]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 21:56:12 spotifyrpi sudo[1834]: pam_unix(sudo:session): session closed for user root May 22 21:56:12 spotifyrpi sudo[1836]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 22 21:56:12 spotifyrpi sudo[1836]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 21:56:12 spotifyrpi sudo[1836]: pam_unix(sudo:session): session closed for user root May 22 21:56:12 spotifyrpi volumio[824]: verbose: New Socket.io Connection to 192.168.178.80 from 192.168.178.30 UA: Mozilla/5.0 (Linux; Android 15; SM-S938B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 May 22 21:56:13 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 22 21:56:13 spotifyrpi sudo[1840]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 22 21:56:13 spotifyrpi sudo[1840]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 21:56:13 spotifyrpi sudo[1840]: pam_unix(sudo:session): session closed for user root May 22 21:56:13 spotifyrpi sudo[1842]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 22 21:56:13 spotifyrpi sudo[1842]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 21:56:13 spotifyrpi sudo[1842]: pam_unix(sudo:session): session closed for user root May 22 21:56:13 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 22 21:56:13 spotifyrpi volumio[824]: verbose: New Socket.io Connection to 192.168.178.80 from 192.168.178.30 UA: Mozilla/5.0 (Linux; Android 15; SM-S938B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 13 May 22 21:56:13 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 22 21:56:13 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetVisibleSources May 22 21:56:13 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 22 21:56:13 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:56:13 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:13 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 22 21:56:13 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 22 21:56:13 spotifyrpi volumio[824]: info: Received Get System Info May 22 21:56:13 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 21:56:13 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 21:56:13 spotifyrpi volumio[824]: info: Discovery: Getting this device information May 22 21:56:13 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:56:13 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:13 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 21:56:13 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:56:13 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:13 spotifyrpi volumio[824]: info: Listing playlists May 22 21:56:13 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 22 21:56:13 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 22 21:56:13 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 22 21:56:14 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 22 21:56:15 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 22 21:56:15 spotifyrpi volumio[824]: info: Received Get System Info May 22 21:56:15 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 21:56:15 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 21:56:15 spotifyrpi volumio[824]: info: Discovery: Getting this device information May 22 21:56:15 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:56:15 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:15 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 21:56:15 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 22 21:56:15 spotifyrpi volumio[824]: info: Received Get System Info May 22 21:56:15 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 22 21:56:15 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 22 21:56:15 spotifyrpi volumio[824]: info: Discovery: Getting this device information May 22 21:56:15 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetState May 22 21:56:15 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:15 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::getUIConfigOnPlugin May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::getUIConfigOnPlugin May 22 21:56:16 spotifyrpi volumio[824]: info: Retrieving Cloud Streaming UI May 22 21:56:16 spotifyrpi volumio[824]: info: Getting Tidal Cloud Configuration May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::getUIConfigOnPlugin May 22 21:56:16 spotifyrpi volumio[824]: info: Getting Qobuz Cloud Configuration May 22 21:56:16 spotifyrpi volumio[824]: info: Asking plugin for UI Config May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::getUIConfigOnPlugin May 22 21:56:16 spotifyrpi volumio[824]: info: Getting Spotify Cloud Configuration May 22 21:56:16 spotifyrpi volumio[824]: info: Asking plugin for UI Config May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::getUIConfigOnPlugin May 22 21:56:16 spotifyrpi volumio[824]: info: Saving Spotify Acccount May 22 21:56:16 spotifyrpi volumio[824]: info: Got Tidal Cloud Configuration May 22 21:56:16 spotifyrpi volumio[824]: info: Got it May 22 21:56:16 spotifyrpi volumio[824]: info: Got it May 22 21:56:16 spotifyrpi volumio[824]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::getUIConfigOnPlugin May 22 21:56:16 spotifyrpi volumio[824]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetBrowseSources May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetBrowseSources May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioGetBrowseSources May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 22 21:56:16 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares May 22 21:56:18 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: networkfs , deleteShare May 22 21:56:18 spotifyrpi sudo[1853]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount /mnt/NAS/NAS May 22 21:56:18 spotifyrpi sudo[1853]: pam_unix(sudo:session): session opened for user root by (uid=0) May 22 21:56:18 spotifyrpi sudo[1853]: pam_unix(sudo:session): session closed for user root May 22 21:56:18 spotifyrpi systemd[1]: mnt-NAS-NAS.mount: Succeeded. May 22 21:56:18 spotifyrpi volumio[824]: info: Share NAS successfully unmounted May 22 21:56:19 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares May 22 21:56:20 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 22 21:56:20 spotifyrpi go-librespot[1150]: time="2025-05-22T21:56:20+02:00" level=trace msg="sent dealer ping" May 22 21:56:21 spotifyrpi go-librespot[1150]: time="2025-05-22T21:56:21+02:00" level=trace msg="received dealer pong" May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::sendMpdCommand status May 22 21:56:21 spotifyrpi volumio[824]: info: May 22 21:56:21 spotifyrpi volumio[824]: ---------------------------- MPD announces state update: update May 22 21:56:21 spotifyrpi volumio[824]: info: ControllerMpd::getState May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::sendMpdCommand status May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::sendMpdCommand status May 22 21:56:21 spotifyrpi volumio[824]: info: May 22 21:56:21 spotifyrpi volumio[824]: ---------------------------- MPD announces state update: update May 22 21:56:21 spotifyrpi volumio[824]: info: ControllerMpd::getState May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::sendMpdCommand status May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::sendMpdCommand status May 22 21:56:21 spotifyrpi volumio[824]: info: May 22 21:56:21 spotifyrpi volumio[824]: ---------------------------- MPD announces state update: update May 22 21:56:21 spotifyrpi volumio[824]: info: ControllerMpd::getState May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::sendMpdCommand status May 22 21:56:21 spotifyrpi volumio[824]: info: sendMpdCommand status took 16 milliseconds May 22 21:56:21 spotifyrpi volumio[824]: info: sendMpdCommand status took 12 milliseconds May 22 21:56:21 spotifyrpi volumio[824]: info: sendMpdCommand status took 11 milliseconds May 22 21:56:21 spotifyrpi volumio[824]: info: sendMpdCommand status took 9 milliseconds May 22 21:56:21 spotifyrpi volumio[824]: info: sendMpdCommand status took 8 milliseconds May 22 21:56:21 spotifyrpi volumio[824]: info: sendMpdCommand status took 7 milliseconds May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::parseState May 22 21:56:21 spotifyrpi volumio[824]: info: Command Router : Notfying DB Updatetrue May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::parseState May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::parseState May 22 21:56:21 spotifyrpi volumio[824]: info: Command Router : Notfying DB Updatetrue May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::Close All Modals sent May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::parseState May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::parseState May 22 21:56:21 spotifyrpi volumio[824]: info: Command Router : Notfying DB Updatetrue May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::Close All Modals sent May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::parseState May 22 21:56:21 spotifyrpi volumio[824]: info: ControllerMpd::pushState May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::servicePushState May 22 21:56:21 spotifyrpi volumio[824]: info: CoreStateMachine::pushState May 22 21:56:21 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioPushState May 22 21:56:21 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:21 spotifyrpi volumio[824]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd May 22 21:56:21 spotifyrpi volumio[824]: info: ControllerMpd::pushState May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::servicePushState May 22 21:56:21 spotifyrpi volumio[824]: info: CoreStateMachine::pushState May 22 21:56:21 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioPushState May 22 21:56:21 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:21 spotifyrpi volumio[824]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd May 22 21:56:21 spotifyrpi volumio[824]: info: ControllerMpd::pushState May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::servicePushState May 22 21:56:21 spotifyrpi volumio[824]: info: CoreStateMachine::pushState May 22 21:56:21 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioPushState May 22 21:56:21 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:21 spotifyrpi volumio[824]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd May 22 21:56:21 spotifyrpi volumio[824]: info: ------------------------------ 334ms May 22 21:56:21 spotifyrpi volumio[824]: info: ------------------------------ 330ms May 22 21:56:21 spotifyrpi volumio[824]: info: ------------------------------ 328ms May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService May 22 21:56:21 spotifyrpi volumio[824]: info: [1747943781489] Database update started May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::sendMpdCommand status May 22 21:56:21 spotifyrpi volumio[824]: info: May 22 21:56:21 spotifyrpi volumio[824]: ---------------------------- MPD announces state update: update May 22 21:56:21 spotifyrpi volumio[824]: info: ControllerMpd::getState May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::sendMpdCommand status May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::sendMpdCommand status May 22 21:56:21 spotifyrpi volumio[824]: info: May 22 21:56:21 spotifyrpi volumio[824]: ---------------------------- MPD announces state update: update May 22 21:56:21 spotifyrpi volumio[824]: info: ControllerMpd::getState May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::sendMpdCommand status May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::sendMpdCommand status May 22 21:56:21 spotifyrpi volumio[824]: info: May 22 21:56:21 spotifyrpi volumio[824]: ---------------------------- MPD announces state update: update May 22 21:56:21 spotifyrpi volumio[824]: info: ControllerMpd::getState May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::sendMpdCommand status May 22 21:56:21 spotifyrpi volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 22 21:56:21 spotifyrpi volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 22 21:56:21 spotifyrpi volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 22 21:56:21 spotifyrpi volumio[824]: info: sendMpdCommand status took 88 milliseconds May 22 21:56:21 spotifyrpi volumio[824]: info: sendMpdCommand status took 85 milliseconds May 22 21:56:21 spotifyrpi volumio[824]: info: sendMpdCommand status took 83 milliseconds May 22 21:56:21 spotifyrpi volumio[824]: info: sendMpdCommand status took 75 milliseconds May 22 21:56:21 spotifyrpi volumio[824]: info: sendMpdCommand status took 72 milliseconds May 22 21:56:21 spotifyrpi volumio[824]: info: sendMpdCommand status took 58 milliseconds May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::parseState May 22 21:56:21 spotifyrpi volumio[824]: info: Command Router : Notfying DB Updatefalse May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::Close All Modals sent May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::parseState May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::parseState May 22 21:56:21 spotifyrpi volumio[824]: info: Command Router : Notfying DB Updatefalse May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::Close All Modals sent May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::parseState May 22 21:56:21 spotifyrpi volumio[824]: info: Command Router : Notfying DB Updatefalse May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::Close All Modals sent May 22 21:56:21 spotifyrpi volumio[824]: verbose: ControllerMpd::parseState May 22 21:56:21 spotifyrpi volumio[824]: info: ControllerMpd::pushState May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::servicePushState May 22 21:56:21 spotifyrpi volumio[824]: info: CoreStateMachine::pushState May 22 21:56:21 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioPushState May 22 21:56:21 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:21 spotifyrpi volumio[824]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd May 22 21:56:21 spotifyrpi volumio[824]: info: ControllerMpd::pushState May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::servicePushState May 22 21:56:21 spotifyrpi volumio[824]: info: CoreStateMachine::pushState May 22 21:56:21 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioPushState May 22 21:56:21 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:21 spotifyrpi volumio[824]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd May 22 21:56:21 spotifyrpi volumio[824]: info: ControllerMpd::pushState May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::servicePushState May 22 21:56:21 spotifyrpi volumio[824]: info: CoreStateMachine::pushState May 22 21:56:21 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:21 spotifyrpi volumio[824]: info: CoreCommandRouter::volumioPushState May 22 21:56:21 spotifyrpi volumio[824]: info: CorePlayQueue::getTrack 0 May 22 21:56:21 spotifyrpi volumio[824]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd May 22 21:56:21 spotifyrpi volumio[824]: info: ------------------------------ 382ms May 22 21:56:21 spotifyrpi volumio[824]: info: ------------------------------ 377ms May 22 21:56:21 spotifyrpi volumio[824]: info: ------------------------------ 366ms May 22 21:56:21 spotifyrpi volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 22 21:56:21 spotifyrpi volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 22 21:56:21 spotifyrpi volumio[824]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 22 21:56:21 spotifyrpi volumio[824]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 22 21:56:21 spotifyrpi volumio[824]: Error: dns service error: unknown May 22 21:56:21 spotifyrpi volumio[824]: at MDNSService.on_resolver_done (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:19:30) May 22 21:56:21 spotifyrpi volumio[824]: at SocketWatcher.MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { May 22 21:56:21 spotifyrpi volumio[824]: errorCode: -65537 May 22 21:56:21 spotifyrpi volumio[824]: } May 22 21:56:21 spotifyrpi volumio[824]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 22 21:56:22 spotifyrpi sudo[1897]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-22 21:55 May 22 21:56:22 spotifyrpi sudo[1897]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"