-- Logs begin at Thu 2019-02-14 10:11:59 UTC, end at Tue 2026-06-02 14:38:42 UTC. -- Jun 02 14:37:56 volumio ntpd[748]: receive: Unexpected origin timestamp 0xedb87cef.de9699f7 does not match aorg 0000000000.00000000 from server@213.239.234.28 xmt 0xedc96944.4bd3ece5 Jun 02 14:37:56 volumio ntpd[748]: receive: Unexpected origin timestamp 0xedb87cef.dea363b8 does not match aorg 0000000000.00000000 from server@37.221.199.157 xmt 0xedc96944.4c1425ea Jun 02 14:37:56 volumio ntpd[748]: receive: Unexpected origin timestamp 0xedb87cef.deab667f does not match aorg 0000000000.00000000 from server@5.45.97.204 xmt 0xedc96944.4c3f8d30 Jun 02 14:37:56 volumio ntpd[748]: receive: Unexpected origin timestamp 0xedb87cef.dea74fdb does not match aorg 0000000000.00000000 from server@178.63.52.31 xmt 0xedc96944.4c2aead5 Jun 02 14:37:56 volumio ntpd[748]: receive: Unexpected origin timestamp 0xedb87cef.deb7232d does not match aorg 0000000000.00000000 from server@212.18.3.19 xmt 0xedc96944.4c6a0a0c Jun 02 14:37:56 volumio ntpd[748]: receive: Unexpected origin timestamp 0xedb87cef.de9b1d34 does not match aorg 0000000000.00000000 from server@45.9.61.155 xmt 0xedc96944.4ba4bb90 Jun 02 14:37:56 volumio ntpd[748]: receive: Unexpected origin timestamp 0xedb87cef.de9f47c4 does not match aorg 0000000000.00000000 from server@85.215.159.215 xmt 0xedc96944.4ca41f43 Jun 02 14:37:56 volumio ntpd[748]: receive: Unexpected origin timestamp 0xedb87cef.deb3573e does not match aorg 0000000000.00000000 from server@217.160.19.219 xmt 0xedc96944.4cf7f88f Jun 02 14:37:56 volumio ntpd[748]: receive: Unexpected origin timestamp 0xedb87cef.de8a4680 does not match aorg 0000000000.00000000 from server@85.121.54.197 xmt 0xedc96944.4bcf005e Jun 02 14:37:56 volumio systemd[1]: Starting Daily apt download activities... Jun 02 14:37:58 volumio systemd[1]: apt-daily.service: Succeeded. Jun 02 14:37:58 volumio systemd[1]: Started Daily apt download activities. Jun 02 14:37:58 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Jun 02 14:37:59 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Jun 02 14:37:59 volumio systemd[1]: Started Daily apt upgrade and clean activities. Jun 02 14:38:00 volumio volumio[815]: info: ------------------------------------------- Jun 02 14:38:00 volumio volumio[815]: info: ----- Volumio3 ---- Jun 02 14:38:00 volumio volumio[815]: info: ------------------------------------------- Jun 02 14:38:00 volumio volumio[815]: info: ----- System startup ---- Jun 02 14:38:00 volumio volumio[815]: info: ------------------------------------------- Jun 02 14:38:02 volumio volumio[815]: info: MYVOLUMIO Environment detected Jun 02 14:38:02 volumio volumio[815]: info: Plugin folders cleanup Jun 02 14:38:02 volumio volumio[815]: info: Scanning into folder /volumio/app/plugins/ Jun 02 14:38:02 volumio volumio[815]: info: Scanning category audio_interface Jun 02 14:38:02 volumio volumio[815]: info: Scanning category miscellanea Jun 02 14:38:02 volumio volumio[815]: info: Scanning category music_service Jun 02 14:38:02 volumio volumio[815]: info: Scanning category plugins.json Jun 02 14:38:02 volumio volumio[815]: info: Scanning category system_controller Jun 02 14:38:02 volumio volumio[815]: info: Scanning category user_interface Jun 02 14:38:02 volumio volumio[815]: info: Scanning into folder /data/plugins/ Jun 02 14:38:02 volumio volumio[815]: info: Scanning category music_service Jun 02 14:38:03 volumio volumio[815]: info: Plugin folders cleanup completed Jun 02 14:38:03 volumio volumio[815]: info: ------------------------------------------- Jun 02 14:38:03 volumio volumio[815]: info: ----- Core plugins startup ---- Jun 02 14:38:03 volumio volumio[815]: info: ------------------------------------------- Jun 02 14:38:03 volumio volumio[815]: info: Loading plugins from folder /volumio/app/plugins/ Jun 02 14:38:03 volumio volumio[815]: info: Adding plugin upnp to MyMusic Plugins Jun 02 14:38:03 volumio volumio[815]: info: Adding plugin airplay_emulation to MyMusic Plugins Jun 02 14:38:03 volumio volumio[815]: info: Adding plugin upnp_browser to MyMusic Plugins Jun 02 14:38:03 volumio volumio[815]: info: Loading plugins from folder /data/plugins/ Jun 02 14:38:03 volumio volumio[815]: info: Loading plugin "system"... Jun 02 14:38:03 volumio volumio[815]: info: Loading plugin "appearance"... Jun 02 14:38:04 volumio volumio-remote-updater[525]: [2026-06-02 14:38:04] [connect] Successful connection Jun 02 14:38:05 volumio systemd[1]: systemd-fsckd.service: Succeeded. Jun 02 14:38:05 volumio volumio[815]: info: Loading plugin "network"... Jun 02 14:38:06 volumio volumio[815]: info: Refreshing Cached IP Addresses Jun 02 14:38:06 volumio sudo[934]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 02 14:38:06 volumio volumio[815]: info: Loading plugin "services"... Jun 02 14:38:06 volumio sudo[934]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:06 volumio volumio[815]: info: Loading plugin "alsa_controller"... Jun 02 14:38:06 volumio sudo[934]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:06 volumio sudo[936]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 02 14:38:06 volumio sudo[936]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:06 volumio sudo[936]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:06 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 02 14:38:06 volumio volumio[815]: info: Loading plugin "wizard"... Jun 02 14:38:06 volumio volumio[815]: info: Loading plugin "volumio_command_line_client"... Jun 02 14:38:06 volumio volumio[815]: info: Loading plugin "upnp"... Jun 02 14:38:06 volumio volumio[815]: info: [1780411086297] Starting Upmpd Daemon Jun 02 14:38:06 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 02 14:38:06 volumio volumio[815]: info: Loading plugin "my_music"... Jun 02 14:38:06 volumio volumio[815]: info: Loading plugin "mpd"... Jun 02 14:38:07 volumio volumio[815]: info: Creating MPD Configuration file Jun 02 14:38:07 volumio volumio[815]: info: Loading plugin "upnp_browser"... Jun 02 14:38:07 volumio sudo[942]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 02 14:38:07 volumio sudo[942]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:07 volumio sudo[942]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:07 volumio sudo[944]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 02 14:38:07 volumio sudo[944]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:07 volumio systemd[1]: Stopping Music Player Daemon... Jun 02 14:38:07 volumio systemd[1]: mpd.service: Succeeded. Jun 02 14:38:07 volumio systemd[1]: Stopped Music Player Daemon. Jun 02 14:38:07 volumio systemd[1]: Starting Music Player Daemon... Jun 02 14:38:08 volumio volumio[815]: info: Loading plugin "networkfs"... Jun 02 14:38:10 volumio mpd[949]: Jun 02 14:38 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 02 14:38:10 volumio volumio[815]: info: Starting Udev Watcher for removable devices Jun 02 14:38:10 volumio sudo[952]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Musik,password=Musik01,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,noserverino //192.168.178.1/FRITZ.NAS/Musik_1/Musik /mnt/NAS/My_Musik Jun 02 14:38:10 volumio sudo[952]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:10 volumio kernel: FS-Cache: Netfs 'cifs' registered for caching Jun 02 14:38:10 volumio kernel: Key type cifs.spnego registered Jun 02 14:38:10 volumio kernel: Key type cifs.idmap registered Jun 02 14:38:10 volumio kernel: CIFS: Attempting to mount //192.168.178.1/FRITZ.NAS/Musik_1/Musik Jun 02 14:38:10 volumio kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Jun 02 14:38:11 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -2 Jun 02 14:38:11 volumio sudo[952]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:11 volumio volumio[815]: info: Ignoring mount for partition: boot Jun 02 14:38:11 volumio volumio[815]: info: Ignoring mount for partition: volumio Jun 02 14:38:11 volumio volumio[815]: info: Ignoring mount for partition: volumio_data Jun 02 14:38:11 volumio mpd[949]: Jun 02 14:38 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Jun 02 14:38:11 volumio mpd[949]: Jun 02 14:38 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Jun 02 14:38:11 volumio systemd[1]: Started Music Player Daemon. Jun 02 14:38:11 volumio sudo[944]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:11 volumio volumio[815]: info: Mounting Device 605B-14FB Jun 02 14:38:11 volumio sudo[985]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/605B-14FB -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Jun 02 14:38:11 volumio sudo[985]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:11 volumio kernel: FAT-fs (sda1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! Jun 02 14:38:11 volumio kernel: FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Jun 02 14:38:11 volumio sudo[985]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:11 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 02 14:38:11 volumio volumio[815]: info: Loading plugin "alarm-clock"... Jun 02 14:38:12 volumio volumio[815]: info: Loading plugin "airplay_emulation"... Jun 02 14:38:12 volumio volumio[815]: info: Starting Shairport Sync Jun 02 14:38:12 volumio volumio[815]: info: Loading plugin "last_100"... Jun 02 14:38:12 volumio volumio[815]: info: Loading plugin "webradio"... Jun 02 14:38:12 volumio volumio[815]: info: Loading plugin "i2s_dacs"... Jun 02 14:38:12 volumio volumio[815]: info: Loading plugin "volumiodiscovery"... Jun 02 14:38:12 volumio volumio[815]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 02 14:38:12 volumio volumio[815]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 02 14:38:12 volumio volumio[815]: *** WARNING *** For more information see Jun 02 14:38:12 volumio node[815]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 02 14:38:12 volumio volumio[815]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 02 14:38:12 volumio volumio[815]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 02 14:38:12 volumio volumio[815]: *** WARNING *** For more information see Jun 02 14:38:12 volumio node[815]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 02 14:38:12 volumio node[815]: *** WARNING *** For more information see Jun 02 14:38:12 volumio node[815]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 02 14:38:12 volumio node[815]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 02 14:38:12 volumio node[815]: *** WARNING *** For more information see Jun 02 14:38:12 volumio volumio[815]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 02 14:38:12 volumio volumio[815]: info: Discovery: Started advertising with name: Volumio Jun 02 14:38:12 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 02 14:38:12 volumio volumio[815]: info: Loading plugin "spop"... Jun 02 14:38:15 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Jun 02 14:38:16 volumio volumio[815]: info: Loading plugin "outputs"... Jun 02 14:38:16 volumio volumio[815]: info: Loading plugin "albumart"... Jun 02 14:38:16 volumio volumio[815]: info: Plugin example_plugin is not enabled Jun 02 14:38:16 volumio volumio[815]: info: Loading plugin "inputs"... Jun 02 14:38:16 volumio volumio[815]: info: Loading plugin "updater_comm"... Jun 02 14:38:16 volumio volumio[815]: info: Plugin mpdemulation is not enabled Jun 02 14:38:16 volumio volumio[815]: info: Loading plugin "rest_api"... Jun 02 14:38:16 volumio volumio[815]: info: Loading plugin "websocket"... Jun 02 14:38:16 volumio volumio[815]: info: Loading plugin "radio_paradise"... Jun 02 14:38:16 volumio volumio[815]: Forking 3 albumart workers Jun 02 14:38:17 volumio volumio[815]: info: Applying required configuration parameters for plugin radio_paradise Jun 02 14:38:17 volumio volumio[815]: info: [1780411097380] [RadioParadise] API delay: 5 Jun 02 14:38:17 volumio volumio[815]: info: Loading i18n strings for locale de Jun 02 14:38:17 volumio volumio[815]: Updating browse sources language Jun 02 14:38:17 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 02 14:38:18 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 02 14:38:18 volumio volumio[815]: info: CoreCommandRouter::initPlayerControls Jun 02 14:38:18 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:18 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:18 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:18 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:18 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:18 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:18 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:18 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:18 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 02 14:38:18 volumio volumio[815]: Express server listening on port 3000 Jun 02 14:38:18 volumio volumio[815]: [Metrics] WebUI: 20s 182.14ms Jun 02 14:38:18 volumio volumio[815]: info: CoreStateMachine::resetVolumioState Jun 02 14:38:18 volumio volumio[815]: info: CoreStateMachine::getcurrentVolume Jun 02 14:38:18 volumio volumio[815]: info: CoreCommandRouter::volumioRetrievevolume Jun 02 14:38:18 volumio volumio[815]: info: CoreStateMachine::pushState Jun 02 14:38:18 volumio volumio[815]: info: CorePlayQueue::getTrack 0 Jun 02 14:38:18 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 02 14:38:18 volumio volumio[815]: info: CoreCommandRouter::volumioPushState Jun 02 14:38:18 volumio sudo[1025]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 02 14:38:18 volumio sudo[1025]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:18 volumio sudo[1025]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:18 volumio sudo[1026]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 02 14:38:18 volumio sudo[1026]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:18 volumio volumio[815]: info: Cannot mount NAS My_Musik at system boot, trial number 1 ,retrying in 5 seconds Jun 02 14:38:18 volumio sudo[1026]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:18 volumio volumio[815]: info: MPD Permissions set Jun 02 14:38:18 volumio volumio[815]: Starting albumart workers Jun 02 14:38:18 volumio volumio[815]: Starting albumart workers Jun 02 14:38:18 volumio volumio[815]: Starting albumart workers Jun 02 14:38:19 volumio volumio[815]: info: MPD running with PID949 Jun 02 14:38:19 volumio volumio[815]: ,establishing connection Jun 02 14:38:19 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:19 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:19 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:19 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:19 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:19 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:19 volumio volumio-remote-updater[525]: [2026-06-02 14:38:19] [connect] Successful connection Jun 02 14:38:19 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:19 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:19 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 02 14:38:19 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:19 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 02 14:38:19 volumio volumio[815]: info: Reloading queue from file Jun 02 14:38:19 volumio volumio[815]: error: updateQueue error: null Jun 02 14:38:19 volumio volumio[815]: info: CoreStateMachine::setRepeat null single undefined Jun 02 14:38:19 volumio volumio[815]: info: CoreStateMachine::pushState Jun 02 14:38:19 volumio volumio[815]: info: CorePlayQueue::getTrack 0 Jun 02 14:38:19 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 02 14:38:19 volumio volumio[815]: info: CoreCommandRouter::volumioPushState Jun 02 14:38:19 volumio volumio[815]: info: CoreStateMachine::setRandom null Jun 02 14:38:19 volumio volumio[815]: info: CoreStateMachine::pushState Jun 02 14:38:19 volumio volumio[815]: info: CorePlayQueue::getTrack 0 Jun 02 14:38:19 volumio volumio[815]: info: CoreCommandRouter::volumioPushState Jun 02 14:38:19 volumio volumio[815]: info: Setting Device type: Raspberry PI Jun 02 14:38:19 volumio volumio[815]: info: Completed loading Core Plugins Jun 02 14:38:19 volumio volumio[815]: info: Preparing to generate the ALSA configuration file Jun 02 14:38:19 volumio volumio[815]: error: updateQueue error: null Jun 02 14:38:19 volumio volumio-remote-updater[525]: [2026-06-02 14:38:19] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1780411099 101 Jun 02 14:38:19 volumio volumio[815]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 1 Jun 02 14:38:19 volumio volumio[815]: info: Asound.conf file written Jun 02 14:38:20 volumio sudo[1061]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 02 14:38:20 volumio sudo[1061]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:20 volumio sudo[1064]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jun 02 14:38:20 volumio sudo[1064]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:20 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Jun 02 14:38:20 volumio sudo[1061]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:20 volumio sudo[1064]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:20 volumio volumio[815]: info: Output device has changed, restarting MPD Jun 02 14:38:20 volumio volumio[815]: info: Output device has changed, restarting Shairport Sync Jun 02 14:38:20 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:20 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 02 14:38:20 volumio sudo[1074]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 02 14:38:20 volumio sudo[1074]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:20 volumio sudo[1074]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:20 volumio sudo[1076]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 02 14:38:20 volumio sudo[1076]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:20 volumio systemd[1]: Stopping Music Player Daemon... Jun 02 14:38:20 volumio volumio[815]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 02 14:38:20 volumio volumio[815]: info: ___________ START PLUGINS ___________ Jun 02 14:38:20 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 02 14:38:20 volumio volumio[815]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 02 14:38:20 volumio volumio[815]: info: [1780411100437] CoreMusicLibrary::Adding element Media Servers Jun 02 14:38:20 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 02 14:38:20 volumio systemd[1]: mpd.service: Succeeded. Jun 02 14:38:20 volumio systemd[1]: Stopped Music Player Daemon. Jun 02 14:38:20 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:20 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 02 14:38:20 volumio systemd[1]: Starting Music Player Daemon... Jun 02 14:38:20 volumio volumio[815]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 02 14:38:20 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:20 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 02 14:38:20 volumio volumio[815]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 02 14:38:20 volumio volumio[815]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 02 14:38:20 volumio volumio[815]: info: [1780411100710] CoreMusicLibrary::Adding element Last_100 Jun 02 14:38:20 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 02 14:38:20 volumio volumio[815]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 02 14:38:20 volumio volumio[815]: info: [1780411100717] CoreMusicLibrary::Adding element Webradio Jun 02 14:38:20 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 02 14:38:20 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 02 14:38:20 volumio volumio[815]: info: Creating Spotify config file Jun 02 14:38:20 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:21 volumio volumio[815]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 02 14:38:21 volumio volumio[815]: info: [1780411101030] CoreMusicLibrary::Adding element Radio Paradise Jun 02 14:38:21 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 02 14:38:21 volumio volumio[815]: Cannot find translation for source Radio Paradise Jun 02 14:38:21 volumio volumio[815]: info: Volumio Calling Home Jun 02 14:38:21 volumio volumio[815]: info: Completed starting Core Plugins Jun 02 14:38:21 volumio volumio[815]: info: ------------------------------------------- Jun 02 14:38:21 volumio volumio[815]: info: ----- MyVolumio plugins startup ---- Jun 02 14:38:21 volumio volumio[815]: info: ------------------------------------------- Jun 02 14:38:21 volumio volumio[815]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 02 14:38:21 volumio volumio[815]: info: Discovery: adding 7e859f47-8bf1-47ba-8f01-380cc0815b56 Jun 02 14:38:21 volumio volumio[815]: info: Discovery: Found device Volumio Jun 02 14:38:21 volumio volumio[815]: info: CoreCommandRouter::volumioGetState Jun 02 14:38:21 volumio volumio[815]: info: CorePlayQueue::getTrack 0 Jun 02 14:38:21 volumio volumio[815]: info: MPD Permissions set Jun 02 14:38:21 volumio volumio[815]: info: Upmpdcli Daemon Started Jun 02 14:38:21 volumio volumio[815]: info: Spotify config file written Jun 02 14:38:21 volumio sudo[1095]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jun 02 14:38:21 volumio sudo[1095]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:21 volumio volumio[815]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Jun 02 14:38:21 volumio volumio[815]: info: Volumio called home Jun 02 14:38:21 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:21 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:21 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:21 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:21 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:21 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:21 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:21 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:21 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 02 14:38:21 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 02 14:38:21 volumio volumio[815]: info: No need to fix Spotify hosts Jun 02 14:38:21 volumio systemd[1]: Started go-librespot Daemon. Jun 02 14:38:21 volumio sudo[1095]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:21 volumio volumio[815]: info: Starting Shairport Sync Jun 02 14:38:21 volumio volumio[815]: info: Starting Shairport Sync Jun 02 14:38:21 volumio go-librespot[1101]: go-librespot daemon starting... Jun 02 14:38:21 volumio volumio[815]: info: Starting Shairport Sync Jun 02 14:38:21 volumio sudo[1103]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 02 14:38:21 volumio sudo[1103]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:22 volumio sudo[1106]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 02 14:38:22 volumio sudo[1106]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:22 volumio sudo[1109]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 02 14:38:22 volumio sudo[1109]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:22 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 02 14:38:22 volumio systemd[1]: shairport-sync.service: Succeeded. Jun 02 14:38:22 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 02 14:38:22 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 02 14:38:22 volumio sudo[1103]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:22 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 02 14:38:22 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Jun 02 14:38:22 volumio systemd[1]: shairport-sync.service: Succeeded. Jun 02 14:38:22 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 02 14:38:22 volumio sudo[1106]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:22 volumio volumio[815]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 02 14:38:22 volumio volumio[815]: SPOTIFY: BQBgZNd2CXhN7RfzFPk3DD2Wo0Dx7cJilUtXNhx3PQuBy_HWz1HYMrCzQqwlxMuVWpWQVmIcGZ3ZpB-Vpejr58fQswb6yUV1gol_e3b7hNWgfyPZBNxiWIkjgZOFCxMscunqvDWxOnJ7oiP1qKyRsKnHCpbJBzho1oun4Z8Njh4fFL6mt53nOiVV1v9p283pH4yxxxVnvVkQILIF-tREXtUcGKVxoyZMVPLIOu9wMOcygI5jV_b5nf-f1j6o4ngKQKAcMR66Qg2p4cfZY6IK80iR3xSJ_sCo6S5XHxe7CXWSINOaC75d6kaAWg Jun 02 14:38:22 volumio volumio[815]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 02 14:38:22 volumio volumio[815]: info: New Spotify access token = BQBgZNd2CXhN7RfzFPk3DD2Wo0Dx7cJilUtXNhx3PQuBy_HWz1HYMrCzQqwlxMuVWpWQVmIcGZ3ZpB-Vpejr58fQswb6yUV1gol_e3b7hNWgfyPZBNxiWIkjgZOFCxMscunqvDWxOnJ7oiP1qKyRsKnHCpbJBzho1oun4Z8Njh4fFL6mt53nOiVV1v9p283pH4yxxxVnvVkQILIF-tREXtUcGKVxoyZMVPLIOu9wMOcygI5jV_b5nf-f1j6o4ngKQKAcMR66Qg2p4cfZY6IK80iR3xSJ_sCo6S5XHxe7CXWSINOaC75d6kaAWg Jun 02 14:38:22 volumio volumio[815]: info: Spotify credentials grant success - running version from March 24, 2019 Jun 02 14:38:22 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 02 14:38:22 volumio sudo[1109]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:22 volumio volumio[815]: info: Shairport-Sync Started Jun 02 14:38:22 volumio volumio[815]: Error adding Membership: Error: addMembership EINVAL Jun 02 14:38:22 volumio volumio[815]: info: Shairport-Sync Started Jun 02 14:38:22 volumio volumio[815]: info: Shairport-Sync Started Jun 02 14:38:22 volumio volumio[815]: info: CoreCommandRouter::volumioGetState Jun 02 14:38:22 volumio volumio[815]: info: CorePlayQueue::getTrack 0 Jun 02 14:38:22 volumio volumio[815]: SPOTIFY: User informations: {"account_id":"ICeW56xnUf","country":"DE","display_name":"Dirk","email":"beba-kreutzwald@t-online.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/ivuif1awll5aodfnpy13z3756"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/ivuif1awll5aodfnpy13z3756","id":"ivuif1awll5aodfnpy13z3756","images":[],"product":"premium","type":"user","uri":"spotify:user:ivuif1awll5aodfnpy13z3756"} Jun 02 14:38:22 volumio volumio[815]: info: Spotify Successfully logged in Jun 02 14:38:22 volumio volumio[815]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 02 14:38:22 volumio volumio[815]: info: [1780411102640] CoreMusicLibrary::Adding element Spotify Jun 02 14:38:22 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 02 14:38:22 volumio volumio[815]: Cannot find translation for source Radio Paradise Jun 02 14:38:22 volumio volumio[815]: Cannot find translation for source Spotify Jun 02 14:38:22 volumio go-librespot[1101]: time="2026-06-02T14:38:22Z" level=info msg="running go-librespot 0.4.0" Jun 02 14:38:22 volumio go-librespot[1101]: time="2026-06-02T14:38:22Z" level=debug msg="app state loaded" Jun 02 14:38:22 volumio go-librespot[1101]: time="2026-06-02T14:38:22Z" level=info msg="api server listening on 127.0.0.1:9879" Jun 02 14:38:23 volumio mpd[1090]: Jun 02 14:38 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 02 14:38:23 volumio go-librespot[1101]: time="2026-06-02T14:38:23Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jun 02 14:38:23 volumio go-librespot[1101]: time="2026-06-02T14:38:23Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jun 02 14:38:23 volumio go-librespot[1101]: time="2026-06-02T14:38:23Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jun 02 14:38:23 volumio go-librespot[1101]: time="2026-06-02T14:38:23Z" level=info msg="zeroconf server listening on port 45577" Jun 02 14:38:23 volumio sudo[1123]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Musik,password=Musik01,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,noserverino //192.168.178.1/FRITZ.NAS/Musik_1/Musik /mnt/NAS/My_Musik Jun 02 14:38:23 volumio sudo[1123]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:23 volumio kernel: CIFS: Attempting to mount //192.168.178.1/FRITZ.NAS/Musik_1/Musik Jun 02 14:38:23 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -2 Jun 02 14:38:23 volumio sudo[1123]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:23 volumio go-librespot[1101]: time="2026-06-02T14:38:23Z" level=debug msg="obtained new client token: AACpfnCLpeCprraXzlrtTvGYqI7qI7vlERPCSLSUZM8QhMHlpFFVssMmGA+YrkvvAsdw30tzV7ZzoC32RnOwV0xD+q+ZmgyIv7+1ay09YCOICTLMybAQJpPEq5QODkxyYT5q5cKzTcIN+zkv95skQ8oSwRX+Djx8tPwUwW5XQRFk+pa2cb0/iP3QimQNthMgN+OBZopjMDI9oiBbuI14HyN4upsZOh7rHx+t84MgcQi2MyXvbCFpKa2y" Jun 02 14:38:23 volumio volumio[815]: info: Cannot mount NAS My_Musik at system boot, trial number 2 ,retrying in 5 seconds Jun 02 14:38:23 volumio go-librespot[1101]: time="2026-06-02T14:38:23Z" level=debug msg="connected to ap-gew4.spotify.com:4070" Jun 02 14:38:23 volumio go-librespot[1101]: time="2026-06-02T14:38:23Z" level=debug msg="completed keyexchange" Jun 02 14:38:23 volumio go-librespot[1101]: time="2026-06-02T14:38:23Z" level=debug msg="completed challenge" Jun 02 14:38:23 volumio go-librespot[1101]: time="2026-06-02T14:38:23Z" level=info msg="authenticated AP" username="iv*********************56" Jun 02 14:38:24 volumio go-librespot[1101]: time="2026-06-02T14:38:24Z" level=info msg="authenticated Login5" username="iv*********************56" Jun 02 14:38:24 volumio go-librespot[1101]: time="2026-06-02T14:38:24Z" level=debug msg="initializing zeroconf session" username="iv*********************56" Jun 02 14:38:24 volumio mpd[1090]: Jun 02 14:38 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Jun 02 14:38:24 volumio mpd[1090]: Jun 02 14:38 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Jun 02 14:38:24 volumio systemd[1]: Started Music Player Daemon. Jun 02 14:38:24 volumio volumio[815]: Upnp client error: Error: This socket has been ended by the other party Jun 02 14:38:24 volumio sudo[1076]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:24 volumio go-librespot[1101]: time="2026-06-02T14:38:24Z" level=debug msg="dealer connection opened" Jun 02 14:38:24 volumio go-librespot[1101]: time="2026-06-02T14:38:24Z" level=trace msg="starting accesspoint recv loop" Jun 02 14:38:24 volumio go-librespot[1101]: time="2026-06-02T14:38:24Z" level=trace msg="starting dealer recv loop" Jun 02 14:38:24 volumio go-librespot[1101]: time="2026-06-02T14:38:24Z" level=trace msg="received accesspoint ping" Jun 02 14:38:24 volumio go-librespot[1101]: time="2026-06-02T14:38:24Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jun 02 14:38:24 volumio go-librespot[1101]: time="2026-06-02T14:38:24Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jun 02 14:38:24 volumio go-librespot[1101]: time="2026-06-02T14:38:24Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jun 02 14:38:24 volumio go-librespot[1101]: time="2026-06-02T14:38:24Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jun 02 14:38:24 volumio go-librespot[1101]: time="2026-06-02T14:38:24Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jun 02 14:38:24 volumio volumio[815]: error: updateQueue error: null Jun 02 14:38:24 volumio go-librespot[1101]: time="2026-06-02T14:38:24Z" level=debug msg="received connection id: YWM2NDllZmUtZjUx...NDQwN0Q1OUY3Qg==" Jun 02 14:38:24 volumio go-librespot[1101]: time="2026-06-02T14:38:24Z" level=trace msg="received accesspoint pong ack" Jun 02 14:38:24 volumio go-librespot[1101]: time="2026-06-02T14:38:24Z" level=debug msg="put connect state because NEW_DEVICE" Jun 02 14:38:24 volumio go-librespot[1101]: time="2026-06-02T14:38:24Z" level=debug msg="update volume requested to 65535/65535" Jun 02 14:38:24 volumio go-librespot[1101]: time="2026-06-02T14:38:24Z" level=debug msg="put connect state because VOLUME_CHANGED" Jun 02 14:38:24 volumio go-librespot[1101]: time="2026-06-02T14:38:24Z" level=trace msg="emitting websocket event: volume" Jun 02 14:38:24 volumio volumio[1070]: Generating RSA private key, 4096 bit long modulus (2 primes) Jun 02 14:38:24 volumio volumio[815]: info: go-librespot daemon successfully initialized Jun 02 14:38:27 volumio volumio[815]: info: Initializing connection to go-librespot Websocket Jun 02 14:38:28 volumio go-librespot[1101]: time="2026-06-02T14:38:28Z" level=debug msg="new websocket client" Jun 02 14:38:28 volumio volumio[815]: info: Connection to go-librespot Websocket established Jun 02 14:38:28 volumio sudo[1146]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Musik,password=Musik01,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,noserverino //192.168.178.1/FRITZ.NAS/Musik_1/Musik /mnt/NAS/My_Musik Jun 02 14:38:28 volumio sudo[1146]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:28 volumio kernel: CIFS: Attempting to mount //192.168.178.1/FRITZ.NAS/Musik_1/Musik Jun 02 14:38:28 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -2 Jun 02 14:38:28 volumio sudo[1146]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:29 volumio volumio[815]: info: Cannot mount NAS My_Musik at system boot, trial number 3 ,retrying in 5 seconds Jun 02 14:38:34 volumio volumio[815]: info: Getting Spotify volume Jun 02 14:38:34 volumio sudo[1152]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Musik,password=Musik01,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft,noserverino //192.168.178.1/FRITZ.NAS/Musik_1/Musik /mnt/NAS/My_Musik Jun 02 14:38:34 volumio sudo[1152]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:34 volumio volumio[815]: info: Spotify volume: 100 Jun 02 14:38:34 volumio kernel: CIFS: Attempting to mount //192.168.178.1/FRITZ.NAS/Musik_1/Musik Jun 02 14:38:34 volumio volumio[815]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Jun 02 14:38:34 volumio sudo[1152]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:34 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -2 Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jun 02 14:38:35 volumio volumio[815]: info: Adding plugin bluetooth to MyMusic Plugins Jun 02 14:38:35 volumio volumio[815]: info: Adding plugin multiroom to MyMusic Plugins Jun 02 14:38:35 volumio volumio[815]: info: Adding plugin metavolumio to MyMusic Plugins Jun 02 14:38:35 volumio volumio[815]: info: Adding plugin cd_controller to MyMusic Plugins Jun 02 14:38:35 volumio volumio[815]: info: Adding plugin smart_inputs to MyMusic Plugins Jun 02 14:38:35 volumio volumio[815]: info: Adding plugin tidalconnect to MyMusic Plugins Jun 02 14:38:35 volumio volumio[815]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jun 02 14:38:36 volumio go-librespot[1101]: time="2026-06-02T14:38:36Z" level=debug msg="handling transfer player command from 28df0cca8091d7437a3e945ed3183d8776bd82e8" Jun 02 14:38:36 volumio go-librespot[1101]: time="2026-06-02T14:38:36Z" level=debug msg="resolved context of track" uri="spotify:track:38qLvs3obCzzePUxYLtAG7" Jun 02 14:38:36 volumio go-librespot[1101]: time="2026-06-02T14:38:36Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:38qLvs3obCzzePUxYLtAG7" Jun 02 14:38:36 volumio go-librespot[1101]: time="2026-06-02T14:38:36Z" level=debug msg="shuffled context with seed 16508680212539625006 (len: 1, keep: -1)" uri="spotify:track:38qLvs3obCzzePUxYLtAG7" Jun 02 14:38:36 volumio go-librespot[1101]: time="2026-06-02T14:38:36Z" level=debug msg="loading track (paused: true, position: 3205ms)" uri="spotify:track:38qLvs3obCzzePUxYLtAG7" Jun 02 14:38:36 volumio go-librespot[1101]: time="2026-06-02T14:38:36Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 02 14:38:36 volumio go-librespot[1101]: time="2026-06-02T14:38:36Z" level=trace msg="emitting websocket event: will_play" Jun 02 14:38:36 volumio go-librespot[1101]: time="2026-06-02T14:38:36Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Jun 02 14:38:36 volumio go-librespot[1101]: time="2026-06-02T14:38:36Z" level=debug msg="selected format OGG_VORBIS_320 (d43ce9b376d0317cc6ad2b25f845782643c53775)" uri="spotify:track:38qLvs3obCzzePUxYLtAG7" Jun 02 14:38:36 volumio go-librespot[1101]: time="2026-06-02T14:38:36Z" level=debug msg="requested aes key for file d43ce9b376d0317cc6ad2b25f845782643c53775, gid: 38qLvs3obCzzePUxYLtAG7" Jun 02 14:38:36 volumio go-librespot[1101]: time="2026-06-02T14:38:36Z" level=trace msg="found 2 cdn urls" uri="spotify:track:38qLvs3obCzzePUxYLtAG7" Jun 02 14:38:36 volumio go-librespot[1101]: time="2026-06-02T14:38:36Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 159" Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1474" Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=debug msg="fetched first chunk of 9, total size is 4314636 bytes" uri="spotify:track:38qLvs3obCzzePUxYLtAG7" Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=trace msg="seek to 3205ms (diff: 98ms, samples: 141340, bytes: 90792)" uri="spotify:track:38qLvs3obCzzePUxYLtAG7" Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=debug msg="created new output device" Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=info msg="loaded track \"Istanbul (Not Constantinople)\" (paused: true, position: 3205ms, duration: 139933ms, prefetched: false)" uri="spotify:track:38qLvs3obCzzePUxYLtAG7" Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=trace msg="emitting websocket event: metadata" Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=trace msg="emitting websocket event: active" Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=debug msg="sending successful reply for dealer request" Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=debug msg="skipping dealer message" uri=playback-settings/content-settings-update Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1239" Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=trace msg="emitting websocket event: paused" Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=debug msg="fetched chunk 3/8, size: 524288" uri="spotify:track:38qLvs3obCzzePUxYLtAG7" Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=debug msg="fetched chunk 1/8, size: 524288" uri="spotify:track:38qLvs3obCzzePUxYLtAG7" Jun 02 14:38:37 volumio volumio[815]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jun 02 14:38:37 volumio volumio[815]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jun 02 14:38:37 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 02 14:38:37 volumio volumio[815]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 02 14:38:37 volumio volumio[815]: info: Starting MyVolumio Remote Streaming Endpoints Jun 02 14:38:37 volumio volumio[815]: info: MyVolumio login type: Token Jun 02 14:38:37 volumio volumio[815]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jun 02 14:38:37 volumio go-librespot[1101]: time="2026-06-02T14:38:37Z" level=debug msg="fetched chunk 2/8, size: 524288" uri="spotify:track:38qLvs3obCzzePUxYLtAG7" Jun 02 14:38:37 volumio volumio[815]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jun 02 14:38:38 volumio go-librespot[1101]: time="2026-06-02T14:38:38Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Jun 02 14:38:38 volumio go-librespot[1101]: time="2026-06-02T14:38:38Z" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DX3ZMXhRgB4QO" Jun 02 14:38:38 volumio go-librespot[1101]: time="2026-06-02T14:38:38Z" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DWUvquQVFIiVB" Jun 02 14:38:38 volumio go-librespot[1101]: time="2026-06-02T14:38:38Z" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DX1BplP07YAuF" Jun 02 14:38:38 volumio go-librespot[1101]: time="2026-06-02T14:38:38Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Jun 02 14:38:38 volumio go-librespot[1101]: time="2026-06-02T14:38:38Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Jun 02 14:38:38 volumio go-librespot[1101]: time="2026-06-02T14:38:38Z" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DX6uHioFvkN7A" Jun 02 14:38:38 volumio go-librespot[1101]: time="2026-06-02T14:38:38Z" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DX2M1RktxUUHG" Jun 02 14:38:38 volumio go-librespot[1101]: time="2026-06-02T14:38:38Z" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DWYJeWl6ior4d" Jun 02 14:38:38 volumio go-librespot[1101]: time="2026-06-02T14:38:38Z" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DX4pUKG1kS0Ac" Jun 02 14:38:38 volumio go-librespot[1101]: time="2026-06-02T14:38:38Z" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DWThZJsiJrkYw" Jun 02 14:38:38 volumio go-librespot[1101]: time="2026-06-02T14:38:38Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Jun 02 14:38:38 volumio go-librespot[1101]: time="2026-06-02T14:38:38Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Jun 02 14:38:38 volumio go-librespot[1101]: time="2026-06-02T14:38:38Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Jun 02 14:38:38 volumio go-librespot[1101]: time="2026-06-02T14:38:38Z" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DX2cNqJ4LgCMf" Jun 02 14:38:39 volumio volumio[1070]: ...................................................++++ Jun 02 14:38:40 volumio volumio[815]: info: Starting Streaming Service Transparent Proxy Jun 02 14:38:40 volumio volumio[815]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jun 02 14:38:40 volumio volumio[815]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jun 02 14:38:40 volumio volumio[815]: info: Streaming services startup Jun 02 14:38:40 volumio volumio[815]: info: Starting Streaming Daemon Jun 02 14:38:40 volumio sudo[1165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 02 14:38:40 volumio sudo[1165]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 02 14:38:40 volumio volumio[815]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jun 02 14:38:40 volumio sudo[1165]: pam_unix(sudo:session): session closed for user root Jun 02 14:38:40 volumio volumio[815]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:38qLvs3obCzzePUxYLtAG7","uri":"spotify:track:38qLvs3obCzzePUxYLtAG7","play_origin":"search"}} Jun 02 14:38:40 volumio volumio[815]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:38qLvs3obCzzePUxYLtAG7","name":"Istanbul (Not Constantinople)","artist_names":["The Four Lads"],"album_name":"16 Most Requested Songs","album_cover_url":"https://i.scdn.co/image/ab67616d00001e021ec7bbe2cb842457a3fc1b2f","position":3205,"duration":139933,"release_date":"year:1953","track_number":10,"disc_number":1}} Jun 02 14:38:40 volumio volumio[815]: SPOTIFY: received: {"type":"active","data":null} Jun 02 14:38:40 volumio volumio[815]: info: Aligning Spotify Volume to Volumio Volume Jun 02 14:38:40 volumio volumio[815]: info: CoreCommandRouter::volumioGetState Jun 02 14:38:40 volumio volumio[815]: info: CorePlayQueue::getTrack 0 Jun 02 14:38:40 volumio volumio[815]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:38qLvs3obCzzePUxYLtAG7","uri":"spotify:track:38qLvs3obCzzePUxYLtAG7","play_origin":"search"}} Jun 02 14:38:40 volumio volumio[815]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 02 14:38:40 volumio volumio[815]: TypeError: Cannot read property 'service' of undefined Jun 02 14:38:40 volumio volumio[815]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:346:50) Jun 02 14:38:40 volumio volumio[815]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:280:18) Jun 02 14:38:40 volumio volumio[815]: at WebSocket.message (/data/plugins/music_service/spop/index.js:199:14) Jun 02 14:38:40 volumio volumio[815]: at WebSocket.emit (events.js:315:20) Jun 02 14:38:40 volumio volumio[815]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Jun 02 14:38:40 volumio volumio[815]: at Receiver.emit (events.js:315:20) Jun 02 14:38:40 volumio volumio[815]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Jun 02 14:38:40 volumio volumio[815]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Jun 02 14:38:40 volumio volumio[815]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Jun 02 14:38:40 volumio volumio[815]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Jun 02 14:38:40 volumio volumio[815]: at writeOrBuffer (internal/streams/writable.js:358:12) Jun 02 14:38:40 volumio volumio[815]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Jun 02 14:38:40 volumio volumio[815]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Jun 02 14:38:40 volumio volumio[815]: at Socket.emit (events.js:315:20) Jun 02 14:38:40 volumio volumio[815]: at addChunk (internal/streams/readable.js:309:12) Jun 02 14:38:40 volumio volumio[815]: at readableAddChunk (internal/streams/readable.js:284:9) Jun 02 14:38:40 volumio volumio[815]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 02 14:38:42 volumio volumio[1070]: .........++++ Jun 02 14:38:42 volumio volumio[1070]: e is 65537 (0x010001) Jun 02 14:38:42 volumio volumio[1070]: writing RSA key Jun 02 14:38:42 volumio sudo[1190]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-06-02 14:37 Jun 02 14:38:42 volumio sudo[1190]: 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="cd8cf34b47ce852e70b71e6f7b6e0265f7fdb695" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="8f88153f9a18f312d56050e6613b45a852ac819a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 27 Sep 2023 11:35:49 AM CEST" VOLUMIO_VERSION="3.546" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="6823c0d83061ff736b7e0dd4481bc496"