-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Wed 2026-02-11 09:04:48 CET. -- Feb 11 09:03:03 volumio volumio-remote-updater[478]: [2026-02-11 09:03:03] [connect] Successful connection Feb 11 09:03:04 volumio volumio[672]: info: Loading plugin "outputs"... Feb 11 09:03:04 volumio volumio[672]: info: Loading plugin "albumart"... Feb 11 09:03:04 volumio volumio[672]: info: Plugin example_plugin is not enabled Feb 11 09:03:04 volumio volumio[672]: info: Loading plugin "inputs"... Feb 11 09:03:04 volumio volumio[672]: info: Loading plugin "updater_comm"... Feb 11 09:03:05 volumio volumio[672]: info: Plugin mpdemulation is not enabled Feb 11 09:03:05 volumio volumio[672]: info: Loading plugin "rest_api"... Feb 11 09:03:05 volumio volumio[672]: info: Loading plugin "websocket"... Feb 11 09:03:05 volumio volumio[672]: info: Starting Socket.io Server version 2.3.0 Feb 11 09:03:05 volumio volumio[672]: info: Loading i18n strings for locale pl Feb 11 09:03:05 volumio volumio[672]: Updating browse sources language Feb 11 09:03:05 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:03:05 volumio volumio[672]: Forking 3 albumart workers Feb 11 09:03:05 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 09:03:05 volumio volumio[672]: info: CoreCommandRouter::initPlayerControls Feb 11 09:03:05 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:05 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:05 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:05 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:05 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:05 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:05 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:05 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:05 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 09:03:05 volumio volumio[672]: Express server listening on port 3000 Feb 11 09:03:05 volumio volumio[672]: [Metrics] WebUI: 39s 84.26ms Feb 11 09:03:06 volumio volumio[672]: info: CoreStateMachine::resetVolumioState Feb 11 09:03:06 volumio volumio[672]: info: CoreStateMachine::getcurrentVolume Feb 11 09:03:06 volumio volumio[672]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 09:03:06 volumio sudo[1039]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 09:03:06 volumio sudo[1039]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:06 volumio sudo[1039]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:06 volumio sudo[1041]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 09:03:06 volumio sudo[1041]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:06 volumio volumio[672]: info: Volumio Network Manager: Network status updated: 1 Feb 11 09:03:06 volumio sudo[1041]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:06 volumio volumio[672]: info: Cannot mount NAS Dysk at system boot, trial number 1 ,retrying in 5 seconds Feb 11 09:03:06 volumio volumio[672]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Feb 11 09:03:06 volumio volumio[672]: wlan0 Interface doesn't support scanning. Feb 11 09:03:06 volumio volumio[672]: info: Cannot use regular scanning, forcing with ap-force Feb 11 09:03:06 volumio sudo[1048]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Feb 11 09:03:06 volumio sudo[1048]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:06 volumio sudo[1048]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:06 volumio volumio[672]: command failed: No such device (-19) Feb 11 09:03:06 volumio volumio[672]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Feb 11 09:03:06 volumio volumio[672]: command failed: No such device (-19) Feb 11 09:03:07 volumio volumio-remote-updater[478]: [2026-02-11 09:03:07] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1770796983 101 Feb 11 09:03:07 volumio volumio[672]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Feb 11 09:03:07 volumio volumio[672]: info: VolumeController:: Volume=33 Mute =false Feb 11 09:03:07 volumio volumio[672]: info: CoreStateMachine::pushState Feb 11 09:03:07 volumio volumio[672]: info: CorePlayQueue::getTrack 0 Feb 11 09:03:07 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 09:03:07 volumio volumio[672]: info: CoreCommandRouter::volumioPushState Feb 11 09:03:07 volumio volumio[672]: info: CoreStateMachine::updateTrackBlock Feb 11 09:03:07 volumio volumio[672]: info: CorePlayQueue::getTrackBlock Feb 11 09:03:07 volumio volumio[672]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 09:03:07 volumio volumio[672]: info: Reloading queue from file Feb 11 09:03:07 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:03:07 volumio volumio[672]: info: CoreStateMachine::setRepeat false single undefined Feb 11 09:03:07 volumio volumio[672]: info: CoreStateMachine::pushState Feb 11 09:03:07 volumio volumio[672]: info: CorePlayQueue::getTrack 0 Feb 11 09:03:07 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 09:03:07 volumio volumio[672]: info: CoreCommandRouter::volumioPushState Feb 11 09:03:07 volumio volumio[672]: info: CoreStateMachine::setRandom false Feb 11 09:03:07 volumio volumio[672]: info: CoreStateMachine::pushState Feb 11 09:03:07 volumio volumio[672]: info: CorePlayQueue::getTrack 0 Feb 11 09:03:07 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 09:03:07 volumio volumio[672]: info: CoreCommandRouter::volumioPushState Feb 11 09:03:07 volumio volumio[672]: info: Setting Device type: Raspberry PI Feb 11 09:03:07 volumio volumio[672]: info: Completed loading Core Plugins Feb 11 09:03:07 volumio volumio[672]: info: Preparing to generate the ALSA configuration file Feb 11 09:03:07 volumio volumio[672]: Starting albumart workers Feb 11 09:03:07 volumio volumio[672]: Starting albumart workers Feb 11 09:03:07 volumio volumio[672]: Starting albumart workers Feb 11 09:03:07 volumio volumio[672]: info: VolumeController:: Volume=33 Mute =false Feb 11 09:03:07 volumio volumio[672]: info: CoreStateMachine::pushState Feb 11 09:03:07 volumio volumio[672]: info: CorePlayQueue::getTrack 0 Feb 11 09:03:07 volumio volumio[672]: info: CoreCommandRouter::volumioPushState Feb 11 09:03:07 volumio volumio[672]: info: Asound.conf file unchanged, so no further update is needed Feb 11 09:03:07 volumio volumio[672]: info: Output device has changed, restarting MPD Feb 11 09:03:07 volumio sudo[1060]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 09:03:07 volumio sudo[1060]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:07 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Feb 11 09:03:07 volumio volumio[672]: info: Output device has changed, restarting Shairport Sync Feb 11 09:03:07 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:07 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:03:07 volumio sudo[1060]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:08 volumio sudo[1063]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 09:03:08 volumio sudo[1063]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:08 volumio sudo[1063]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:08 volumio sudo[1066]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 09:03:08 volumio sudo[1066]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:08 volumio volumio[672]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 09:03:08 volumio volumio[672]: info: ___________ START PLUGINS ___________ Feb 11 09:03:08 volumio volumio[672]: info: ControllerMpd::onStart: Initializing MPD Feb 11 09:03:08 volumio volumio[672]: info: Creating MPD Configuration file Feb 11 09:03:08 volumio systemd[1]: Listening on mpd.socket. Feb 11 09:03:08 volumio systemd[1]: Starting Music Player Daemon... Feb 11 09:03:08 volumio sudo[1074]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 09:03:08 volumio sudo[1074]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:08 volumio sudo[1074]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:08 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 09:03:08 volumio volumio[672]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:03:08 volumio volumio[672]: info: [1770796988443] CoreMusicLibrary::Adding element Serwery Mediów Feb 11 09:03:08 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:03:08 volumio volumio[672]: info: UPNP Browser: Client initialized successfully Feb 11 09:03:08 volumio sudo[1078]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 09:03:08 volumio sudo[1078]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:08 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:08 volumio sudo[1075]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 09:03:08 volumio sudo[1075]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:08 volumio sudo[1075]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:08 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Feb 11 09:03:08 volumio systemd[1]: mpd.service: Succeeded. Feb 11 09:03:08 volumio systemd[1]: Stopped Music Player Daemon. Feb 11 09:03:08 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:03:08 volumio systemd[1]: Starting Music Player Daemon... Feb 11 09:03:08 volumio volumio[672]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 09:03:08 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:08 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:03:09 volumio sudo[1080]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 09:03:09 volumio sudo[1080]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:09 volumio sudo[1080]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Feb 11 09:03:09 volumio sudo[1080]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:09 volumio volumio[672]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 09:03:09 volumio volumio[672]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:03:09 volumio volumio[672]: info: [1770796989056] CoreMusicLibrary::Adding element Last_100 Feb 11 09:03:09 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:03:09 volumio volumio[672]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:03:09 volumio volumio[672]: info: [1770796989065] CoreMusicLibrary::Adding element Webradio Feb 11 09:03:09 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:03:09 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 09:03:09 volumio volumio[672]: info: Initializing BBC Radios Feb 11 09:03:09 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 09:03:09 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:03:09 volumio volumio[672]: info: Creating Spotify config file Feb 11 09:03:09 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:09 volumio volumio[672]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:03:09 volumio volumio[672]: info: [1770796989436] CoreMusicLibrary::Adding element YouTube2 Feb 11 09:03:09 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:03:09 volumio volumio[672]: Cannot find translation for source YouTube2 Feb 11 09:03:09 volumio volumio[672]: info: [ytcr] Data store TTL expired - clearing it... Feb 11 09:03:09 volumio volumio[672]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:03:09 volumio volumio[672]: info: [1770796989605] CoreMusicLibrary::Adding element YouTube Music Feb 11 09:03:09 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:03:09 volumio volumio[672]: Cannot find translation for source YouTube2 Feb 11 09:03:09 volumio volumio[672]: Cannot find translation for source YouTube Music Feb 11 09:03:09 volumio volumio[672]: info: Volumio Calling Home Feb 11 09:03:10 volumio volumio[672]: info: Discovery: adding 2fe05d6a-f0d4-420f-9222-11dac4e7c1ed Feb 11 09:03:10 volumio volumio[672]: info: Discovery: Found device Volumio Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::volumioGetState Feb 11 09:03:10 volumio volumio[672]: info: CorePlayQueue::getTrack 0 Feb 11 09:03:10 volumio volumio[672]: info: Discovery: A device disappeared from network Feb 11 09:03:10 volumio volumio[672]: info: Discovery: Device volumio disappeared from network Feb 11 09:03:10 volumio volumio[672]: info: MPD Permissions set Feb 11 09:03:10 volumio volumio[672]: info: Upmpdcli Daemon Started Feb 11 09:03:10 volumio volumio[672]: info: Volumio called home Feb 11 09:03:10 volumio volumio[672]: info: Spotify config file written Feb 11 09:03:10 volumio sudo[1128]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 09:03:10 volumio sudo[1128]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:10 volumio systemd[1]: Started go-librespot Daemon. Feb 11 09:03:10 volumio go-librespot[1130]: go-librespot daemon starting... Feb 11 09:03:10 volumio sudo[1128]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:10 volumio volumio[672]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:03:10 volumio volumio[672]: info: No need to fix Spotify hosts Feb 11 09:03:11 volumio volumio[672]: info: Discovery: adding 2fe05d6a-f0d4-420f-9222-11dac4e7c1ed Feb 11 09:03:11 volumio volumio[672]: info: Discovery: Found device Volumio Feb 11 09:03:11 volumio volumio[672]: info: CoreCommandRouter::volumioGetState Feb 11 09:03:11 volumio volumio[672]: info: CorePlayQueue::getTrack 0 Feb 11 09:03:11 volumio volumio[672]: info: Starting Shairport Sync Feb 11 09:03:11 volumio go-librespot[1130]: time="2026-02-11T09:03:11+01:00" level=info msg="running go-librespot 0.4.0" Feb 11 09:03:11 volumio go-librespot[1130]: time="2026-02-11T09:03:11+01:00" level=debug msg="app state loaded" Feb 11 09:03:11 volumio go-librespot[1130]: time="2026-02-11T09:03:11+01:00" level=debug msg="stored credentials not found" Feb 11 09:03:11 volumio go-librespot[1130]: time="2026-02-11T09:03:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 09:03:11 volumio volumio[672]: info: Starting Shairport Sync Feb 11 09:03:11 volumio volumio[672]: info: Starting Shairport Sync Feb 11 09:03:11 volumio sudo[1146]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 09:03:11 volumio sudo[1146]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:11 volumio sudo[1148]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 09:03:11 volumio sudo[1148]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:11 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 11 09:03:11 volumio systemd[1]: shairport-sync.service: Succeeded. Feb 11 09:03:11 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 11 09:03:11 volumio sudo[1151]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 09:03:11 volumio sudo[1151]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:11 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 11 09:03:11 volumio sudo[1146]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:11 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 11 09:03:11 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Feb 11 09:03:11 volumio systemd[1]: shairport-sync.service: Succeeded. Feb 11 09:03:11 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 11 09:03:11 volumio volumio[672]: info: CoreCommandRouter::volumioGetState Feb 11 09:03:11 volumio volumio[672]: info: CorePlayQueue::getTrack 0 Feb 11 09:03:11 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 11 09:03:11 volumio sudo[1148]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:11 volumio sudo[1151]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:12 volumio sudo[1160]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Volumio,password=Ustijuf1@,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,vers=1.0 //192.168.50.1/muzyka /mnt/NAS/Dysk Feb 11 09:03:12 volumio sudo[1160]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:12 volumio volumio[672]: info: Shairport-Sync Started Feb 11 09:03:12 volumio volumio[672]: Error adding Membership: Error: addMembership EINVAL Feb 11 09:03:12 volumio volumio[672]: info: Shairport-Sync Started Feb 11 09:03:12 volumio volumio[672]: info: Shairport-Sync Started Feb 11 09:03:12 volumio kernel: Use of the less secure dialect vers=1.0 is not recommended unless required for access to very old servers Feb 11 09:03:12 volumio kernel: CIFS: VFS: Use of the less secure dialect vers=1.0 is not recommended unless required for access to very old servers Feb 11 09:03:12 volumio kernel: CIFS: Attempting to mount //192.168.50.1/muzyka Feb 11 09:03:12 volumio go-librespot[1130]: time="2026-02-11T09:03:12+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 11 09:03:12 volumio go-librespot[1130]: time="2026-02-11T09:03:12+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 11 09:03:12 volumio go-librespot[1130]: time="2026-02-11T09:03:12+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 11 09:03:12 volumio go-librespot[1130]: time="2026-02-11T09:03:12+01:00" level=info msg="zeroconf server listening on port 33571" Feb 11 09:03:12 volumio sudo[1160]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:13 volumio volumio[672]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 11 09:03:13 volumio volumio[672]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 09:03:13 volumio volumio[672]: info: VolumeController:: Volume=33 Mute =false Feb 11 09:03:13 volumio volumio[672]: info: CoreCommandRouter::volumioGetState Feb 11 09:03:13 volumio volumio[672]: info: CorePlayQueue::getTrack 0 Feb 11 09:03:13 volumio volumio[672]: info: CoreStateMachine::pushState Feb 11 09:03:13 volumio volumio[672]: info: CorePlayQueue::getTrack 0 Feb 11 09:03:13 volumio volumio[672]: info: CoreCommandRouter::volumioPushState Feb 11 09:03:14 volumio volumio[672]: info: go-librespot daemon successfully initialized Feb 11 09:03:14 volumio mpd[1088]: Feb 11 09:03 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 09:03:15 volumio systemd[1]: Started Music Player Daemon. Feb 11 09:03:15 volumio sudo[1066]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:15 volumio sudo[1078]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:15 volumio volumio[672]: Upnp client error: Error: This socket has been ended by the other party Feb 11 09:03:15 volumio volumio[672]: Upnp client error: Error: This socket has been ended by the other party Feb 11 09:03:16 volumio volumio[672]: error: MPD error: The expression evaluated to a falsy value: Feb 11 09:03:16 volumio volumio[672]: assert.ok(self.idling) Feb 11 09:03:16 volumio volumio[672]: error: The expression evaluated to a falsy value: Feb 11 09:03:16 volumio volumio[672]: assert.ok(self.idling) Feb 11 09:03:16 volumio volumio[672]: info: MPD running with PID1088 Feb 11 09:03:16 volumio volumio[672]: ,establishing connection Feb 11 09:03:16 volumio volumio[672]: error: updateQueue error: null Feb 11 09:03:16 volumio volumio[672]: info: Completed starting Core Plugins Feb 11 09:03:16 volumio volumio[672]: info: ------------------------------------------- Feb 11 09:03:16 volumio volumio[672]: info: ----- MyVolumio plugins startup ---- Feb 11 09:03:16 volumio volumio[672]: info: ------------------------------------------- Feb 11 09:03:16 volumio volumio[672]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 11 09:03:16 volumio volumio[672]: error: updateQueue error: null Feb 11 09:03:17 volumio systemd[1]: systemd-timedated.service: Succeeded. Feb 11 09:03:17 volumio volumio[672]: info: Initializing connection to go-librespot Websocket Feb 11 09:03:17 volumio go-librespot[1130]: time="2026-02-11T09:03:17+01:00" level=debug msg="new websocket client" Feb 11 09:03:17 volumio volumio[672]: info: Connection to go-librespot Websocket established Feb 11 09:03:18 volumio volumio[1064]: Generating RSA private key, 4096 bit long modulus (2 primes) Feb 11 09:03:18 volumio sudo[1210]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 11 09:03:19 volumio sudo[1210]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:19 volumio sudo[1212]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 11 09:03:19 volumio sudo[1212]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:19 volumio systemd[1]: Started MPD Monitor Service. Feb 11 09:03:19 volumio sudo[1210]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:19 volumio systemd[1]: Stopping MPD Monitor Service... Feb 11 09:03:19 volumio volumio[672]: info: Successfully started MPD Monitor Feb 11 09:03:19 volumio systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Feb 11 09:03:19 volumio systemd[1]: mpd_monitor.service: Succeeded. Feb 11 09:03:19 volumio systemd[1]: Stopped MPD Monitor Service. Feb 11 09:03:19 volumio systemd[1]: Started MPD Monitor Service. Feb 11 09:03:19 volumio sudo[1212]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:19 volumio volumio[672]: info: Successfully started MPD Monitor Feb 11 09:03:19 volumio mpd_monitor.sh[1216]: MPD Monitor Service: Starting MPD Monitor Service Feb 11 09:03:20 volumio volumio[672]: info: Getting Spotify volume Feb 11 09:03:20 volumio volumio[672]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 11 09:03:20 volumio volumio[672]: info: CoreCommandRouter::volumioGetState Feb 11 09:03:20 volumio volumio[672]: info: CorePlayQueue::getTrack 0 Feb 11 09:03:20 volumio volumio[672]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 Feb 11 09:03:20 volumio volumio[672]: SPOTIFY: SPOTIFY VOLUME undefined Feb 11 09:03:20 volumio volumio[672]: SPOTIFY: VOLUMIO VOLUME 33 Feb 11 09:03:20 volumio volumio[672]: info: Aligning Spotify Volume to Volumio Volume Feb 11 09:03:20 volumio volumio[672]: info: CoreCommandRouter::volumioGetState Feb 11 09:03:20 volumio volumio[672]: info: CorePlayQueue::getTrack 0 Feb 11 09:03:20 volumio volumio[672]: info: Setting Spotify Volume from Volumio: 33 Feb 11 09:03:21 volumio volumio[672]: SPOTIFY: SETTING SPOTIFY VOLUME 33 Feb 11 09:03:21 volumio volumio[672]: info: Sending Spotify command with payload to local API: /player/volume Feb 11 09:03:22 volumio volumio[672]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 11 09:03:26 volumio volumio[672]: info: Adding plugin bluetooth to MyMusic Plugins Feb 11 09:03:26 volumio volumio[672]: info: Adding plugin multiroom to MyMusic Plugins Feb 11 09:03:26 volumio volumio[672]: info: Adding plugin metavolumio to MyMusic Plugins Feb 11 09:03:26 volumio volumio[672]: info: Adding plugin cd_controller to MyMusic Plugins Feb 11 09:03:26 volumio volumio[672]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 11 09:03:26 volumio volumio[672]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 11 09:03:26 volumio volumio[672]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 11 09:03:26 volumio volumio[672]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 11 09:03:29 volumio volumio[672]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 11 09:03:29 volumio volumio[672]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 11 09:03:29 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:03:29 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:03:29 volumio volumio[672]: info: Starting MyVolumio Remote Streaming Endpoints Feb 11 09:03:29 volumio volumio[672]: info: MyVolumio login type: Token Feb 11 09:03:29 volumio volumio[672]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 11 09:03:29 volumio volumio[672]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 11 09:03:29 volumio ntpd[631]: Soliciting pool server 193.70.94.182 Feb 11 09:03:29 volumio ntpd[631]: Soliciting pool server 193.25.222.136 Feb 11 09:03:29 volumio ntpd[631]: Soliciting pool server 162.159.200.123 Feb 11 09:03:30 volumio ntpd[631]: Soliciting pool server 194.92.94.32 Feb 11 09:03:30 volumio ntpd[631]: Soliciting pool server 212.127.95.218 Feb 11 09:03:30 volumio ntpd[631]: Soliciting pool server 54.37.233.160 Feb 11 09:03:31 volumio ntpd[631]: Soliciting pool server 212.127.78.21 Feb 11 09:03:31 volumio ntpd[631]: Soliciting pool server 162.159.200.1 Feb 11 09:03:31 volumio ntpd[631]: Soliciting pool server 51.68.141.5 Feb 11 09:03:31 volumio ntpd[631]: Soliciting pool server 156.17.245.123 Feb 11 09:03:31 volumio volumio[672]: info: Starting Streaming Service Transparent Proxy Feb 11 09:03:32 volumio volumio[672]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 11 09:03:32 volumio volumio[672]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 11 09:03:32 volumio volumio[672]: info: Streaming services startup Feb 11 09:03:32 volumio volumio[672]: info: Starting Streaming Daemon Feb 11 09:03:32 volumio sudo[1279]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 11 09:03:32 volumio sudo[1279]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:32 volumio sudo[1279]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:32 volumio volumio[672]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 11 09:03:32 volumio ntpd[631]: Soliciting pool server 178.215.228.24 Feb 11 09:03:32 volumio ntpd[631]: Soliciting pool server 89.250.197.242 Feb 11 09:03:32 volumio ntpd[631]: Soliciting pool server 46.175.224.7 Feb 11 09:03:32 volumio ntpd[631]: Soliciting pool server 89.161.47.132 Feb 11 09:03:32 volumio volumio[672]: error: Cannot start Volumio Streaming Daemon Feb 11 09:03:32 volumio volumio[672]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 11 09:03:32 volumio volumio[672]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 11 09:03:33 volumio ntpd[631]: Soliciting pool server 89.161.47.136 Feb 11 09:03:34 volumio ntpd[631]: Soliciting pool server 51.38.131.245 Feb 11 09:03:35 volumio volumio[672]: error: MyVolumio Custom Token format not valid, refreshing it Feb 11 09:03:35 volumio volumio[672]: STREAMING PROXY: Starting server on port 3245 Feb 11 09:03:35 volumio volumio[672]: Node JS runtime: 14 Feb 11 09:03:35 volumio ntpd[631]: Soliciting pool server 2606:4700:f1::1 Feb 11 09:03:37 volumio ntpd[631]: receive: Unexpected origin timestamp 0xed36b658.96f7c84d does not match aorg 0000000000.00000000 from server@46.175.224.7 xmt 0xed36b659.3bf826df Feb 11 09:03:37 volumio ntpd[631]: receive: Unexpected origin timestamp 0xed36b658.96fcc1ea does not match aorg 0000000000.00000000 from server@156.17.245.123 xmt 0xed36b659.3f47b173 Feb 11 09:03:37 volumio ntpd[631]: receive: Unexpected origin timestamp 0xed36b658.96f3406c does not match aorg 0000000000.00000000 from server@178.215.228.24 xmt 0xed36b659.3d6cb874 Feb 11 09:03:40 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 09:03:40 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:03:40 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Feb 11 09:03:41 volumio volumio-remote-updater[478]: No test mode Feb 11 09:03:41 volumio volumio-remote-updater[478]: No alpha test mode Feb 11 09:03:41 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Feb 11 09:03:43 volumio volumio[672]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

 

