-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Fri 2025-07-11 07:44:43 CEST. -- Jul 11 07:44:12 volumio systemd-timedated[779]: Changed local time to Fri Jul 11 07:44:12 2025 Jul 11 07:44:12 volumio sudo[777]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:12 volumio volumio-time-update[475]: volumio-time-update-util: System time updated successfully. Jul 11 07:44:12 volumio systemd[1]: Starting Daily apt download activities... Jul 11 07:44:12 volumio systemd[1]: Started Volumio Time Update Utility. Jul 11 07:44:12 volumio systemd[1]: Reached target Multi-User System. Jul 11 07:44:12 volumio systemd[1]: Reached target Graphical Interface. Jul 11 07:44:12 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Jul 11 07:44:12 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jul 11 07:44:12 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Jul 11 07:44:12 volumio volumio[680]: info: MYVOLUMIO Environment detected Jul 11 07:44:13 volumio volumio[680]: info: Plugin folders cleanup Jul 11 07:44:13 volumio volumio[680]: info: Scanning into folder /volumio/app/plugins/ Jul 11 07:44:13 volumio volumio[680]: info: Scanning category audio_interface Jul 11 07:44:13 volumio volumio[680]: info: Scanning category miscellanea Jul 11 07:44:13 volumio volumio[680]: info: Scanning category music_service Jul 11 07:44:13 volumio volumio[680]: info: Scanning category plugins.json Jul 11 07:44:13 volumio volumio[680]: info: Scanning category system_controller Jul 11 07:44:13 volumio volumio[680]: info: Scanning category user_interface Jul 11 07:44:13 volumio volumio[680]: info: Scanning into folder /data/plugins/ Jul 11 07:44:13 volumio volumio[680]: info: Scanning category music_service Jul 11 07:44:13 volumio volumio[680]: info: Scanning category user_interface Jul 11 07:44:13 volumio volumio[680]: info: Plugin folders cleanup completed Jul 11 07:44:13 volumio volumio[680]: info: ------------------------------------------- Jul 11 07:44:13 volumio volumio[680]: info: ----- Core plugins startup ---- Jul 11 07:44:13 volumio volumio[680]: info: ------------------------------------------- Jul 11 07:44:13 volumio volumio[680]: info: Loading plugins from folder /volumio/app/plugins/ Jul 11 07:44:13 volumio volumio[680]: info: Adding plugin upnp to MyMusic Plugins Jul 11 07:44:13 volumio volumio[680]: info: Adding plugin airplay_emulation to MyMusic Plugins Jul 11 07:44:13 volumio volumio[680]: info: Adding plugin upnp_browser to MyMusic Plugins Jul 11 07:44:13 volumio volumio-remote-updater[501]: [2025-07-11 07:44:13] [connect] Successful connection Jul 11 07:44:13 volumio volumio[680]: info: Loading plugins from folder /data/plugins/ Jul 11 07:44:13 volumio volumio[680]: info: Loading plugin "system"... Jul 11 07:44:13 volumio volumio[680]: info: Loading plugin "appearance"... Jul 11 07:44:14 volumio systemd[1]: apt-daily.service: Succeeded. Jul 11 07:44:14 volumio systemd[1]: Started Daily apt download activities. Jul 11 07:44:14 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Jul 11 07:44:15 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Jul 11 07:44:15 volumio systemd[1]: Started Daily apt upgrade and clean activities. Jul 11 07:44:15 volumio systemd[1]: Startup finished in 15.081s (kernel) + 23.524s (userspace) = 38.605s. Jul 11 07:44:16 volumio volumio[680]: info: Loading plugin "network"... Jul 11 07:44:16 volumio volumio[680]: info: Refreshing Cached IP Addresses Jul 11 07:44:16 volumio sudo[887]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 11 07:44:16 volumio sudo[887]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 11 07:44:16 volumio sudo[889]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 11 07:44:16 volumio sudo[889]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 11 07:44:16 volumio sudo[887]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:16 volumio volumio[680]: info: Loading plugin "services"... Jul 11 07:44:16 volumio volumio[680]: info: Loading plugin "alsa_controller"... Jul 11 07:44:16 volumio sudo[889]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:16 volumio sudo[899]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jul 11 07:44:16 volumio sudo[899]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 11 07:44:16 volumio sudo[899]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:16 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 11 07:44:16 volumio volumio[680]: info: Loading plugin "wizard"... Jul 11 07:44:16 volumio volumio[680]: info: Loading plugin "networkfs"... Jul 11 07:44:16 volumio volumio[680]: info: Starting Udev Watcher for removable devices Jul 11 07:44:16 volumio sudo[919]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=mcavalera,password=Passio-Nate45,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.75/Music /mnt/NAS/Music Jul 11 07:44:16 volumio sudo[919]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 11 07:44:16 volumio volumio[680]: info: Ignoring mount for partition: boot Jul 11 07:44:16 volumio volumio[680]: info: Ignoring mount for partition: volumio Jul 11 07:44:16 volumio volumio[680]: info: Ignoring mount for partition: volumio_data Jul 11 07:44:16 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 11 07:44:16 volumio volumio[680]: info: Loading plugin "volumio_command_line_client"... Jul 11 07:44:17 volumio volumio[680]: info: Loading plugin "upnp"... Jul 11 07:44:17 volumio volumio[680]: info: [1752212657049] Starting Upmpd Daemon Jul 11 07:44:17 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 11 07:44:17 volumio volumio[680]: info: Loading plugin "my_music"... Jul 11 07:44:17 volumio volumio[680]: info: Loading plugin "mpd"... Jul 11 07:44:17 volumio kernel: Key type cifs.spnego registered Jul 11 07:44:17 volumio kernel: Key type cifs.idmap registered Jul 11 07:44:17 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. Jul 11 07:44:17 volumio kernel: CIFS: Attempting to mount //192.168.0.75/Music Jul 11 07:44:17 volumio kernel: cryptd: max_cpu_qlen set to 1000 Jul 11 07:44:17 volumio sudo[919]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:18 volumio volumio[680]: info: Loading plugin "upnp_browser"... Jul 11 07:44:18 volumio volumio[680]: info: Loading plugin "alarm-clock"... Jul 11 07:44:19 volumio volumio[680]: info: Loading plugin "airplay_emulation"... Jul 11 07:44:19 volumio volumio[680]: info: Starting Shairport Sync Jul 11 07:44:19 volumio volumio[680]: info: Loading plugin "last_100"... Jul 11 07:44:19 volumio volumio[680]: info: Loading plugin "webradio"... Jul 11 07:44:19 volumio volumio[680]: info: Loading plugin "i2s_dacs"... Jul 11 07:44:19 volumio volumio[680]: info: Loading plugin "volumiodiscovery"... Jul 11 07:44:19 volumio volumio[680]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 11 07:44:19 volumio volumio[680]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 11 07:44:19 volumio node[680]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 11 07:44:19 volumio volumio[680]: *** WARNING *** For more information see Jul 11 07:44:19 volumio volumio[680]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 11 07:44:19 volumio volumio[680]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 11 07:44:19 volumio volumio[680]: *** WARNING *** For more information see Jul 11 07:44:19 volumio node[680]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 11 07:44:19 volumio node[680]: *** WARNING *** For more information see Jul 11 07:44:19 volumio node[680]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 11 07:44:19 volumio node[680]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 11 07:44:19 volumio node[680]: *** WARNING *** For more information see Jul 11 07:44:19 volumio volumio[680]: info: Applying required configuration parameters for plugin volumiodiscovery Jul 11 07:44:19 volumio volumio[680]: info: Discovery: Started advertising with name: Volumio Jul 11 07:44:19 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 11 07:44:19 volumio volumio[680]: info: Loading plugin "spop"... Jul 11 07:44:22 volumio volumio[680]: info: Loading plugin "outputs"... Jul 11 07:44:22 volumio volumio[680]: info: Loading plugin "albumart"... Jul 11 07:44:23 volumio volumio[680]: info: Plugin example_plugin is not enabled Jul 11 07:44:23 volumio volumio[680]: info: Loading plugin "inputs"... Jul 11 07:44:23 volumio volumio[680]: info: Loading plugin "updater_comm"... Jul 11 07:44:23 volumio volumio[680]: info: Plugin mpdemulation is not enabled Jul 11 07:44:23 volumio volumio[680]: info: Loading plugin "rest_api"... Jul 11 07:44:23 volumio volumio[680]: info: Loading plugin "websocket"... Jul 11 07:44:23 volumio volumio[680]: info: Starting Socket.io Server version 2.3.0 Jul 11 07:44:23 volumio volumio[680]: info: Loading plugin "Systeminfo"... Jul 11 07:44:23 volumio volumio[680]: Forking 3 albumart workers Jul 11 07:44:24 volumio volumio[680]: info: Loading i18n strings for locale hu Jul 11 07:44:24 volumio volumio[680]: Updating browse sources language Jul 11 07:44:24 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 11 07:44:25 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 11 07:44:25 volumio volumio[680]: info: CoreCommandRouter::initPlayerControls Jul 11 07:44:25 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:25 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:25 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:25 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:25 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:25 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:25 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:25 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:25 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 11 07:44:25 volumio volumio[680]: Express server listening on port 3000 Jul 11 07:44:25 volumio volumio[680]: [Metrics] WebUI: 17s 154.23ms Jul 11 07:44:25 volumio volumio[680]: info: CoreStateMachine::resetVolumioState Jul 11 07:44:25 volumio volumio[680]: info: CoreStateMachine::getcurrentVolume Jul 11 07:44:25 volumio volumio[680]: info: CoreCommandRouter::volumioRetrievevolume Jul 11 07:44:25 volumio volumio[680]: Starting albumart workers Jul 11 07:44:25 volumio volumio[680]: Starting albumart workers Jul 11 07:44:25 volumio volumio[680]: Starting albumart workers Jul 11 07:44:25 volumio volumio[680]: info: Volumio Network Manager: Network status updated: 1 Jul 11 07:44:25 volumio volumio[680]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Jul 11 07:44:25 volumio volumio[680]: wlan0 Interface doesn't support scanning. Jul 11 07:44:25 volumio volumio[680]: info: Cannot use regular scanning, forcing with ap-force Jul 11 07:44:26 volumio sudo[996]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Jul 11 07:44:26 volumio sudo[996]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 11 07:44:26 volumio sudo[996]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:26 volumio volumio[680]: command failed: No such device (-19) Jul 11 07:44:26 volumio volumio[680]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Jul 11 07:44:26 volumio volumio[680]: command failed: No such device (-19) Jul 11 07:44:26 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 11 07:44:26 volumio volumio[680]: info: Executing start script for DAC IQaudIO DAC Plus Jul 11 07:44:26 volumio volumio[680]: info: Reloading queue from file Jul 11 07:44:26 volumio volumio[680]: info: CoreStateMachine::setRepeat null single undefined Jul 11 07:44:26 volumio volumio[680]: info: CoreStateMachine::pushState Jul 11 07:44:26 volumio volumio[680]: info: CorePlayQueue::getTrack 0 Jul 11 07:44:26 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 11 07:44:26 volumio volumio[680]: info: CoreCommandRouter::volumioPushState Jul 11 07:44:26 volumio volumio[680]: info: CoreStateMachine::setRandom true Jul 11 07:44:26 volumio volumio[680]: info: CoreStateMachine::pushState Jul 11 07:44:26 volumio volumio[680]: info: CorePlayQueue::getTrack 0 Jul 11 07:44:26 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 11 07:44:26 volumio volumio[680]: info: CoreCommandRouter::volumioPushState Jul 11 07:44:26 volumio volumio[680]: info: Setting Device type: Raspberry PI Jul 11 07:44:26 volumio volumio[680]: info: VolumeController:: Volume=93 Mute =false Jul 11 07:44:26 volumio volumio[680]: info: CoreStateMachine::pushState Jul 11 07:44:26 volumio volumio[680]: info: CorePlayQueue::getTrack 0 Jul 11 07:44:26 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 11 07:44:26 volumio volumio[680]: info: CoreCommandRouter::volumioPushState Jul 11 07:44:26 volumio volumio[680]: info: CoreStateMachine::updateTrackBlock Jul 11 07:44:26 volumio volumio[680]: info: CorePlayQueue::getTrackBlock Jul 11 07:44:26 volumio volumio[680]: info: CoreCommandRouter::volumioRetrievevolume Jul 11 07:44:26 volumio volumio[680]: info: DAC script executed Jul 11 07:44:26 volumio volumio[680]: info: Completed loading Core Plugins Jul 11 07:44:26 volumio volumio[680]: info: Preparing to generate the ALSA configuration file Jul 11 07:44:27 volumio volumio[680]: info: Discovery: adding 20595d90-4bb5-4691-baea-cf7819f4cc9f Jul 11 07:44:27 volumio volumio[680]: info: Discovery: Found device Volumio Jul 11 07:44:27 volumio volumio[680]: info: CoreCommandRouter::volumioGetState Jul 11 07:44:27 volumio volumio[680]: info: CorePlayQueue::getTrack 0 Jul 11 07:44:27 volumio volumio[680]: info: VolumeController:: Volume=93 Mute =false Jul 11 07:44:27 volumio sudo[1031]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 11 07:44:27 volumio volumio[680]: info: CoreStateMachine::pushState Jul 11 07:44:27 volumio volumio[680]: info: CorePlayQueue::getTrack 0 Jul 11 07:44:27 volumio volumio[680]: info: CoreCommandRouter::volumioPushState Jul 11 07:44:27 volumio sudo[1031]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 11 07:44:27 volumio volumio[680]: info: Asound.conf file unchanged, so no further update is needed Jul 11 07:44:27 volumio sudo[1031]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:27 volumio volumio[680]: info: Output device has changed, restarting MPD Jul 11 07:44:27 volumio sudo[1037]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 11 07:44:27 volumio sudo[1037]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 11 07:44:27 volumio volumio[680]: info: Output device has changed, restarting Shairport Sync Jul 11 07:44:27 volumio sudo[1037]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:27 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:27 volumio sudo[1041]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 11 07:44:27 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 11 07:44:27 volumio sudo[1041]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 11 07:44:27 volumio sudo[1041]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:27 volumio sudo[1045]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 11 07:44:27 volumio sudo[1045]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 11 07:44:27 volumio systemd[1]: Stopping Music Player Daemon... Jul 11 07:44:27 volumio volumio[680]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 11 07:44:27 volumio volumio[680]: info: ___________ START PLUGINS ___________ Jul 11 07:44:27 volumio volumio[680]: info: ControllerMpd::onStart: Initializing MPD Jul 11 07:44:27 volumio volumio[680]: info: Creating MPD Configuration file Jul 11 07:44:27 volumio sudo[1068]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 11 07:44:27 volumio sudo[1068]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 11 07:44:27 volumio sudo[1068]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:27 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 11 07:44:27 volumio volumio[680]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 11 07:44:27 volumio volumio[680]: info: [1752212667733] CoreMusicLibrary::Adding element Médiaszerverek Jul 11 07:44:27 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 11 07:44:27 volumio sudo[1071]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 11 07:44:27 volumio sudo[1071]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 11 07:44:27 volumio systemd[1]: systemd-fsckd.service: Succeeded. Jul 11 07:44:27 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:27 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 11 07:44:27 volumio systemd[1]: mpd.service: Succeeded. Jul 11 07:44:27 volumio systemd[1]: Stopped Music Player Daemon. Jul 11 07:44:27 volumio systemd[1]: Starting Music Player Daemon... Jul 11 07:44:27 volumio volumio[680]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 11 07:44:27 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:27 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 11 07:44:28 volumio volumio[680]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 11 07:44:28 volumio volumio[680]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 11 07:44:28 volumio volumio[680]: info: [1752212668007] CoreMusicLibrary::Adding element Last_100 Jul 11 07:44:28 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 11 07:44:28 volumio volumio[680]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 11 07:44:28 volumio volumio[680]: info: [1752212668014] CoreMusicLibrary::Adding element Webradio Jul 11 07:44:28 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 11 07:44:28 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 11 07:44:28 volumio volumio[680]: info: Initializing BBC Radios Jul 11 07:44:28 volumio sudo[1076]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 11 07:44:28 volumio sudo[1076]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 11 07:44:28 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 11 07:44:28 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 11 07:44:28 volumio sudo[1076]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:28 volumio volumio[680]: info: Creating Spotify config file Jul 11 07:44:28 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:28 volumio volumio[680]: info: Volumio Calling Home Jul 11 07:44:28 volumio volumio-remote-updater[501]: [2025-07-11 07:44:28] [connect] Successful connection Jul 11 07:44:28 volumio volumio[680]: info: MPD Permissions set Jul 11 07:44:28 volumio volumio[680]: info: MPD Permissions set Jul 11 07:44:28 volumio volumio-remote-updater[501]: [2025-07-11 07:44:28] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1752212668 101 Jul 11 07:44:28 volumio volumio[680]: 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 Jul 11 07:44:28 volumio volumio[680]: info: Volumio called home Jul 11 07:44:28 volumio volumio[680]: info: Spotify config file written Jul 11 07:44:28 volumio sudo[1098]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jul 11 07:44:28 volumio sudo[1098]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 11 07:44:28 volumio volumio[680]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jul 11 07:44:28 volumio systemd[1]: Started go-librespot Daemon. Jul 11 07:44:28 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:28 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:28 volumio go-librespot[1100]: Librespot-go daemon starting... Jul 11 07:44:29 volumio sudo[1098]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:29 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 11 07:44:29 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:29 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:29 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:29 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:29 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:29 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:29 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:29 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:29 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:29 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 11 07:44:29 volumio volumio[680]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 11 07:44:29 volumio sudo[1111]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jul 11 07:44:29 volumio sudo[1111]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 11 07:44:29 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Jul 11 07:44:29 volumio sudo[1111]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:29 volumio volumio[680]: info: Upmpdcli Daemon Started Jul 11 07:44:29 volumio volumio[680]: info: Starting Shairport Sync Jul 11 07:44:29 volumio volumio[680]: info: Starting Shairport Sync Jul 11 07:44:29 volumio volumio[680]: info: Starting Shairport Sync Jul 11 07:44:29 volumio sudo[1121]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 11 07:44:29 volumio sudo[1121]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 11 07:44:29 volumio go-librespot[1100]: time="2025-07-11T07:44:29+02:00" level=info msg="generated new device id: bebb41ddfec73f1927911e407b2694df78bf336e" Jul 11 07:44:29 volumio sudo[1123]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 11 07:44:29 volumio sudo[1123]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 11 07:44:29 volumio sudo[1125]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 11 07:44:29 volumio sudo[1125]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 11 07:44:29 volumio volumio[680]: info: CoreCommandRouter::volumioGetState Jul 11 07:44:29 volumio volumio[680]: info: CorePlayQueue::getTrack 0 Jul 11 07:44:29 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jul 11 07:44:29 volumio systemd[1]: shairport-sync.service: Succeeded. Jul 11 07:44:29 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jul 11 07:44:29 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 11 07:44:29 volumio sudo[1121]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:29 volumio sudo[1123]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:29 volumio sudo[1125]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:29 volumio volumio[680]: info: Shairport-Sync Started Jul 11 07:44:29 volumio volumio[680]: Error adding Membership: Error: addMembership EINVAL Jul 11 07:44:29 volumio volumio[680]: info: Shairport-Sync Started Jul 11 07:44:29 volumio volumio[680]: info: Shairport-Sync Started Jul 11 07:44:30 volumio go-librespot[1100]: time="2025-07-11T07:44:30+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jul 11 07:44:30 volumio go-librespot[1100]: time="2025-07-11T07:44:30+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jul 11 07:44:30 volumio go-librespot[1100]: time="2025-07-11T07:44:30+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jul 11 07:44:30 volumio go-librespot[1100]: time="2025-07-11T07:44:30+02:00" level=debug msg="zeroconf server listening on port 41747" Jul 11 07:44:31 volumio mpd[1091]: Jul 11 07:44 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 11 07:44:31 volumio systemd[1]: Started Music Player Daemon. Jul 11 07:44:31 volumio volumio[680]: Upnp client error: Error: This socket has been ended by the other party Jul 11 07:44:31 volumio sudo[1045]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:31 volumio sudo[1071]: pam_unix(sudo:session): session closed for user root Jul 11 07:44:31 volumio volumio[680]: info: Completed starting Core Plugins Jul 11 07:44:31 volumio volumio[680]: info: ------------------------------------------- Jul 11 07:44:31 volumio volumio[680]: info: ----- MyVolumio plugins startup ---- Jul 11 07:44:31 volumio volumio[680]: info: ------------------------------------------- Jul 11 07:44:31 volumio volumio[680]: info: [MyVolumio PluginManager] Fetching plans data.... Jul 11 07:44:31 volumio volumio[680]: error: MPD error: The expression evaluated to a falsy value: Jul 11 07:44:31 volumio volumio[680]: assert.ok(self.idling) Jul 11 07:44:31 volumio volumio[680]: error: The expression evaluated to a falsy value: Jul 11 07:44:31 volumio volumio[680]: assert.ok(self.idling) Jul 11 07:44:31 volumio volumio[680]: error: updateQueue error: null Jul 11 07:44:31 volumio volumio[680]: info: MPD running with PID1091 Jul 11 07:44:31 volumio volumio[680]: ,establishing connection Jul 11 07:44:31 volumio volumio[680]: error: updateQueue error: null Jul 11 07:44:32 volumio volumio[680]: info: go-librespot daemon successfully initialized Jul 11 07:44:33 volumio volumio[1118]: Generating RSA private key, 4096 bit long modulus (2 primes) Jul 11 07:44:35 volumio volumio[680]: info: Initializing connection to go-librespot Websocket Jul 11 07:44:35 volumio go-librespot[1100]: time="2025-07-11T07:44:35+02:00" level=debug msg="new websocket client" Jul 11 07:44:35 volumio volumio[680]: info: Connection to go-librespot Websocket established Jul 11 07:44:37 volumio volumio[680]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jul 11 07:44:38 volumio go-librespot[1100]: time="2025-07-11T07:44:38+02:00" level=debug msg="obtained new client token: AAA1siGOl1OZGADOm2TrBEvNylFj/OFpe8Bs5sFnRVomRc4n7xCnt6nbEE2ggBGwKFe9ef/A4HNPAnY/4+e88DDklvfsnxmoHeNC/93REl5I3gP1woNIAZnQVkzQyOTpj7tDezpb9DlzSKjq1tYTtgyQ2eAR50+NR10hs7Do0+r+wV61e8NwydCJhVD4LtnuChUzguSlwwiD1KHe+iK2XX06Le08xP9dI8quXBBoz5Tk2nSTH7eze7RYghMbI0Q=" Jul 11 07:44:38 volumio go-librespot[1100]: time="2025-07-11T07:44:38+02:00" level=debug msg="completed keyexchange" Jul 11 07:44:38 volumio go-librespot[1100]: time="2025-07-11T07:44:38+02:00" level=debug msg="completed challenge" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="authenticated as pazvzu6s6iqfcb5yvy4xcjgul" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="authenticated as pazvzu6s6iqfcb5yvy4xcjgul" Jul 11 07:44:39 volumio volumio[680]: info: Getting Spotify volume Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="dealer connection opened" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=info msg="accepted zeroconf user pazvzu6s6iqfcb5yvy4xcjgul from SIRIUS-SMALL" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="received connection id: MjJjMzcwOTQtYjA0Mi00NGYyLWI0ZTAtMWNiOGQ2ODM5ZWJmK2RlYWxlcit0Y3A6Ly8wYWNhNDI0NC5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArRDEyRTU1OUM4QzIwQTE5OTdCNDI4NzRGMzlCMDIzQzI2MTVBRUI3QTBDQkUyMEE3REEzQjZCNkVFODQ2MEY1RQ==" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="put connect state because NEW_DEVICE" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="handling transfer player command from 9249c8eecd7559a27615706d4fe01a15f0b4cd08" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 1 with 1 items (list: 2)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 2 with 1 items (list: 3)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 3 with 1 items (list: 4)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 4 with 10 items (list: 14)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 5 with 2 items (list: 16)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 6 with 1 items (list: 17)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 7 with 1 items (list: 18)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 8 with 8 items (list: 26)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 9 with 2 items (list: 28)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 10 with 1 items (list: 29)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 11 with 10 items (list: 39)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 12 with 1 items (list: 40)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 13 with 11 items (list: 51)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 14 with 1 items (list: 52)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 15 with 1 items (list: 53)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 16 with 1 items (list: 54)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 17 with 14 items (list: 68)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 18 with 1 items (list: 69)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 19 with 13 items (list: 82)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 20 with 13 items (list: 95)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 21 with 1 items (list: 96)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 22 with 12 items (list: 108)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 23 with 12 items (list: 120)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 24 with 3 items (list: 123)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 25 with 13 items (list: 136)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 26 with 15 items (list: 151)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 27 with 27 items (list: 178)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 28 with 12 items (list: 190)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 29 with 12 items (list: 202)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 30 with 13 items (list: 215)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 31 with 17 items (list: 232)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 32 with 12 items (list: 244)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="fetched new page 33 with 15 items (list: 259)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="shuffled context with seed 16322221979784158263 (len: 259, keep: 55)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="loading track spotify:track:7cdV2P2AYQGmtR55snLYWC (paused: false, position: 70862ms)" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=trace msg="emitting websocket event: will_play" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:7cdV2P2AYQGmtR55snLYWC" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="requested aes key for file d5496e2ef9eb0cc07c26caa06db54859c8637202, gid: 7cdV2P2AYQGmtR55snLYWC" Jul 11 07:44:39 volumio go-librespot[1100]: time="2025-07-11T07:44:39+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1690" Jul 11 07:44:40 volumio volumio[680]: info: Spotify volume: 100 Jul 11 07:44:40 volumio volumio[680]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jul 11 07:44:40 volumio go-librespot[1100]: time="2025-07-11T07:44:40+02:00" level=debug msg="fetched first chunk of 18, total size is 9305464 bytes" Jul 11 07:44:40 volumio go-librespot[1100]: time="2025-07-11T07:44:40+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1289" Jul 11 07:44:40 volumio volumio[680]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7cdV2P2AYQGmtR55snLYWC","play_origin":"artist"}} Jul 11 07:44:40 volumio go-librespot[1100]: time="2025-07-11T07:44:40+02:00" level=debug msg="fetched chunk 1/17, size: 524288" Jul 11 07:44:41 volumio go-librespot[1100]: time="2025-07-11T07:44:41+02:00" level=debug msg="fetched chunk 3/17, size: 524288" Jul 11 07:44:41 volumio go-librespot[1100]: time="2025-07-11T07:44:41+02:00" level=debug msg="fetched chunk 5/17, size: 524288" Jul 11 07:44:41 volumio go-librespot[1100]: time="2025-07-11T07:44:41+02:00" level=debug msg="fetched chunk 8/17, size: 524288" Jul 11 07:44:41 volumio go-librespot[1100]: time="2025-07-11T07:44:41+02:00" level=trace msg="seek to 70862ms (diff: 133ms, samples: 3125014, bytes: 2773011)" Jul 11 07:44:41 volumio go-librespot[1100]: time="2025-07-11T07:44:41+02:00" level=debug msg="fetched chunk 7/17, size: 524288" Jul 11 07:44:41 volumio go-librespot[1100]: time="2025-07-11T07:44:41+02:00" level=debug msg="fetched chunk 2/17, size: 524288" Jul 11 07:44:41 volumio go-librespot[1100]: time="2025-07-11T07:44:41+02:00" level=debug msg="fetched chunk 6/17, size: 524288" Jul 11 07:44:41 volumio go-librespot[1100]: time="2025-07-11T07:44:41+02:00" level=info msg="loaded track \"Ebullition\" (uri: spotify:track:7cdV2P2AYQGmtR55snLYWC, paused: false, position: 70862ms, duration: 236746ms)" Jul 11 07:44:41 volumio go-librespot[1100]: time="2025-07-11T07:44:41+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 11 07:44:41 volumio go-librespot[1100]: time="2025-07-11T07:44:41+02:00" level=trace msg="emitting websocket event: metadata" Jul 11 07:44:41 volumio go-librespot[1100]: time="2025-07-11T07:44:41+02:00" level=trace msg="emitting websocket event: active" Jul 11 07:44:41 volumio go-librespot[1100]: time="2025-07-11T07:44:41+02:00" level=debug msg="sending successful reply for delaer request" Jul 11 07:44:41 volumio go-librespot[1100]: time="2025-07-11T07:44:41+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jul 11 07:44:41 volumio go-librespot[1100]: time="2025-07-11T07:44:41+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jul 11 07:44:41 volumio go-librespot[1100]: time="2025-07-11T07:44:41+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jul 11 07:44:41 volumio go-librespot[1100]: time="2025-07-11T07:44:41+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 11 07:44:41 volumio go-librespot[1100]: time="2025-07-11T07:44:41+02:00" level=trace msg="emitting websocket event: playing" Jul 11 07:44:41 volumio volumio[680]: info: CoreCommandRouter::volumioGetState Jul 11 07:44:41 volumio volumio[680]: info: CorePlayQueue::getTrack 0 Jul 11 07:44:42 volumio systemd[1]: systemd-timedated.service: Succeeded. Jul 11 07:44:42 volumio volumio[680]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7cdV2P2AYQGmtR55snLYWC","name":"Ebullition","artist_names":["Ektomorf"],"album_name":"Reborn","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02030b1de3eee3aa7353cfd69d","position":70862,"duration":236746,"release_date":"year:2021 month:1 day:22","track_number":1,"disc_number":1}} Jul 11 07:44:42 volumio volumio[680]: SPOTIFY: received: {"type":"active","data":null} Jul 11 07:44:42 volumio volumio[680]: info: Aligning Spotify Volume to Volumio Volume Jul 11 07:44:42 volumio volumio[680]: info: CoreCommandRouter::volumioGetState Jul 11 07:44:42 volumio volumio[680]: info: CorePlayQueue::getTrack 0 Jul 11 07:44:42 volumio volumio[680]: info: Setting Spotify Volume from Volumio: 93 Jul 11 07:44:42 volumio volumio[680]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7cdV2P2AYQGmtR55snLYWC","play_origin":"artist"}} Jul 11 07:44:42 volumio volumio[680]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 11 07:44:42 volumio volumio[680]: TypeError: Cannot read property 'service' of undefined Jul 11 07:44:42 volumio volumio[680]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Jul 11 07:44:42 volumio volumio[680]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:262:18) Jul 11 07:44:42 volumio volumio[680]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Jul 11 07:44:42 volumio volumio[680]: at WebSocket.emit (events.js:315:20) Jul 11 07:44:42 volumio volumio[680]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1203:20) Jul 11 07:44:42 volumio volumio[680]: at Receiver.emit (events.js:315:20) Jul 11 07:44:42 volumio volumio[680]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:608:16 Jul 11 07:44:42 volumio volumio[680]: at internal/process/task_queues.js:149:7 Jul 11 07:44:42 volumio volumio[680]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) Jul 11 07:44:42 volumio volumio[680]: at AsyncResource.runMicrotask (internal/process/task_queues.js:146:8) Jul 11 07:44:42 volumio volumio[680]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Jul 11 07:44:42 volumio volumio[680]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 11 07:44:43 volumio sudo[1181]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-11 07:43 Jul 11 07:44:43 volumio sudo[1181]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 30 Apr 2025 11:47:57 AM CEST" VOLUMIO_VERSION="3.807" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fddd10196af80fdc784c726185a6abe4"