-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Thu 2025-07-03 09:57:18 CEST. -- Jul 03 09:57:01 mediaplayer systemd-timedated[978]: Changed local time to Thu Jul 3 09:57:01 2025 Jul 03 09:57:01 mediaplayer sudo[976]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:01 mediaplayer volumio-time-update[593]: volumio-time-update-util: System time updated successfully. Jul 03 09:57:01 mediaplayer systemd[1]: Starting Daily apt download activities... Jul 03 09:57:01 mediaplayer systemd[1]: Starting Daily man-db regeneration... Jul 03 09:57:01 mediaplayer systemd[1]: Started Volumio Time Update Utility. Jul 03 09:57:01 mediaplayer volumio[946]: info: MYVOLUMIO Environment detected Jul 03 09:57:01 mediaplayer nmbd[717]: [2025/07/03 09:57:01.891889, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jul 03 09:57:01 mediaplayer nmbd[717]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jul 03 09:57:01 mediaplayer systemd[1]: Started Samba NMB Daemon. Jul 03 09:57:01 mediaplayer systemd[1]: Starting Samba Winbind Daemon... Jul 03 09:57:02 mediaplayer volumio[946]: info: Plugin folders cleanup Jul 03 09:57:02 mediaplayer volumio[946]: info: Scanning into folder /volumio/app/plugins/ Jul 03 09:57:02 mediaplayer volumio[946]: info: Scanning category audio_interface Jul 03 09:57:02 mediaplayer volumio[946]: info: Scanning category miscellanea Jul 03 09:57:02 mediaplayer volumio[946]: info: Scanning category music_service Jul 03 09:57:02 mediaplayer volumio[946]: info: Scanning category plugins.json Jul 03 09:57:02 mediaplayer volumio[946]: info: Scanning category system_controller Jul 03 09:57:02 mediaplayer volumio[946]: info: Scanning category user_interface Jul 03 09:57:02 mediaplayer volumio[946]: info: Scanning into folder /data/plugins/ Jul 03 09:57:02 mediaplayer volumio[946]: info: Scanning category audio_interface Jul 03 09:57:02 mediaplayer volumio[946]: info: Scanning category music_service Jul 03 09:57:02 mediaplayer volumio[946]: info: Scanning category user_interface Jul 03 09:57:02 mediaplayer volumio[946]: info: Plugin folders cleanup completed Jul 03 09:57:02 mediaplayer volumio[946]: info: ------------------------------------------- Jul 03 09:57:02 mediaplayer volumio[946]: info: ----- Core plugins startup ---- Jul 03 09:57:02 mediaplayer volumio[946]: info: ------------------------------------------- Jul 03 09:57:02 mediaplayer volumio[946]: info: Loading plugins from folder /volumio/app/plugins/ Jul 03 09:57:02 mediaplayer volumio[946]: info: Adding plugin upnp to MyMusic Plugins Jul 03 09:57:02 mediaplayer volumio[946]: info: Adding plugin airplay_emulation to MyMusic Plugins Jul 03 09:57:02 mediaplayer volumio[946]: info: Adding plugin upnp_browser to MyMusic Plugins Jul 03 09:57:02 mediaplayer volumio[946]: info: Loading plugins from folder /data/plugins/ Jul 03 09:57:02 mediaplayer volumio[946]: info: Loading plugin "system"... Jul 03 09:57:02 mediaplayer winbindd[1004]: [2025/07/03 09:57:02.213351, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jul 03 09:57:02 mediaplayer winbindd[1004]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jul 03 09:57:02 mediaplayer volumio[946]: info: Loading plugin "appearance"... Jul 03 09:57:02 mediaplayer winbindd[1004]: [2025/07/03 09:57:02.312481, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jul 03 09:57:02 mediaplayer winbindd[1004]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jul 03 09:57:02 mediaplayer systemd[1]: Started Samba Winbind Daemon. Jul 03 09:57:02 mediaplayer systemd[1]: Starting Samba SMB Daemon... Jul 03 09:57:02 mediaplayer systemd[1]: man-db.service: Succeeded. Jul 03 09:57:02 mediaplayer systemd[1]: Started Daily man-db regeneration. Jul 03 09:57:02 mediaplayer smbd[1012]: [2025/07/03 09:57:02.757429, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jul 03 09:57:02 mediaplayer systemd[1]: Started Samba SMB Daemon. Jul 03 09:57:02 mediaplayer smbd[1012]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jul 03 09:57:02 mediaplayer systemd[1]: Reached target Multi-User System. Jul 03 09:57:02 mediaplayer systemd[1]: Reached target Graphical Interface. Jul 03 09:57:02 mediaplayer systemd[1]: Starting Update UTMP about System Runlevel Changes... Jul 03 09:57:02 mediaplayer systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jul 03 09:57:02 mediaplayer systemd[1]: Started Update UTMP about System Runlevel Changes. Jul 03 09:57:03 mediaplayer volumio-remote-updater[590]: [2025-07-03 09:57:03] [connect] Successful connection Jul 03 09:57:03 mediaplayer systemd[1]: apt-daily.service: Succeeded. Jul 03 09:57:03 mediaplayer systemd[1]: Started Daily apt download activities. Jul 03 09:57:03 mediaplayer systemd[1]: Starting Daily apt upgrade and clean activities... Jul 03 09:57:03 mediaplayer volumio[946]: info: Loading plugin "network"... Jul 03 09:57:03 mediaplayer volumio[946]: info: Refreshing Cached IP Addresses Jul 03 09:57:03 mediaplayer sudo[1068]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 03 09:57:03 mediaplayer sudo[1068]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:03 mediaplayer sudo[1071]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 03 09:57:03 mediaplayer sudo[1071]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:03 mediaplayer sudo[1068]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:03 mediaplayer volumio[946]: info: Loading plugin "services"... Jul 03 09:57:03 mediaplayer sudo[1071]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:03 mediaplayer volumio[946]: info: Loading plugin "alsa_controller"... Jul 03 09:57:03 mediaplayer sudo[1081]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jul 03 09:57:03 mediaplayer sudo[1081]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:03 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 03 09:57:03 mediaplayer volumio[946]: info: Loading plugin "wizard"... Jul 03 09:57:03 mediaplayer volumio[946]: info: Loading plugin "networkfs"... Jul 03 09:57:03 mediaplayer volumio[946]: info: Starting Udev Watcher for removable devices Jul 03 09:57:03 mediaplayer volumio[946]: info: Ignoring mount for partition: boot Jul 03 09:57:03 mediaplayer volumio[946]: info: Ignoring mount for partition: volumio Jul 03 09:57:03 mediaplayer volumio[946]: info: Ignoring mount for partition: volumio_data Jul 03 09:57:03 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 03 09:57:03 mediaplayer volumio[946]: info: Loading plugin "volumio_command_line_client"... Jul 03 09:57:03 mediaplayer volumio[946]: info: Loading plugin "upnp"... Jul 03 09:57:03 mediaplayer volumio[946]: info: [1751529423718] Starting Upmpd Daemon Jul 03 09:57:03 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 03 09:57:03 mediaplayer volumio[946]: info: Loading plugin "my_music"... Jul 03 09:57:03 mediaplayer volumio[946]: info: Loading plugin "mpd"... Jul 03 09:57:04 mediaplayer volumio[946]: info: Loading plugin "upnp_browser"... Jul 03 09:57:04 mediaplayer volumio[946]: info: Loading plugin "alarm-clock"... Jul 03 09:57:04 mediaplayer volumio[946]: info: Loading plugin "airplay_emulation"... Jul 03 09:57:04 mediaplayer volumio[946]: info: Starting Shairport Sync Jul 03 09:57:04 mediaplayer volumio[946]: info: Loading plugin "last_100"... Jul 03 09:57:04 mediaplayer volumio[946]: info: Loading plugin "webradio"... Jul 03 09:57:04 mediaplayer systemd[1]: apt-daily-upgrade.service: Succeeded. Jul 03 09:57:04 mediaplayer systemd[1]: Started Daily apt upgrade and clean activities. Jul 03 09:57:04 mediaplayer systemd[1]: Startup finished in 11.852s (kernel) + 28.097s (userspace) = 39.949s. Jul 03 09:57:04 mediaplayer volumio[946]: info: Loading plugin "i2s_dacs"... Jul 03 09:57:04 mediaplayer volumio[946]: info: I2S DAC not set, start Auto-detection Jul 03 09:57:04 mediaplayer volumio[946]: info: Loading plugin "volumiodiscovery"... Jul 03 09:57:04 mediaplayer volumio[946]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 03 09:57:04 mediaplayer volumio[946]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 03 09:57:04 mediaplayer node[946]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jul 03 09:57:04 mediaplayer volumio[946]: *** WARNING *** For more information see Jul 03 09:57:04 mediaplayer volumio[946]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 03 09:57:04 mediaplayer volumio[946]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 03 09:57:04 mediaplayer volumio[946]: *** WARNING *** For more information see Jul 03 09:57:04 mediaplayer node[946]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 03 09:57:04 mediaplayer node[946]: *** WARNING *** For more information see Jul 03 09:57:04 mediaplayer node[946]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jul 03 09:57:04 mediaplayer node[946]: *** WARNING *** Please fix your application to use the native API of Avahi! Jul 03 09:57:04 mediaplayer node[946]: *** WARNING *** For more information see Jul 03 09:57:04 mediaplayer volumio[946]: info: Applying required configuration parameters for plugin volumiodiscovery Jul 03 09:57:04 mediaplayer volumio[946]: info: Discovery: Started advertising with name: Mediaplayer Jul 03 09:57:04 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 03 09:57:04 mediaplayer volumio[946]: info: Plugin soundcloud is not enabled Jul 03 09:57:04 mediaplayer volumio[946]: info: Loading plugin "spop"... Jul 03 09:57:05 mediaplayer volumio[946]: info: Loading plugin "now_playing"... Jul 03 09:57:07 mediaplayer sudo[1081]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:07 mediaplayer volumio[946]: info: Loading plugin "outputs"... Jul 03 09:57:07 mediaplayer volumio[946]: info: Loading plugin "albumart"... Jul 03 09:57:07 mediaplayer volumio[946]: info: Plugin example_plugin is not enabled Jul 03 09:57:07 mediaplayer volumio[946]: info: Loading plugin "inputs"... Jul 03 09:57:07 mediaplayer volumio[946]: info: Loading plugin "updater_comm"... Jul 03 09:57:07 mediaplayer volumio[946]: info: Plugin mpdemulation is not enabled Jul 03 09:57:07 mediaplayer volumio[946]: info: Loading plugin "rest_api"... Jul 03 09:57:07 mediaplayer volumio[946]: info: Loading plugin "websocket"... Jul 03 09:57:07 mediaplayer volumio[946]: info: Starting Socket.io Server version 2.3.0 Jul 03 09:57:07 mediaplayer volumio[946]: info: Loading plugin "fusiondsp"... Jul 03 09:57:07 mediaplayer volumio[946]: Forking 3 albumart workers Jul 03 09:57:07 mediaplayer volumio[946]: info: Applying required configuration parameters for plugin fusiondsp Jul 03 09:57:07 mediaplayer volumio[946]: info: Loading plugin "touch_display"... Jul 03 09:57:07 mediaplayer volumio[946]: Starting albumart workers Jul 03 09:57:07 mediaplayer volumio[946]: Starting albumart workers Jul 03 09:57:07 mediaplayer volumio[946]: Starting albumart workers Jul 03 09:57:08 mediaplayer volumio[946]: info: Applying required configuration parameters for plugin touch_display Jul 03 09:57:08 mediaplayer volumio[946]: info: Loading i18n strings for locale en Jul 03 09:57:08 mediaplayer volumio[946]: Updating browse sources language Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::initPlayerControls Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 09:57:08 mediaplayer volumio[946]: Express server listening on port 3000 Jul 03 09:57:08 mediaplayer volumio[946]: [Metrics] WebUI: 8s 408.65ms Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreStateMachine::resetVolumioState Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreStateMachine::getcurrentVolume Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::volumioRetrievevolume Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 09:57:08 mediaplayer volumio[946]: info: Volumio Network Manager: Network status updated: 2 Jul 03 09:57:08 mediaplayer systemd[1]: systemd-fsckd.service: Succeeded. Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::volumioGetState Jul 03 09:57:08 mediaplayer volumio[946]: info: CorePlayQueue::getTrack 0 Jul 03 09:57:08 mediaplayer volumio[946]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jul 03 09:57:08 mediaplayer volumio[946]: info: VolumeController:: Volume=76 Mute =false Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreStateMachine::pushState Jul 03 09:57:08 mediaplayer volumio[946]: info: CorePlayQueue::getTrack 0 Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::volumioPushState Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreStateMachine::updateTrackBlock Jul 03 09:57:08 mediaplayer volumio[946]: info: CorePlayQueue::getTrackBlock Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::volumioRetrievevolume Jul 03 09:57:08 mediaplayer volumio[946]: info: Reloading queue from file Jul 03 09:57:08 mediaplayer volumio[946]: info: Setting Device type: Raspberry PI Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreStateMachine::setRepeat true single undefined Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreStateMachine::pushState Jul 03 09:57:08 mediaplayer volumio[946]: info: CorePlayQueue::getTrack 0 Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::volumioPushState Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreStateMachine::setRandom true Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreStateMachine::pushState Jul 03 09:57:08 mediaplayer volumio[946]: info: CorePlayQueue::getTrack 0 Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::volumioPushState Jul 03 09:57:08 mediaplayer volumio[946]: info: Listing playlists Jul 03 09:57:08 mediaplayer volumio[946]: info: Listing playlists Jul 03 09:57:08 mediaplayer volumio[946]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jul 03 09:57:08 mediaplayer volumio[946]: info: USB Boot Capable - System SBC Revision found in cpuinfo: a03111 Jul 03 09:57:08 mediaplayer volumio[946]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jul 03 09:57:08 mediaplayer volumio[946]: info: VolumeController:: Volume=76 Mute =false Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreStateMachine::pushState Jul 03 09:57:08 mediaplayer volumio[946]: info: CorePlayQueue::getTrack 0 Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::volumioPushState Jul 03 09:57:08 mediaplayer volumio[946]: info: Discovery: adding e006a035-3ade-440f-88ce-8198758a13d3 Jul 03 09:57:08 mediaplayer volumio[946]: info: Discovery: Found device Mediaplayer Jul 03 09:57:08 mediaplayer volumio[946]: info: CoreCommandRouter::volumioGetState Jul 03 09:57:08 mediaplayer volumio[946]: info: CorePlayQueue::getTrack 0 Jul 03 09:57:08 mediaplayer volumio[946]: info: Completed loading Core Plugins Jul 03 09:57:08 mediaplayer volumio[946]: info: Preparing to generate the ALSA configuration file Jul 03 09:57:08 mediaplayer volumio[946]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jul 03 09:57:08 mediaplayer volumio[946]: info: Reading ALSA contributions from plugins. Jul 03 09:57:08 mediaplayer volumio[946]: info: Asound.conf file unchanged, so no further update is needed Jul 03 09:57:08 mediaplayer volumio[946]: info: Output device has changed, restarting MPD Jul 03 09:57:09 mediaplayer volumio[946]: info: Output device has changed, restarting Shairport Sync Jul 03 09:57:09 mediaplayer sudo[1196]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 09:57:09 mediaplayer sudo[1196]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:09 mediaplayer sudo[1196]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:09 mediaplayer sudo[1198]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 03 09:57:09 mediaplayer sudo[1198]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:09 mediaplayer systemd[1]: Stopping Music Player Daemon... Jul 03 09:57:09 mediaplayer volumio[946]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 03 09:57:09 mediaplayer volumio[946]: info: ___________ START PLUGINS ___________ Jul 03 09:57:09 mediaplayer volumio[946]: info: ControllerMpd::onStart: Initializing MPD Jul 03 09:57:09 mediaplayer volumio[946]: info: Creating MPD Configuration file Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 03 09:57:09 mediaplayer volumio[946]: info: [1751529429083] CoreMusicLibrary::Adding element Media Servers Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 03 09:57:09 mediaplayer sudo[1205]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 03 09:57:09 mediaplayer sudo[1205]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:09 mediaplayer sudo[1207]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 03 09:57:09 mediaplayer sudo[1207]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:09 mediaplayer sudo[1205]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 09:57:09 mediaplayer volumio[946]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 09:57:09 mediaplayer systemd[1]: mpd.service: Succeeded. Jul 03 09:57:09 mediaplayer systemd[1]: Stopped Music Player Daemon. Jul 03 09:57:09 mediaplayer volumio[946]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 03 09:57:09 mediaplayer volumio[946]: info: [1751529429168] CoreMusicLibrary::Adding element Last_100 Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 03 09:57:09 mediaplayer volumio[946]: info: [1751529429170] CoreMusicLibrary::Adding element Webradio Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 03 09:57:09 mediaplayer volumio[946]: info: Initializing BBC Radios Jul 03 09:57:09 mediaplayer systemd[1]: Starting Music Player Daemon... Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 09:57:09 mediaplayer volumio[946]: info: Creating Spotify config file Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:09 mediaplayer sudo[1214]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 03 09:57:09 mediaplayer sudo[1214]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:09 mediaplayer sudo[1214]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:09 mediaplayer volumio[946]: info: [now-playing] ConfigUpdater: config is up to date. Jul 03 09:57:09 mediaplayer volumio[946]: info: Loading i18n strings for locale en Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:09 mediaplayer volumio[946]: info: FusionDsp - mixtype--------------------- Hardware Jul 03 09:57:09 mediaplayer volumio[946]: info: Loading i18n strings for locale en Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 03 09:57:09 mediaplayer volumio[946]: info: Volumio Calling Home Jul 03 09:57:09 mediaplayer volumio[946]: info: Preparing to generate the ALSA configuration file Jul 03 09:57:09 mediaplayer sudo[1233]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Jul 03 09:57:09 mediaplayer sudo[1233]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:09 mediaplayer sudo[1235]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Jul 03 09:57:09 mediaplayer sudo[1235]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:09 mediaplayer sudo[1238]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Jul 03 09:57:09 mediaplayer sudo[1238]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:09 mediaplayer volumio[946]: info: [now-playing] App is listening on port 4004. Jul 03 09:57:09 mediaplayer systemd[1]: Reloading. Jul 03 09:57:09 mediaplayer sh[471]: timed out Jul 03 09:57:09 mediaplayer dhcpcd[523]: timed out Jul 03 09:57:09 mediaplayer volumio[946]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Jul 03 09:57:09 mediaplayer sh[471]: dhcpcd exited Jul 03 09:57:09 mediaplayer dhcpcd[523]: dhcpcd exited Jul 03 09:57:09 mediaplayer sh[471]: ifup: failed to bring up eth0 Jul 03 09:57:09 mediaplayer volumio[946]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jul 03 09:57:09 mediaplayer volumio[946]: info: Reading ALSA contributions from plugins. Jul 03 09:57:09 mediaplayer volumio[946]: error: touch_display: Error detecting backlight interface: Error: ENOENT: no such file or directory, scandir '/sys/class/backlight/' Jul 03 09:57:09 mediaplayer volumio[946]: info: MPD Permissions set Jul 03 09:57:09 mediaplayer volumio[946]: info: MPD Permissions set Jul 03 09:57:09 mediaplayer volumio[946]: info: Volumio called home Jul 03 09:57:09 mediaplayer volumio[946]: info: Spotify config file written Jul 03 09:57:09 mediaplayer volumio[946]: 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 03 09:57:09 mediaplayer sudo[1243]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jul 03 09:57:09 mediaplayer sudo[1243]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:09 mediaplayer volumio[946]: info: No need to fix Spotify hosts Jul 03 09:57:09 mediaplayer volumio[946]: info: touch_display: No Raspberry Pi Foundation touch screen detected. Jul 03 09:57:09 mediaplayer systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Jul 03 09:57:09 mediaplayer sudo[1267]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Jul 03 09:57:09 mediaplayer sudo[1267]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:09 mediaplayer sudo[1267]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:09 mediaplayer volumio[946]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Jul 03 09:57:09 mediaplayer volumio[946]: info: Starting Shairport Sync Jul 03 09:57:09 mediaplayer volumio[946]: info: Starting Shairport Sync Jul 03 09:57:09 mediaplayer sudo[1270]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 03 09:57:09 mediaplayer sudo[1270]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:09 mediaplayer volumio[946]: info: Starting Shairport Sync Jul 03 09:57:09 mediaplayer sudo[1273]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 03 09:57:09 mediaplayer sudo[1273]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:09 mediaplayer volumio[946]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jul 03 09:57:09 mediaplayer sudo[1275]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 03 09:57:09 mediaplayer sudo[1275]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::volumioGetState Jul 03 09:57:09 mediaplayer volumio[946]: info: CorePlayQueue::getTrack 0 Jul 03 09:57:09 mediaplayer volumio[946]: info: Asound.conf file unchanged, so no further update is needed Jul 03 09:57:09 mediaplayer volumio[946]: info: Output device has changed, restarting MPD Jul 03 09:57:09 mediaplayer systemd[1]: ifup@eth0.service: Current command vanished from the unit file, execution of the command list won't be resumed. Jul 03 09:57:09 mediaplayer volumio[946]: info: Output device has changed, restarting Shairport Sync Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:09 mediaplayer sudo[1279]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 03 09:57:09 mediaplayer sudo[1279]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:09 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 09:57:09 mediaplayer sudo[1279]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:10 mediaplayer sudo[1281]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 03 09:57:10 mediaplayer sudo[1281]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:10 mediaplayer volumio[946]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 03 09:57:10 mediaplayer volumio[946]: info: MPD Permissions set Jul 03 09:57:10 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:10 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:10 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:10 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:10 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:10 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:10 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:10 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:10 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 09:57:10 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:10 mediaplayer volumio[946]: info: Starting Shairport Sync Jul 03 09:57:10 mediaplayer sudo[1292]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 03 09:57:10 mediaplayer sudo[1292]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:10 mediaplayer mpd[1228]: Jul 03 09:57 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 03 09:57:10 mediaplayer systemd[1]: Started Music Player Daemon. Jul 03 09:57:10 mediaplayer systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Jul 03 09:57:10 mediaplayer systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Jul 03 09:57:10 mediaplayer sudo[1207]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:10 mediaplayer sudo[1198]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:10 mediaplayer sudo[1238]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:10 mediaplayer systemd[1]: Reloading. Jul 03 09:57:10 mediaplayer volumio[946]: info: touch_display: systemctl daemon-reload succeeded. Jul 03 09:57:10 mediaplayer sudo[1299]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Jul 03 09:57:10 mediaplayer sudo[1299]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:10 mediaplayer volumio[946]: error: MPD error: The expression evaluated to a falsy value: Jul 03 09:57:10 mediaplayer volumio[946]: assert.ok(self.idling) Jul 03 09:57:10 mediaplayer volumio[946]: error: The expression evaluated to a falsy value: Jul 03 09:57:10 mediaplayer volumio[946]: assert.ok(self.idling) Jul 03 09:57:10 mediaplayer volumio[946]: info: MPD running with PID1228 Jul 03 09:57:10 mediaplayer volumio[946]: ,establishing connection Jul 03 09:57:10 mediaplayer volumio[946]: error: updateQueue error: null Jul 03 09:57:10 mediaplayer volumio[946]: error: updateQueue error: null Jul 03 09:57:10 mediaplayer systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Jul 03 09:57:10 mediaplayer sudo[1235]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:10 mediaplayer volumio[946]: info: touch_display: systemctl disable getty@tty1.service succeeded. Jul 03 09:57:10 mediaplayer systemd[1]: Started Volumio Kiosk. Jul 03 09:57:10 mediaplayer systemd[1]: Stopping Music Player Daemon... Jul 03 09:57:10 mediaplayer systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jul 03 09:57:10 mediaplayer systemd[1]: Started go-librespot Daemon. Jul 03 09:57:10 mediaplayer sudo[1243]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:10 mediaplayer go-librespot[1316]: go-librespot daemon starting... Jul 03 09:57:10 mediaplayer systemd[1]: shairport-sync.service: Succeeded. Jul 03 09:57:10 mediaplayer systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jul 03 09:57:10 mediaplayer systemd[1]: mpd.service: Succeeded. Jul 03 09:57:10 mediaplayer systemd[1]: Stopped Music Player Daemon. Jul 03 09:57:10 mediaplayer sudo[1299]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:10 mediaplayer volumio[946]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Jul 03 09:57:10 mediaplayer volumio[946]: info: touch_display: Volumio Kiosk started. Jul 03 09:57:10 mediaplayer sudo[1233]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:10 mediaplayer volumio[946]: info: CoreCommandRouter::volumioGetState Jul 03 09:57:10 mediaplayer volumio[946]: info: CorePlayQueue::getTrack 0 Jul 03 09:57:10 mediaplayer volumio[946]: info: Completed starting Core Plugins Jul 03 09:57:10 mediaplayer volumio[946]: info: ------------------------------------------- Jul 03 09:57:10 mediaplayer volumio[946]: info: ----- MyVolumio plugins startup ---- Jul 03 09:57:10 mediaplayer volumio[946]: info: ------------------------------------------- Jul 03 09:57:10 mediaplayer volumio[946]: info: [MyVolumio PluginManager] Fetching plans data.... Jul 03 09:57:10 mediaplayer systemd[1]: Starting Music Player Daemon... Jul 03 09:57:10 mediaplayer systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 03 09:57:10 mediaplayer sudo[1273]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:10 mediaplayer sudo[1275]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:10 mediaplayer sudo[1292]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:10 mediaplayer sudo[1270]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:10 mediaplayer volumio[946]: info: CoreCommandRouter::volumioGetState Jul 03 09:57:10 mediaplayer volumio[946]: info: CorePlayQueue::getTrack 0 Jul 03 09:57:10 mediaplayer volumio[946]: info: Shairport-Sync Started Jul 03 09:57:10 mediaplayer volumio[946]: Error adding Membership: Error: addMembership EINVAL Jul 03 09:57:10 mediaplayer volumio[946]: info: Shairport-Sync Started Jul 03 09:57:10 mediaplayer volumio[946]: info: touch_display: systemctl stop getty@tty1.service succeeded. Jul 03 09:57:10 mediaplayer volumio[946]: info: Shairport-Sync Started Jul 03 09:57:10 mediaplayer volumio[946]: info: Shairport-Sync Started Jul 03 09:57:10 mediaplayer volumio[946]: info: touch_display: X display number found: 0 Jul 03 09:57:11 mediaplayer sudo[1335]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 03 09:57:11 mediaplayer sudo[1335]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:11 mediaplayer sudo[1335]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:11 mediaplayer volumio[946]: info: touch_display: X display number found: 0 Jul 03 09:57:11 mediaplayer startx[1315]: X.Org X Server 1.20.4 Jul 03 09:57:11 mediaplayer startx[1315]: X Protocol Version 11, Revision 0 Jul 03 09:57:11 mediaplayer startx[1315]: Build Operating System: Linux 5.4.0-109-generic armv8l Raspbian Jul 03 09:57:11 mediaplayer startx[1315]: Current Operating System: Linux mediaplayer 6.6.62-v7l+ #1816 SMP Mon Nov 18 15:33:33 GMT 2024 armv7l Jul 03 09:57:11 mediaplayer startx[1315]: Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_headphones=0 cgroup_disable=memory numa_policy=interleave snd_bcm2835.enable_headphones=1 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=1024 bcm2708_fb.fbheight=600 bcm2708_fb.fbswap=1 smsc95xx.macaddr=DC:A6:32:3D:87:D8 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 splash plymouth.ignore-serial-consoles dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0xF dwc_otg.nak_holdoff=1 quiet console=ttyS0,115200 console=tty1 imgpart=UUID=31894860-154d-4623-adeb-3744ffaa6b75 imgfile=/volumio_current.sqsh bootpart=UUID=8E61-2966 datapart=UUID=ddd2acb8-eb82-4115-8903-a4448dfe67a8 uuidconfig=cmdline.txt pcie_aspm=off pci=pcie_bus_safe rootwait bootdelay=7 logo.nologo vt.global_cursor_default=0 net.ifnames=0 snd-bcm2835.enable_compat_alsa= snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 loglevel=0 nodebug use_kmsg=no Jul 03 09:57:11 mediaplayer startx[1315]: Build Date: 04 April 2023 07:50:56AM Jul 03 09:57:11 mediaplayer startx[1315]: xorg-server 2:1.20.4-1+rpt4+deb10u9 (https://www.debian.org/support) Jul 03 09:57:11 mediaplayer startx[1315]: Current version of pixman: 0.36.0 Jul 03 09:57:11 mediaplayer startx[1315]: Before reporting problems, check http://wiki.x.org Jul 03 09:57:11 mediaplayer startx[1315]: to make sure that you have the latest version. Jul 03 09:57:11 mediaplayer startx[1315]: Markers: (--) probed, (**) from config file, (==) default setting, Jul 03 09:57:11 mediaplayer startx[1315]: (++) from command line, (!!) notice, (II) informational, Jul 03 09:57:11 mediaplayer startx[1315]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Jul 03 09:57:11 mediaplayer startx[1315]: (==) Log file: "/var/log/Xorg.0.log", Time: Thu Jul 3 09:57:11 2025 Jul 03 09:57:11 mediaplayer startx[1315]: (==) Using config directory: "/etc/X11/xorg.conf.d" Jul 03 09:57:11 mediaplayer startx[1315]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Jul 03 09:57:11 mediaplayer volumio[946]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Jul 03 09:57:11 mediaplayer volumio[946]: info: touch_display: X display number found: 0 Jul 03 09:57:11 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:11+02:00" level=info msg="running go-librespot 0.2.0" Jul 03 09:57:11 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:11+02:00" level=debug msg="app state loaded" Jul 03 09:57:11 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:11+02:00" level=debug msg="stored credentials not found" Jul 03 09:57:11 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:11+02:00" level=info msg="api server listening on 127.0.0.1:9879" Jul 03 09:57:11 mediaplayer volumio[946]: info: camilladsp service started and running in background, instance 1 Jul 03 09:57:11 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 09:57:11 mediaplayer systemd[1]: systemd-hostnamed.service: Succeeded. Jul 03 09:57:11 mediaplayer volumio[946]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA Jul 03 09:57:11 mediaplayer volumio[946]: info: FusionDsp loaded Jul 03 09:57:11 mediaplayer volumio[946]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 03 09:57:11 mediaplayer sudo[1371]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jul 03 09:57:11 mediaplayer sudo[1371]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:11 mediaplayer volumio[946]: info: FusionDsp - Reporting Fusion DSP Enabled Jul 03 09:57:11 mediaplayer volumio[946]: info: Adding Signal Path Element [object Object] Jul 03 09:57:11 mediaplayer volumio[946]: info: Adding fusiondspeq DSP Signal Path Element Jul 03 09:57:11 mediaplayer volumio[946]: info: FusionDsp - ---- installed callbackRead Jul 03 09:57:11 mediaplayer volumio[946]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jul 03 09:57:11 mediaplayer volumio[946]: error: FusionDsp - WebSocket error: [object Object] Jul 03 09:57:11 mediaplayer volumio[946]: 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 03 09:57:11 mediaplayer systemd[1]: Started FusionDsp Daemon. Jul 03 09:57:11 mediaplayer sudo[1371]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:11 mediaplayer mpd[1352]: Jul 03 09:57 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 03 09:57:11 mediaplayer systemd[1]: Started Music Player Daemon. Jul 03 09:57:11 mediaplayer sudo[1281]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:11 mediaplayer volumio[946]: error: updateQueue error: null Jul 03 09:57:11 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:11+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jul 03 09:57:11 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:11+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jul 03 09:57:11 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:11+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jul 03 09:57:11 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:11+02:00" level=info msg="zeroconf server listening on port 42069" Jul 03 09:57:12 mediaplayer volumio[946]: info: CoreCommandRouter::volumioGetState Jul 03 09:57:12 mediaplayer volumio[946]: info: CorePlayQueue::getTrack 0 Jul 03 09:57:12 mediaplayer volumio[946]: info: touch_display: Setting screensaver timeout to 120 seconds. Jul 03 09:57:13 mediaplayer sudo[1458]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 03 09:57:13 mediaplayer sudo[1458]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:13 mediaplayer sudo[1458]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:13 mediaplayer sudo[1460]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 03 09:57:13 mediaplayer sudo[1460]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:13 mediaplayer sudo[1460]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:13 mediaplayer sudo[1464]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jul 03 09:57:13 mediaplayer sudo[1464]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 09:57:13 mediaplayer volumio[946]: info: go-librespot daemon successfully initialized Jul 03 09:57:13 mediaplayer systemd[1]: Started UPnP Renderer front-end to MPD. Jul 03 09:57:13 mediaplayer sudo[1464]: pam_unix(sudo:session): session closed for user root Jul 03 09:57:13 mediaplayer volumio[946]: info: Upmpdcli Daemon Started Jul 03 09:57:14 mediaplayer volumio[1466]: Generating RSA private key, 4096 bit long modulus (2 primes) Jul 03 09:57:14 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:14+02:00" level=debug msg="obtained new client token: AACJhAMCjnaD7CCS2BNdBP3Oo3f7wmZYt74Y6Gc6dbNWPdyRDiN6YwWhXVE0jqTVa7lMMqrtl0SfcQ5j/lQomss0KYz2ufHQcagmX5BORQr7ArUi6Rz30TTikF+2lN3p71FHJh1egOnvBfP+8UAoAtu28enj8HLIMtH5+lxZjh7FVHfk55pUK8X9SRrl+WpbPQSO2r62YkRqbU1EN7TzWmnbzdA9l4LPjNExJ0ij1tff2xheExZAzIZ3" Jul 03 09:57:14 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:14+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jul 03 09:57:14 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:14+02:00" level=debug msg="completed keyexchange" Jul 03 09:57:14 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:14+02:00" level=debug msg="completed challenge" Jul 03 09:57:14 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:14+02:00" level=info msg="authenticated AP as la1710" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=info msg="authenticated Login5 as la1710" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=info msg="accepted zeroconf user la1710 from STARKSTROM_MB" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="dealer connection opened" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=trace msg="starting accesspoint recv loop" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=trace msg="starting dealer recv loop" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=trace msg="received accesspoint ping" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="received connection id: NDJiYzc5OTEtN2ZjMy00M2QzLTk0Y2ItZTRiMmNiMTNlMjQ2K2RlYWxlcit0Y3A6Ly8wYWIxNTEzYy5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArQTVBN0FDNjgxNjA0RUQ4OTJDNTJGMkUwNkUwQ0YyMTFBQ0JFRkQ5MkUxQzNGQTkwQjM1RkYxRjdBODI1MTg5OA==" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=trace msg="received accesspoint pong ack" Jul 03 09:57:15 mediaplayer volumio[946]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="put connect state because NEW_DEVICE" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="handling transfer player command from 477495c289e5cf4a29bc48e105b1fc4e658c8fed" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:5GyZDhvVLRUL3DEwzukjtU" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=trace msg="fetched new page 0 with 206 items (list: 206)" uri="spotify:playlist:5GyZDhvVLRUL3DEwzukjtU" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="loading track (paused: true, position: 1ms)" uri="spotify:track:0ntQJM78wzOLVeCUAW7Y45" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=trace msg="emitting websocket event: will_play" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="selected format OGG_VORBIS_320 (61fb4e8b232b44cd185a768707431ca03af675bd)" uri="spotify:track:0ntQJM78wzOLVeCUAW7Y45" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="requested aes key for file 61fb4e8b232b44cd185a768707431ca03af675bd, gid: 0ntQJM78wzOLVeCUAW7Y45" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1328" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="fetched first chunk of 15, total size is 7361296 bytes" uri="spotify:track:0ntQJM78wzOLVeCUAW7Y45" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:0ntQJM78wzOLVeCUAW7Y45" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="created new output device" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=info msg="loaded track \"Sex on Fire\" (paused: true, position: 1ms, duration: 203346ms, prefetched: false)" uri="spotify:track:0ntQJM78wzOLVeCUAW7Y45" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="fetched chunk 1/14, size: 524288" uri="spotify:track:0ntQJM78wzOLVeCUAW7Y45" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=trace msg="emitting websocket event: metadata" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=trace msg="emitting websocket event: active" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="sending successful reply for dealer request" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="fetched chunk 3/14, size: 524288" uri="spotify:track:0ntQJM78wzOLVeCUAW7Y45" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1110" Jul 03 09:57:15 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:15+02:00" level=debug msg="fetched chunk 2/14, size: 524288" uri="spotify:track:0ntQJM78wzOLVeCUAW7Y45" Jul 03 09:57:16 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:16+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 03 09:57:16 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:16+02:00" level=trace msg="emitting websocket event: paused" Jul 03 09:57:16 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:16+02:00" level=debug msg="handling resume player command from 477495c289e5cf4a29bc48e105b1fc4e658c8fed" Jul 03 09:57:16 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:16+02:00" level=debug msg="vorbis: corrupt or missing data in bitstream" uri="spotify:track:0ntQJM78wzOLVeCUAW7Y45" Jul 03 09:57:16 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:16+02:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:0ntQJM78wzOLVeCUAW7Y45" Jul 03 09:57:16 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:16+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" Jul 03 09:57:16 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:16+02:00" level=debug msg="resume track at 0ms" Jul 03 09:57:16 mediaplayer volumio[946]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jul 03 09:57:16 mediaplayer volumio[946]: info: FusionDsp - ---- read samplerate from file: 44100 Jul 03 09:57:16 mediaplayer volumio[946]: info: camilladsp stopping service pid 1365... Jul 03 09:57:16 mediaplayer kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=-11) Jul 03 09:57:16 mediaplayer volumio[946]: info: camilladsp service terminated, instance 1 Jul 03 09:57:16 mediaplayer volumio[946]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jul 03 09:57:16 mediaplayer volumio[946]: info: camilladsp service started and running in background, instance 1 Jul 03 09:57:16 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:16+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 03 09:57:16 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:16+02:00" level=trace msg="scheduling prefetch in 173s" Jul 03 09:57:16 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:16+02:00" level=debug msg="sending successful reply for dealer request" Jul 03 09:57:16 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:16+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 03 09:57:16 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:16+02:00" level=trace msg="emitting websocket event: playing" Jul 03 09:57:16 mediaplayer volumio[946]: info: CoreCommandRouter::volumioGetState Jul 03 09:57:16 mediaplayer volumio[946]: info: CorePlayQueue::getTrack 0 Jul 03 09:57:16 mediaplayer volumio[946]: info: Initializing connection to go-librespot Websocket Jul 03 09:57:16 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:16+02:00" level=debug msg="new websocket client" Jul 03 09:57:16 mediaplayer volumio[946]: info: Connection to go-librespot Websocket established Jul 03 09:57:17 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:17+02:00" level=debug msg="handling play player command from 477495c289e5cf4a29bc48e105b1fc4e658c8fed" Jul 03 09:57:17 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:17+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZF1E8O2zJWMfdLIW" Jul 03 09:57:17 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:17+02:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:playlist:37i9dQZF1E8O2zJWMfdLIW" Jul 03 09:57:17 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:17+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:52KmC88JozxOuGraFXE43C" Jul 03 09:57:17 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:17+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 162" Jul 03 09:57:18 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:18+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 03 09:57:18 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:18+02:00" level=trace msg="emitting websocket event: will_play" Jul 03 09:57:18 mediaplayer volumio[946]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:52KmC88JozxOuGraFXE43C","play_origin":"playlist"}} Jul 03 09:57:18 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:18+02:00" level=debug msg="selected format OGG_VORBIS_320 (5e5bd30e6a9b8a806d28ba66cab9255400a45648)" uri="spotify:track:52KmC88JozxOuGraFXE43C" Jul 03 09:57:18 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:18+02:00" level=debug msg="requested aes key for file 5e5bd30e6a9b8a806d28ba66cab9255400a45648, gid: 52KmC88JozxOuGraFXE43C" Jul 03 09:57:18 mediaplayer volumio-remote-updater[590]: [2025-07-03 09:57:18] [connect] Successful connection Jul 03 09:57:18 mediaplayer volumio-remote-updater[590]: [2025-07-03 09:57:18] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1751529438 101 Jul 03 09:57:18 mediaplayer volumio[946]: 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: 4 Jul 03 09:57:18 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:18+02:00" level=debug msg="fetched first chunk of 13, total size is 6767128 bytes" uri="spotify:track:52KmC88JozxOuGraFXE43C" Jul 03 09:57:18 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:18+02:00" level=info msg="loaded track \"2000er\" (paused: false, position: 0ms, duration: 183573ms, prefetched: false)" uri="spotify:track:52KmC88JozxOuGraFXE43C" Jul 03 09:57:18 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:18+02:00" level=debug msg="fetched chunk 1/12, size: 524288" uri="spotify:track:52KmC88JozxOuGraFXE43C" Jul 03 09:57:18 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:18+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 03 09:57:18 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:18+02:00" level=trace msg="scheduling prefetch in 153s" Jul 03 09:57:18 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:18+02:00" level=trace msg="emitting websocket event: metadata" Jul 03 09:57:18 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:18+02:00" level=debug msg="sending successful reply for dealer request" Jul 03 09:57:18 mediaplayer volumio[946]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:52KmC88JozxOuGraFXE43C","name":"2000er","artist_names":["01099","Miksu / Macloud"],"album_name":"Altbau","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0202a51d326fec04165386738f","position":0,"duration":183573,"release_date":"year:2022 month:3 day:25","track_number":5,"disc_number":1}} Jul 03 09:57:18 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:18+02:00" level=debug msg="skipping dealer message" uri=playback-settings/content-settings-update Jul 03 09:57:18 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:18+02:00" level=debug msg="fetched chunk 3/12, size: 524288" uri="spotify:track:52KmC88JozxOuGraFXE43C" Jul 03 09:57:18 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:18+02:00" level=debug msg="fetched chunk 2/12, size: 524288" uri="spotify:track:52KmC88JozxOuGraFXE43C" Jul 03 09:57:18 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:18+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 03 09:57:18 mediaplayer go-librespot[1316]: time="2025-07-03T09:57:18+02:00" level=trace msg="emitting websocket event: playing" Jul 03 09:57:18 mediaplayer volumio[946]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:52KmC88JozxOuGraFXE43C","play_origin":"playlist"}} Jul 03 09:57:18 mediaplayer volumio[946]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 03 09:57:18 mediaplayer volumio[946]: TypeError: Cannot read property 'service' of undefined Jul 03 09:57:18 mediaplayer volumio[946]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:340:50) Jul 03 09:57:18 mediaplayer volumio[946]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:266:18) Jul 03 09:57:18 mediaplayer volumio[946]: at WebSocket.message (/data/plugins/music_service/spop/index.js:193:14) Jul 03 09:57:18 mediaplayer volumio[946]: at WebSocket.emit (events.js:315:20) Jul 03 09:57:18 mediaplayer volumio[946]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Jul 03 09:57:18 mediaplayer volumio[946]: at Receiver.emit (events.js:315:20) Jul 03 09:57:18 mediaplayer volumio[946]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Jul 03 09:57:18 mediaplayer volumio[946]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Jul 03 09:57:18 mediaplayer volumio[946]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Jul 03 09:57:18 mediaplayer volumio[946]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Jul 03 09:57:18 mediaplayer volumio[946]: at writeOrBuffer (internal/streams/writable.js:358:12) Jul 03 09:57:18 mediaplayer volumio[946]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Jul 03 09:57:18 mediaplayer volumio[946]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Jul 03 09:57:18 mediaplayer volumio[946]: at Socket.emit (events.js:315:20) Jul 03 09:57:18 mediaplayer volumio[946]: at addChunk (internal/streams/readable.js:309:12) Jul 03 09:57:18 mediaplayer volumio[946]: at readableAddChunk (internal/streams/readable.js:284:9) Jul 03 09:57:18 mediaplayer volumio[946]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 03 09:57:18 mediaplayer sudo[1604]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-03 09:56 Jul 03 09:57:18 mediaplayer sudo[1604]: 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 10 Jun 2025 04:52:53 PM CEST" VOLUMIO_VERSION="3.816" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="a72866a0de4045751d03a035de6290e1"