NEW ADDITIONS

 

","title":"Update v3.908","updateavailable":true} Feb 11 09:03:43 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Feb 11 09:03:44 volumio volumio[1064]: ..........................................................................................................++++ Feb 11 09:03:45 volumio volumio[672]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 11 09:03:46 volumio volumio[672]: <--- Last few GCs ---> Feb 11 09:03:46 volumio volumio[672]: [672:0x508a780] 81151 ms: Scavenge 175.1 (187.4) -> 175.0 (187.4) MB, 3.2 / 0.0 ms (average mu = 0.875, current mu = 0.905) allocation failure Feb 11 09:03:46 volumio volumio[672]: [672:0x508a780] 81453 ms: Scavenge 191.0 (203.0) -> 190.9 (203.0) MB, 2.4 / 0.0 ms (average mu = 0.875, current mu = 0.905) allocation failure Feb 11 09:03:46 volumio volumio[672]: <--- JS stacktrace ---> Feb 11 09:03:46 volumio volumio[672]: FATAL ERROR: MarkCompactCollector: young object promotion failed Allocation failed - JavaScript heap out of memory Feb 11 09:03:46 volumio volumio-remote-updater[478]: [2026-02-11 09:03:46] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 11 09:03:46 volumio volumio-remote-updater[478]: [2026-02-11 09:03:46] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 11 09:03:46 volumio go-librespot[1130]: time="2026-02-11T09:03:46+01:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Feb 11 09:03:46 volumio systemd[1]: volumio.service: Main process exited, code=killed, status=11/SEGV Feb 11 09:03:46 volumio systemd[1]: volumio.service: Failed with result 'signal'. Feb 11 09:03:46 volumio systemd[1]: Started dynamicswap service. Feb 11 09:03:46 volumio systemd[1]: dynamicswap.service: Succeeded. Feb 11 09:03:46 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Feb 11 09:03:46 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Feb 11 09:03:46 volumio systemd[1]: Started dynamicswap service. Feb 11 09:03:46 volumio systemd[1]: Stopped Volumio Backend Module. Feb 11 09:03:46 volumio systemd[1]: Started Volumio Backend Module. Feb 11 09:03:47 volumio systemd[1]: dynamicswap.service: Succeeded. Feb 11 09:03:50 volumio volumio[1327]: info: ------------------------------------------- Feb 11 09:03:50 volumio volumio[1327]: info: ----- Volumio3 ---- Feb 11 09:03:50 volumio volumio[1327]: info: ------------------------------------------- Feb 11 09:03:50 volumio volumio[1327]: info: ----- System startup ---- Feb 11 09:03:50 volumio volumio[1327]: info: ------------------------------------------- Feb 11 09:03:51 volumio volumio[1327]: info: MYVOLUMIO Environment detected Feb 11 09:03:51 volumio volumio-remote-updater[478]: [2026-02-11 09:03:51] [connect] Successful connection Feb 11 09:03:51 volumio volumio[1327]: info: Plugin folders cleanup Feb 11 09:03:51 volumio volumio[1327]: info: Scanning into folder /volumio/app/plugins/ Feb 11 09:03:51 volumio volumio[1327]: info: Scanning category audio_interface Feb 11 09:03:51 volumio volumio[1327]: info: Scanning category miscellanea Feb 11 09:03:51 volumio volumio[1327]: info: Scanning category music_service Feb 11 09:03:51 volumio volumio[1327]: info: Scanning category plugins.json Feb 11 09:03:51 volumio volumio[1327]: info: Scanning category system_controller Feb 11 09:03:51 volumio volumio[1327]: info: Scanning category user_interface Feb 11 09:03:51 volumio volumio[1327]: info: Scanning into folder /data/plugins/ Feb 11 09:03:51 volumio volumio[1327]: info: Scanning category music_service Feb 11 09:03:51 volumio volumio[1327]: info: Plugin folders cleanup completed Feb 11 09:03:51 volumio volumio[1327]: info: ------------------------------------------- Feb 11 09:03:51 volumio volumio[1327]: info: ----- Core plugins startup ---- Feb 11 09:03:51 volumio volumio[1327]: info: ------------------------------------------- Feb 11 09:03:51 volumio volumio[1327]: info: Loading plugins from folder /volumio/app/plugins/ Feb 11 09:03:51 volumio volumio[1327]: info: Adding plugin upnp to MyMusic Plugins Feb 11 09:03:51 volumio volumio[1327]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 11 09:03:51 volumio volumio[1327]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 11 09:03:51 volumio volumio[1327]: info: Loading plugins from folder /data/plugins/ Feb 11 09:03:51 volumio volumio[1327]: info: Loading plugin "system"... Feb 11 09:03:51 volumio volumio[1327]: info: Loading plugin "appearance"... Feb 11 09:03:53 volumio volumio[1327]: info: Loading plugin "network"... Feb 11 09:03:53 volumio volumio[1327]: info: Refreshing Cached IP Addresses Feb 11 09:03:53 volumio sudo[1355]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 09:03:53 volumio sudo[1353]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 09:03:53 volumio sudo[1355]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:53 volumio sudo[1353]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:53 volumio sudo[1353]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:53 volumio volumio[1327]: info: Loading plugin "services"... Feb 11 09:03:53 volumio sudo[1355]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:53 volumio volumio[1327]: info: Loading plugin "alsa_controller"... Feb 11 09:03:54 volumio sudo[1370]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 11 09:03:54 volumio sudo[1370]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:03:54 volumio sudo[1370]: pam_unix(sudo:session): session closed for user root Feb 11 09:03:54 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 09:03:54 volumio volumio[1327]: info: Loading plugin "wizard"... Feb 11 09:03:54 volumio volumio[1327]: info: Loading plugin "networkfs"... Feb 11 09:03:54 volumio volumio[1327]: info: Cannot mount NAS Dysk at system boot, trial number 1 ,retrying in 5 seconds Feb 11 09:03:54 volumio volumio[1327]: info: Starting Udev Watcher for removable devices Feb 11 09:03:54 volumio volumio[1327]: info: Ignoring mount for partition: boot Feb 11 09:03:54 volumio volumio[1327]: info: Ignoring mount for partition: volumio Feb 11 09:03:54 volumio volumio[1327]: info: Ignoring mount for partition: volumio_data Feb 11 09:03:54 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 09:03:54 volumio volumio[1327]: info: Loading plugin "volumio_command_line_client"... Feb 11 09:03:54 volumio volumio[1327]: info: Loading plugin "upnp"... Feb 11 09:03:54 volumio volumio[1327]: info: [1770797034416] Starting Upmpd Daemon Feb 11 09:03:54 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 09:03:54 volumio volumio[1327]: info: Loading plugin "my_music"... Feb 11 09:03:54 volumio volumio[1327]: info: Loading plugin "mpd"... Feb 11 09:03:55 volumio volumio[1327]: info: Loading plugin "upnp_browser"... Feb 11 09:03:55 volumio volumio[1327]: info: Starting UPNP Browser Feb 11 09:03:55 volumio volumio[1327]: info: Loading plugin "alarm-clock"... Feb 11 09:03:55 volumio volumio[1327]: info: Loading plugin "airplay_emulation"... Feb 11 09:03:55 volumio volumio[1327]: info: Starting Shairport Sync Feb 11 09:03:55 volumio volumio[1327]: info: Loading plugin "last_100"... Feb 11 09:03:56 volumio volumio[1327]: info: Loading plugin "webradio"... Feb 11 09:03:56 volumio volumio[1327]: info: Loading plugin "i2s_dacs"... Feb 11 09:03:56 volumio volumio[1327]: info: Loading plugin "volumiodiscovery"... Feb 11 09:03:56 volumio volumio[1327]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 09:03:56 volumio volumio[1327]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 09:03:56 volumio volumio[1327]: *** WARNING *** For more information see Feb 11 09:03:56 volumio node[1327]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 11 09:03:56 volumio volumio[1327]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 09:03:56 volumio volumio[1327]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 09:03:56 volumio volumio[1327]: *** WARNING *** For more information see Feb 11 09:03:56 volumio node[1327]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 09:03:56 volumio node[1327]: *** WARNING *** For more information see Feb 11 09:03:56 volumio node[1327]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 11 09:03:56 volumio node[1327]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 11 09:03:56 volumio node[1327]: *** WARNING *** For more information see Feb 11 09:03:56 volumio volumio[1327]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 11 09:03:56 volumio volumio[1327]: info: Discovery: Started advertising with name: Volumio Feb 11 09:03:56 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 11 09:03:56 volumio volumio[1327]: info: Loading plugin "spop"... Feb 11 09:03:58 volumio volumio[1327]: info: Loading plugin "youtube2"... Feb 11 09:04:04 volumio volumio[1327]: info: Loading plugin "ytcr"... Feb 11 09:04:04 volumio volumio-remote-updater[478]: [2026-02-11 09:04:04] [connect] Successful connection Feb 11 09:04:12 volumio volumio[1327]: info: Loading plugin "ytmusic"... Feb 11 09:04:13 volumio volumio[1064]: ..........................................................................................................................++++ Feb 11 09:04:13 volumio volumio[1064]: e is 65537 (0x010001) Feb 11 09:04:13 volumio volumio[1064]: writing RSA key Feb 11 09:04:17 volumio volumio[1327]: info: Loading plugin "outputs"... Feb 11 09:04:17 volumio volumio[1327]: info: Loading plugin "albumart"... Feb 11 09:04:17 volumio volumio[1327]: info: Plugin example_plugin is not enabled Feb 11 09:04:17 volumio volumio[1327]: info: Loading plugin "inputs"... Feb 11 09:04:17 volumio volumio[1327]: info: Loading plugin "updater_comm"... Feb 11 09:04:17 volumio volumio[1327]: info: Plugin mpdemulation is not enabled Feb 11 09:04:17 volumio volumio[1327]: info: Loading plugin "rest_api"... Feb 11 09:04:17 volumio volumio[1327]: info: Loading plugin "websocket"... Feb 11 09:04:17 volumio volumio[1327]: info: Starting Socket.io Server version 2.3.0 Feb 11 09:04:18 volumio volumio[1327]: info: Loading i18n strings for locale pl Feb 11 09:04:18 volumio volumio[1327]: Updating browse sources language Feb 11 09:04:18 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:04:18 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 09:04:18 volumio volumio[1327]: info: CoreCommandRouter::initPlayerControls Feb 11 09:04:18 volumio volumio[1327]: Forking 3 albumart workers Feb 11 09:04:18 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:18 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:18 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:18 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:18 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:18 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:18 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:18 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:18 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 09:04:18 volumio volumio[1327]: Express server listening on port 3000 Feb 11 09:04:18 volumio volumio[1327]: [Metrics] WebUI: 29s 138.80ms Feb 11 09:04:18 volumio volumio[1327]: info: CoreStateMachine::resetVolumioState Feb 11 09:04:18 volumio volumio[1327]: info: CoreStateMachine::getcurrentVolume Feb 11 09:04:18 volumio volumio[1327]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 09:04:18 volumio volumio[1327]: info: Cannot mount NAS Dysk at system boot, trial number 2 ,retrying in 5 seconds Feb 11 09:04:18 volumio sudo[1475]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 11 09:04:18 volumio sudo[1475]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:04:18 volumio sudo[1475]: pam_unix(sudo:session): session closed for user root Feb 11 09:04:18 volumio sudo[1477]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 11 09:04:18 volumio sudo[1477]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:04:18 volumio volumio[1327]: info: Volumio Network Manager: Network status updated: 1 Feb 11 09:04:18 volumio sudo[1477]: pam_unix(sudo:session): session closed for user root Feb 11 09:04:19 volumio volumio[1327]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Feb 11 09:04:19 volumio volumio[1327]: wlan0 Interface doesn't support scanning. Feb 11 09:04:19 volumio volumio[1327]: info: Cannot use regular scanning, forcing with ap-force Feb 11 09:04:19 volumio sudo[1484]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Feb 11 09:04:19 volumio sudo[1484]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:04:19 volumio sudo[1484]: pam_unix(sudo:session): session closed for user root Feb 11 09:04:19 volumio volumio[1327]: command failed: No such device (-19) Feb 11 09:04:19 volumio volumio[1327]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Feb 11 09:04:19 volumio volumio[1327]: command failed: No such device (-19) Feb 11 09:04:19 volumio volumio-remote-updater[478]: [2026-02-11 09:04:19] [connect] Successful connection Feb 11 09:04:19 volumio volumio[1327]: info: VolumeController:: Volume=33 Mute =false Feb 11 09:04:19 volumio volumio[1327]: info: CoreStateMachine::pushState Feb 11 09:04:19 volumio volumio[1327]: info: CorePlayQueue::getTrack 0 Feb 11 09:04:19 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 09:04:19 volumio volumio[1327]: info: CoreCommandRouter::volumioPushState Feb 11 09:04:19 volumio volumio[1327]: info: CoreStateMachine::updateTrackBlock Feb 11 09:04:19 volumio volumio[1327]: info: CorePlayQueue::getTrackBlock Feb 11 09:04:19 volumio volumio[1327]: info: CoreCommandRouter::volumioRetrievevolume Feb 11 09:04:19 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:04:19 volumio volumio[1327]: info: Reloading queue from file Feb 11 09:04:19 volumio volumio-remote-updater[478]: [2026-02-11 09:04:19] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1770797059 101 Feb 11 09:04:19 volumio volumio[1327]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Feb 11 09:04:19 volumio volumio[1327]: info: CoreStateMachine::setRepeat false single undefined Feb 11 09:04:19 volumio volumio[1327]: info: CoreStateMachine::pushState Feb 11 09:04:19 volumio volumio[1327]: info: CorePlayQueue::getTrack 0 Feb 11 09:04:19 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 09:04:19 volumio volumio[1327]: info: CoreCommandRouter::volumioPushState Feb 11 09:04:19 volumio volumio[1327]: info: CoreStateMachine::setRandom false Feb 11 09:04:19 volumio volumio[1327]: info: CoreStateMachine::pushState Feb 11 09:04:19 volumio volumio[1327]: info: CorePlayQueue::getTrack 0 Feb 11 09:04:19 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 11 09:04:19 volumio volumio[1327]: info: CoreCommandRouter::volumioPushState Feb 11 09:04:19 volumio volumio[1327]: info: Setting Device type: Raspberry PI Feb 11 09:04:19 volumio volumio[1327]: info: Completed loading Core Plugins Feb 11 09:04:20 volumio volumio[1327]: info: Preparing to generate the ALSA configuration file Feb 11 09:04:20 volumio volumio[1327]: info: Discovery: adding 2fe05d6a-f0d4-420f-9222-11dac4e7c1ed Feb 11 09:04:20 volumio volumio[1327]: info: Discovery: Found device Volumio Feb 11 09:04:20 volumio volumio[1327]: info: CoreCommandRouter::volumioGetState Feb 11 09:04:20 volumio volumio[1327]: info: CorePlayQueue::getTrack 0 Feb 11 09:04:20 volumio sudo[1499]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 11 09:04:20 volumio sudo[1499]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:04:20 volumio volumio[1327]: info: Asound.conf file unchanged, so no further update is needed Feb 11 09:04:20 volumio volumio[1327]: info: Output device has changed, restarting MPD Feb 11 09:04:20 volumio sudo[1499]: pam_unix(sudo:session): session closed for user root Feb 11 09:04:20 volumio sudo[1502]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 09:04:20 volumio sudo[1502]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:04:20 volumio volumio[1327]: Starting albumart workers Feb 11 09:04:20 volumio sudo[1502]: pam_unix(sudo:session): session closed for user root Feb 11 09:04:20 volumio volumio[1327]: info: Output device has changed, restarting Shairport Sync Feb 11 09:04:20 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:20 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:04:20 volumio sudo[1505]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 09:04:20 volumio sudo[1505]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:04:20 volumio volumio[1327]: Starting albumart workers Feb 11 09:04:20 volumio volumio[1327]: Starting albumart workers Feb 11 09:04:20 volumio systemd[1]: Stopping Music Player Daemon... Feb 11 09:04:20 volumio volumio[1327]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 09:04:20 volumio volumio[1327]: info: ___________ START PLUGINS ___________ Feb 11 09:04:20 volumio volumio[1327]: info: ControllerMpd::onStart: Initializing MPD Feb 11 09:04:20 volumio volumio[1327]: info: Creating MPD Configuration file Feb 11 09:04:20 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 11 09:04:20 volumio volumio[1327]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:04:20 volumio volumio[1327]: info: [1770797060977] CoreMusicLibrary::Adding element Serwery Mediów Feb 11 09:04:20 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:04:21 volumio systemd[1]: mpd.service: Succeeded. Feb 11 09:04:21 volumio systemd[1]: Stopped Music Player Daemon. Feb 11 09:04:21 volumio sudo[1527]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 11 09:04:21 volumio sudo[1527]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:04:21 volumio volumio[1327]: info: UPNP Browser: Client initialized successfully Feb 11 09:04:21 volumio sudo[1535]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 11 09:04:21 volumio sudo[1535]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:04:21 volumio systemd[1]: Starting Music Player Daemon... Feb 11 09:04:21 volumio sudo[1527]: pam_unix(sudo:session): session closed for user root Feb 11 09:04:21 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Feb 11 09:04:21 volumio systemd[1]: mpd.service: Succeeded. Feb 11 09:04:21 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:21 volumio systemd[1]: Stopped Music Player Daemon. Feb 11 09:04:21 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:04:21 volumio systemd[1]: Starting Music Player Daemon... Feb 11 09:04:21 volumio volumio[1327]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 09:04:21 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:21 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:04:21 volumio sudo[1555]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 11 09:04:21 volumio sudo[1555]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:04:21 volumio volumio[1327]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 11 09:04:21 volumio volumio[1327]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:04:21 volumio volumio[1327]: info: [1770797061640] CoreMusicLibrary::Adding element Last_100 Feb 11 09:04:21 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:04:21 volumio sudo[1555]: pam_unix(sudo:session): session closed for user root Feb 11 09:04:21 volumio volumio[1327]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:04:21 volumio volumio[1327]: info: [1770797061653] CoreMusicLibrary::Adding element Webradio Feb 11 09:04:21 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:04:21 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 09:04:21 volumio volumio[1327]: info: Initializing BBC Radios Feb 11 09:04:22 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 11 09:04:22 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:04:22 volumio volumio[1327]: info: Creating Spotify config file Feb 11 09:04:22 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:22 volumio volumio[1327]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:04:22 volumio volumio[1327]: info: [1770797062105] CoreMusicLibrary::Adding element YouTube2 Feb 11 09:04:22 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:04:22 volumio volumio[1327]: Cannot find translation for source YouTube2 Feb 11 09:04:22 volumio volumio[1327]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 11 09:04:22 volumio volumio[1327]: info: [1770797062465] CoreMusicLibrary::Adding element YouTube Music Feb 11 09:04:22 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 11 09:04:22 volumio volumio[1327]: Cannot find translation for source YouTube2 Feb 11 09:04:22 volumio volumio[1327]: Cannot find translation for source YouTube Music Feb 11 09:04:22 volumio volumio[1327]: info: Volumio Calling Home Feb 11 09:04:23 volumio volumio[1327]: info: VolumeController:: Volume=33 Mute =false Feb 11 09:04:23 volumio volumio[1327]: info: CoreCommandRouter::volumioGetState Feb 11 09:04:23 volumio volumio[1327]: info: CorePlayQueue::getTrack 0 Feb 11 09:04:23 volumio volumio[1327]: info: CoreStateMachine::pushState Feb 11 09:04:23 volumio volumio[1327]: info: CorePlayQueue::getTrack 0 Feb 11 09:04:23 volumio volumio[1327]: info: CoreCommandRouter::volumioPushState Feb 11 09:04:23 volumio volumio[1327]: info: MPD Permissions set Feb 11 09:04:23 volumio volumio[1327]: info: MPD Permissions set Feb 11 09:04:23 volumio volumio[1327]: info: Upmpdcli Daemon Started Feb 11 09:04:23 volumio volumio[1327]: info: Spotify config file written Feb 11 09:04:23 volumio sudo[1602]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 11 09:04:23 volumio sudo[1602]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:04:23 volumio volumio[1327]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 11 09:04:23 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:23 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:23 volumio systemd[1]: Stopping go-librespot Daemon... Feb 11 09:04:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Feb 11 09:04:23 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Feb 11 09:04:23 volumio systemd[1]: Stopped go-librespot Daemon. Feb 11 09:04:23 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:04:23 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:23 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:23 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:23 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:23 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:23 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:23 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:23 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:23 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:23 volumio go-librespot[1608]: go-librespot daemon starting... Feb 11 09:04:23 volumio systemd[1]: Started go-librespot Daemon. Feb 11 09:04:23 volumio sudo[1602]: pam_unix(sudo:session): session closed for user root Feb 11 09:04:23 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 11 09:04:23 volumio volumio[1327]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 11 09:04:23 volumio volumio[1327]: info: No need to fix Spotify hosts Feb 11 09:04:23 volumio go-librespot[1608]: time="2026-02-11T09:04:23+01:00" level=info msg="running go-librespot 0.4.0" Feb 11 09:04:23 volumio go-librespot[1608]: time="2026-02-11T09:04:23+01:00" level=debug msg="app state loaded" Feb 11 09:04:23 volumio go-librespot[1608]: time="2026-02-11T09:04:23+01:00" level=debug msg="stored credentials not found" Feb 11 09:04:23 volumio go-librespot[1608]: time="2026-02-11T09:04:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 11 09:04:23 volumio volumio[1327]: info: Cannot mount NAS Dysk at system boot, trial number 3 ,retrying in 5 seconds Feb 11 09:04:23 volumio volumio[1327]: info: Starting Shairport Sync Feb 11 09:04:23 volumio volumio[1327]: info: Starting Shairport Sync Feb 11 09:04:23 volumio sudo[1623]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 09:04:23 volumio sudo[1623]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:04:23 volumio volumio[1327]: info: Starting Shairport Sync Feb 11 09:04:23 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 11 09:04:24 volumio sudo[1626]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 09:04:24 volumio systemd[1]: shairport-sync.service: Succeeded. Feb 11 09:04:24 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 11 09:04:24 volumio sudo[1626]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:04:24 volumio go-librespot[1608]: time="2026-02-11T09:04:24+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 11 09:04:24 volumio go-librespot[1608]: time="2026-02-11T09:04:24+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 11 09:04:24 volumio go-librespot[1608]: time="2026-02-11T09:04:24+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 11 09:04:24 volumio go-librespot[1608]: time="2026-02-11T09:04:24+01:00" level=info msg="zeroconf server listening on port 42545" Feb 11 09:04:24 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 11 09:04:24 volumio sudo[1623]: pam_unix(sudo:session): session closed for user root Feb 11 09:04:24 volumio sudo[1630]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 11 09:04:24 volumio sudo[1630]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:04:24 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 11 09:04:24 volumio systemd[1]: shairport-sync.service: Succeeded. Feb 11 09:04:24 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 11 09:04:24 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 11 09:04:24 volumio sudo[1626]: pam_unix(sudo:session): session closed for user root Feb 11 09:04:24 volumio volumio[1327]: info: Shairport-Sync Started Feb 11 09:04:24 volumio volumio[1327]: Error adding Membership: Error: addMembership EINVAL Feb 11 09:04:24 volumio sudo[1630]: pam_unix(sudo:session): session closed for user root Feb 11 09:04:24 volumio volumio[1327]: info: Shairport-Sync Started Feb 11 09:04:24 volumio volumio[1327]: info: Shairport-Sync Started Feb 11 09:04:25 volumio mpd[1563]: Feb 11 09:04 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 11 09:04:26 volumio systemd[1]: Started Music Player Daemon. Feb 11 09:04:26 volumio sudo[1535]: pam_unix(sudo:session): session closed for user root Feb 11 09:04:26 volumio sudo[1505]: pam_unix(sudo:session): session closed for user root Feb 11 09:04:26 volumio volumio[1327]: error: MPD error: The expression evaluated to a falsy value: Feb 11 09:04:26 volumio volumio[1327]: assert.ok(self.idling) Feb 11 09:04:26 volumio volumio[1327]: error: The expression evaluated to a falsy value: Feb 11 09:04:26 volumio volumio[1327]: assert.ok(self.idling) Feb 11 09:04:26 volumio volumio[1327]: info: MPD running with PID1563 Feb 11 09:04:26 volumio volumio[1327]: ,establishing connection Feb 11 09:04:26 volumio volumio[1327]: error: updateQueue error: null Feb 11 09:04:26 volumio volumio[1327]: error: updateQueue error: null Feb 11 09:04:26 volumio volumio[1327]: info: go-librespot daemon successfully initialized Feb 11 09:04:27 volumio volumio[1327]: info: Volumio called home Feb 11 09:04:28 volumio volumio[1327]: info: CoreCommandRouter::volumioGetState Feb 11 09:04:28 volumio volumio[1327]: info: CorePlayQueue::getTrack 0 Feb 11 09:04:28 volumio volumio[1327]: info: Cannot mount NAS Dysk at system boot, trial number 4 ,retrying in 5 seconds Feb 11 09:04:29 volumio sudo[1655]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 11 09:04:29 volumio sudo[1655]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:04:29 volumio systemd[1]: Stopping MPD Monitor Service... Feb 11 09:04:29 volumio systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Feb 11 09:04:29 volumio systemd[1]: mpd_monitor.service: Succeeded. Feb 11 09:04:29 volumio systemd[1]: Stopped MPD Monitor Service. Feb 11 09:04:29 volumio sudo[1658]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Feb 11 09:04:29 volumio sudo[1658]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 11 09:04:29 volumio systemd[1]: Started MPD Monitor Service. Feb 11 09:04:29 volumio mpd_monitor.sh[1660]: MPD Monitor Service: Starting MPD Monitor Service Feb 11 09:04:29 volumio sudo[1655]: pam_unix(sudo:session): session closed for user root Feb 11 09:04:29 volumio systemd[1]: Stopping MPD Monitor Service... Feb 11 09:04:29 volumio volumio[1327]: info: Successfully started MPD Monitor Feb 11 09:04:29 volumio systemd[1]: mpd_monitor.service: Main process exited, code=killed, status=15/TERM Feb 11 09:04:29 volumio systemd[1]: mpd_monitor.service: Succeeded. Feb 11 09:04:29 volumio systemd[1]: Stopped MPD Monitor Service. Feb 11 09:04:29 volumio systemd[1]: Started MPD Monitor Service. Feb 11 09:04:29 volumio sudo[1658]: pam_unix(sudo:session): session closed for user root Feb 11 09:04:29 volumio volumio[1327]: info: Successfully started MPD Monitor Feb 11 09:04:29 volumio mpd_monitor.sh[1663]: MPD Monitor Service: Starting MPD Monitor Service Feb 11 09:04:29 volumio volumio[1327]: info: Initializing connection to go-librespot Websocket Feb 11 09:04:32 volumio volumio[1327]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 11 09:04:33 volumio go-librespot[1608]: time="2026-02-11T09:04:33+01:00" level=debug msg="new websocket client" Feb 11 09:04:33 volumio volumio[1327]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Feb 11 09:04:34 volumio volumio[1327]: info: Connection to go-librespot Websocket established Feb 11 09:04:37 volumio volumio[1327]: info: Getting Spotify volume Feb 11 09:04:38 volumio volumio[1327]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=debug msg="obtained new client token: AADc4/tNHaWHBFJl0t5XUZVarKaSsh5/Kj5NIbUc6EKYhPi1K6x1CQiBOAM/Qwan+IlreksbhoLw+VsDqoPLT6H6Gdb6/PMYriN9pvoUQ+ToQr5LQe39GOmev9cdr2bk7QeVYnXbiTWnDBFO4KnfllEuwe5mQ3nHtW7CZJu6GmoopAIrMZsMkYvbSJJU5E9C7Ou8mPIJIc9W4QjjrNZkj3WN5dNOqtdX4KumDiE6WfECA35XnVVYx51a" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=debug msg="completed keyexchange" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=debug msg="completed challenge" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=info msg="authenticated AP" username="0v*********************pk" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=info msg="authenticated Login5" username="0v*********************pk" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=info msg="accepted zeroconf from DESKTOP-CSQ2T4P" username="0v*********************pk" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=debug msg="dealer connection opened" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=trace msg="starting accesspoint recv loop" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=trace msg="starting dealer recv loop" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=trace msg="received accesspoint ping" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=debug msg="received connection id: OTQzNWU5MjEtNTJm...Q0IwQjg3OTAyMw==" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=trace msg="received accesspoint pong ack" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=debug msg="handling transfer player command from f2e55318a1036d2dac5dadd0ec9eb02f96227535" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=debug msg="resolved context of track" uri="spotify:artist:7AC976RDJzL2asmZuz7qil" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=trace msg="fetched new page 0 with 38 items (list: 38)" uri="spotify:artist:7AC976RDJzL2asmZuz7qil" Feb 11 09:04:42 volumio go-librespot[1608]: time="2026-02-11T09:04:42+01:00" level=debug msg="loading track (paused: false, position: 237415ms)" uri="spotify:track:2zgRRcBuseLg2AJMPhvD7l" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=trace msg="emitting websocket event: will_play" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=debug msg="selected format OGG_VORBIS_320 (8ae435fd057597bdee63c49f4c1c0305c97cee2c)" uri="spotify:track:2zgRRcBuseLg2AJMPhvD7l" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=debug msg="requested aes key for file 8ae435fd057597bdee63c49f4c1c0305c97cee2c, gid: 2zgRRcBuseLg2AJMPhvD7l" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:2zgRRcBuseLg2AJMPhvD7l" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=debug msg="fetched first chunk of 17, total size is 8529266 bytes" uri="spotify:track:2zgRRcBuseLg2AJMPhvD7l" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=debug msg="fetched chunk 16/16, size: 140658" uri="spotify:track:2zgRRcBuseLg2AJMPhvD7l" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=trace msg="seek to 210118ms (diff: 281ms, samples: 9266203, bytes: 8517122)" uri="spotify:track:2zgRRcBuseLg2AJMPhvD7l" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=debug msg="created new output device" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=debug msg="fetched chunk 1/16, size: 524288" uri="spotify:track:2zgRRcBuseLg2AJMPhvD7l" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames, PCM format = FLOAT_LE" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=debug msg="fetched chunk 2/16, size: 524288" uri="spotify:track:2zgRRcBuseLg2AJMPhvD7l" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=info msg="loaded track \"Long Distance Runaround - 2024 Steven Wilson Remix\" (paused: false, position: 237415ms, duration: 210118ms, prefetched: false)" uri="spotify:track:2zgRRcBuseLg2AJMPhvD7l" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=debug msg="prefetching next track" uri="spotify:track:3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=trace msg="emitting websocket event: metadata" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=trace msg="emitting websocket event: active" Feb 11 09:04:43 volumio go-librespot[1608]: time="2026-02-11T09:04:43+01:00" level=debug msg="sending successful reply for dealer request" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=debug msg="fetched chunk 3/16, size: 524288" uri="spotify:track:2zgRRcBuseLg2AJMPhvD7l" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=debug msg="selected format OGG_VORBIS_320 (53292eb56cc44e384df0448e8e28536706df5eec)" uri="spotify:track:3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=debug msg="requested aes key for file 53292eb56cc44e384df0448e8e28536706df5eec, gid: 3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=trace msg="emitting websocket event: playing" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=trace msg="emitting websocket event: not_playing" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=trace msg="emitting websocket event: will_play" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=debug msg="selected format OGG_VORBIS_320 (53292eb56cc44e384df0448e8e28536706df5eec)" uri="spotify:track:3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=debug msg="requested aes key for file 53292eb56cc44e384df0448e8e28536706df5eec, gid: 3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=debug msg="fetched first chunk of 21, total size is 10747664 bytes" uri="spotify:track:3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=info msg="prefetched track \"Leave It\" (duration: 253800ms)" uri="spotify:track:3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=debug msg="fetched first chunk of 21, total size is 10747664 bytes" uri="spotify:track:3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames, PCM format = FLOAT_LE" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=info msg="loaded track \"Leave It\" (paused: false, position: 0ms, duration: 253800ms, prefetched: false)" uri="spotify:track:3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=trace msg="scheduling prefetch in 224s" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=trace msg="emitting websocket event: metadata" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=trace msg="emitting websocket event: playing" Feb 11 09:04:44 volumio go-librespot[1608]: time="2026-02-11T09:04:44+01:00" level=debug msg="fetched chunk 1/20, size: 524288" uri="spotify:track:3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:45 volumio go-librespot[1608]: time="2026-02-11T09:04:45+01:00" level=debug msg="fetched chunk 2/20, size: 524288" uri="spotify:track:3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:45 volumio go-librespot[1608]: time="2026-02-11T09:04:45+01:00" level=debug msg="fetched chunk 3/20, size: 524288" uri="spotify:track:3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:45 volumio go-librespot[1608]: time="2026-02-11T09:04:45+01:00" level=debug msg="fetched chunk 3/20, size: 524288" uri="spotify:track:3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:45 volumio go-librespot[1608]: time="2026-02-11T09:04:45+01:00" level=debug msg="fetched chunk 1/20, size: 524288" uri="spotify:track:3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:45 volumio go-librespot[1608]: time="2026-02-11T09:04:45+01:00" level=debug msg="fetched chunk 2/20, size: 524288" uri="spotify:track:3qSlbAE7VfK1AVyxfoHNJZ" Feb 11 09:04:46 volumio volumio[1327]: info: CoreCommandRouter::volumioGetState Feb 11 09:04:46 volumio volumio[1327]: info: CorePlayQueue::getTrack 0 Feb 11 09:04:47 volumio volumio[1327]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:artist:7AC976RDJzL2asmZuz7qil","uri":"spotify:track:2zgRRcBuseLg2AJMPhvD7l","play_origin":"artist"}} Feb 11 09:04:47 volumio volumio[1327]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2zgRRcBuseLg2AJMPhvD7l","name":"Long Distance Runaround - 2024 Steven Wilson Remix","artist_names":["Yes"],"album_name":"Fragile (Super Deluxe)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02fb00f7be0eca020bb5c05911","position":237415,"duration":210118,"release_date":"year:1971 month:11 day:12","track_number":6,"disc_number":2}} Feb 11 09:04:47 volumio volumio[1327]: SPOTIFY: received: {"type":"active","data":null} Feb 11 09:04:47 volumio volumio[1327]: info: Aligning Spotify Volume to Volumio Volume Feb 11 09:04:47 volumio volumio[1327]: info: CoreCommandRouter::volumioGetState Feb 11 09:04:47 volumio volumio[1327]: info: CorePlayQueue::getTrack 0 Feb 11 09:04:47 volumio volumio[1327]: info: Setting Spotify Volume from Volumio: 33 Feb 11 09:04:47 volumio volumio[1327]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:artist:7AC976RDJzL2asmZuz7qil","uri":"spotify:track:2zgRRcBuseLg2AJMPhvD7l","resume":false,"play_origin":"artist"}} Feb 11 09:04:47 volumio volumio[1327]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 09:04:47 volumio volumio[1327]: TypeError: Cannot read property 'service' of undefined Feb 11 09:04:47 volumio volumio[1327]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Feb 11 09:04:47 volumio volumio[1327]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:272:18) Feb 11 09:04:47 volumio volumio[1327]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Feb 11 09:04:47 volumio volumio[1327]: at WebSocket.emit (events.js:315:20) Feb 11 09:04:47 volumio volumio[1327]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Feb 11 09:04:47 volumio volumio[1327]: at Receiver.emit (events.js:315:20) Feb 11 09:04:47 volumio volumio[1327]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Feb 11 09:04:47 volumio volumio[1327]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Feb 11 09:04:47 volumio volumio[1327]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Feb 11 09:04:47 volumio volumio[1327]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Feb 11 09:04:47 volumio volumio[1327]: at writeOrBuffer (internal/streams/writable.js:358:12) Feb 11 09:04:47 volumio volumio[1327]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Feb 11 09:04:47 volumio volumio[1327]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Feb 11 09:04:47 volumio volumio[1327]: at Socket.emit (events.js:315:20) Feb 11 09:04:47 volumio volumio[1327]: at addChunk (internal/streams/readable.js:309:12) Feb 11 09:04:47 volumio volumio[1327]: at readableAddChunk (internal/streams/readable.js:284:9) Feb 11 09:04:47 volumio volumio[1327]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 11 09:04:48 volumio sudo[1705]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-02-11 09:03 Feb 11 09:04:48 volumio sudo[1705]: 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="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 05:43:24 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="15d0241b0cd805792809f3ddf4a0fc4e"