-- Logs begin at Thu 2019-02-14 04:11:59 CST, end at Thu 2025-03-13 19:10:16 CDT. -- Mar 13 19:09:58 deskdac systemd-timedated[1010]: Changed local time to Thu Mar 13 19:09:58 2025 Mar 13 19:09:58 deskdac sudo[1008]: pam_unix(sudo:session): session closed for user root Mar 13 19:09:58 deskdac volumio-time-update[550]: volumio-time-update-util: System time updated successfully. Mar 13 19:09:58 deskdac systemd[1]: Started Volumio Time Update Utility. Mar 13 19:09:58 deskdac systemd[1]: Starting Daily apt download activities... Mar 13 19:09:58 deskdac systemd[1]: Starting Daily man-db regeneration... Mar 13 19:09:58 deskdac systemd[1]: man-db.service: Succeeded. Mar 13 19:09:58 deskdac systemd[1]: Started Daily man-db regeneration. Mar 13 19:09:58 deskdac volumio[978]: info: MYVOLUMIO Environment detected Mar 13 19:09:59 deskdac volumio[978]: info: Plugin folders cleanup Mar 13 19:09:59 deskdac volumio[978]: info: Scanning into folder /volumio/app/plugins/ Mar 13 19:09:59 deskdac volumio[978]: info: Scanning category audio_interface Mar 13 19:09:59 deskdac volumio[978]: info: Scanning category miscellanea Mar 13 19:09:59 deskdac volumio[978]: info: Scanning category music_service Mar 13 19:09:59 deskdac volumio[978]: info: Scanning category plugins.json Mar 13 19:09:59 deskdac volumio[978]: info: Scanning category system_controller Mar 13 19:09:59 deskdac volumio[978]: info: Scanning category user_interface Mar 13 19:09:59 deskdac volumio[978]: info: Scanning into folder /data/plugins/ Mar 13 19:09:59 deskdac volumio[978]: info: Scanning category music_service Mar 13 19:09:59 deskdac volumio[978]: info: Scanning category system_controller Mar 13 19:09:59 deskdac volumio[978]: info: Scanning category system_hardware Mar 13 19:09:59 deskdac volumio[978]: info: Scanning category user_interface Mar 13 19:09:59 deskdac volumio[978]: info: Plugin folders cleanup completed Mar 13 19:09:59 deskdac volumio[978]: info: ------------------------------------------- Mar 13 19:09:59 deskdac volumio[978]: info: ----- Core plugins startup ---- Mar 13 19:09:59 deskdac volumio[978]: info: ------------------------------------------- Mar 13 19:09:59 deskdac volumio[978]: info: Loading plugins from folder /volumio/app/plugins/ Mar 13 19:09:59 deskdac volumio[978]: info: Adding plugin upnp to MyMusic Plugins Mar 13 19:09:59 deskdac volumio[978]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 13 19:09:59 deskdac volumio[978]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 13 19:09:59 deskdac volumio[978]: info: Loading plugins from folder /data/plugins/ Mar 13 19:09:59 deskdac volumio[978]: info: Loading plugin "system"... Mar 13 19:09:59 deskdac volumio[978]: info: Loading plugin "appearance"... Mar 13 19:10:00 deskdac volumio-remote-updater[548]: [2025-03-13 19:10:00] [connect] Successful connection Mar 13 19:10:00 deskdac nmbd[765]: [2025/03/13 19:10:00.119468, 0] ../lib/util/become_daemon.c:138(daemon_ready) Mar 13 19:10:00 deskdac nmbd[765]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Mar 13 19:10:00 deskdac systemd[1]: Started Samba NMB Daemon. Mar 13 19:10:00 deskdac systemd[1]: Starting Samba Winbind Daemon... Mar 13 19:10:00 deskdac systemd[1]: apt-daily.service: Succeeded. Mar 13 19:10:00 deskdac systemd[1]: Started Daily apt download activities. Mar 13 19:10:00 deskdac systemd[1]: Starting Daily apt upgrade and clean activities... Mar 13 19:10:00 deskdac winbindd[1055]: [2025/03/13 19:10:00.394018, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Mar 13 19:10:00 deskdac winbindd[1055]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Mar 13 19:10:00 deskdac winbindd[1055]: [2025/03/13 19:10:00.409397, 0] ../lib/util/become_daemon.c:138(daemon_ready) Mar 13 19:10:00 deskdac winbindd[1055]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Mar 13 19:10:00 deskdac systemd[1]: Started Samba Winbind Daemon. Mar 13 19:10:00 deskdac systemd[1]: Starting Samba SMB Daemon... Mar 13 19:10:00 deskdac volumio[978]: info: Loading plugin "network"... Mar 13 19:10:00 deskdac volumio[978]: info: Refreshing Cached IP Addresses Mar 13 19:10:00 deskdac sudo[1091]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 13 19:10:00 deskdac sudo[1091]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:00 deskdac sudo[1093]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 13 19:10:00 deskdac sudo[1093]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:00 deskdac sudo[1091]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:00 deskdac sudo[1093]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:00 deskdac volumio[978]: info: Loading plugin "services"... Mar 13 19:10:00 deskdac volumio[978]: info: Loading plugin "alsa_controller"... Mar 13 19:10:00 deskdac sudo[1109]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 13 19:10:00 deskdac sudo[1109]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:00 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 19:10:00 deskdac volumio[978]: info: Loading plugin "wizard"... Mar 13 19:10:00 deskdac volumio[978]: info: Loading plugin "networkfs"... Mar 13 19:10:00 deskdac volumio[978]: info: Starting Udev Watcher for removable devices Mar 13 19:10:00 deskdac sudo[1129]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=eric,password=Root123!,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.160/music /mnt/NAS/NAS Mar 13 19:10:00 deskdac sudo[1129]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:00 deskdac volumio[978]: info: Ignoring mount for partition: boot Mar 13 19:10:00 deskdac volumio[978]: info: Ignoring mount for partition: volumio Mar 13 19:10:00 deskdac volumio[978]: info: Ignoring mount for partition: volumio_data Mar 13 19:10:00 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 19:10:00 deskdac volumio[978]: info: Loading plugin "volumio_command_line_client"... Mar 13 19:10:00 deskdac volumio[978]: info: Loading plugin "upnp"... Mar 13 19:10:00 deskdac volumio[978]: info: [1741911000830] Starting Upmpd Daemon Mar 13 19:10:00 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 19:10:00 deskdac volumio[978]: info: Loading plugin "my_music"... Mar 13 19:10:00 deskdac volumio[978]: info: Loading plugin "mpd"... Mar 13 19:10:00 deskdac smbd[1082]: [2025/03/13 19:10:00.875597, 0] ../lib/util/become_daemon.c:138(daemon_ready) Mar 13 19:10:00 deskdac smbd[1082]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Mar 13 19:10:00 deskdac systemd[1]: Started Samba SMB Daemon. Mar 13 19:10:00 deskdac systemd[1]: Reached target Multi-User System. Mar 13 19:10:00 deskdac systemd[1]: Reached target Graphical Interface. Mar 13 19:10:00 deskdac kernel: Key type cifs.spnego registered Mar 13 19:10:00 deskdac kernel: Key type cifs.idmap registered Mar 13 19:10:00 deskdac 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. Mar 13 19:10:00 deskdac kernel: CIFS: Attempting to mount //192.168.1.160/music Mar 13 19:10:00 deskdac systemd[1]: Starting Update UTMP about System Runlevel Changes... Mar 13 19:10:00 deskdac systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Mar 13 19:10:00 deskdac systemd[1]: Started Update UTMP about System Runlevel Changes. Mar 13 19:10:01 deskdac kernel: cryptd: max_cpu_qlen set to 1000 Mar 13 19:10:01 deskdac volumio[978]: info: Loading plugin "upnp_browser"... Mar 13 19:10:01 deskdac volumio[978]: info: Loading plugin "alarm-clock"... Mar 13 19:10:01 deskdac systemd[1]: apt-daily-upgrade.service: Succeeded. Mar 13 19:10:01 deskdac systemd[1]: Started Daily apt upgrade and clean activities. Mar 13 19:10:01 deskdac volumio[978]: info: Loading plugin "airplay_emulation"... Mar 13 19:10:01 deskdac volumio[978]: info: Starting Shairport Sync Mar 13 19:10:01 deskdac volumio[978]: info: Loading plugin "last_100"... Mar 13 19:10:01 deskdac volumio[978]: info: Loading plugin "webradio"... Mar 13 19:10:01 deskdac systemd[1]: Startup finished in 12.239s (kernel) + 28.760s (userspace) = 41.000s. Mar 13 19:10:01 deskdac volumio[978]: info: Loading plugin "i2s_dacs"... Mar 13 19:10:01 deskdac volumio[978]: info: Loading plugin "volumiodiscovery"... Mar 13 19:10:01 deskdac sudo[1129]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:01 deskdac volumio[978]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 13 19:10:01 deskdac volumio[978]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 19:10:01 deskdac volumio[978]: *** WARNING *** For more information see Mar 13 19:10:01 deskdac node[978]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 13 19:10:01 deskdac volumio[978]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 13 19:10:01 deskdac volumio[978]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 19:10:01 deskdac volumio[978]: *** WARNING *** For more information see Mar 13 19:10:01 deskdac node[978]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 19:10:01 deskdac node[978]: *** WARNING *** For more information see Mar 13 19:10:01 deskdac node[978]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 13 19:10:01 deskdac node[978]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 13 19:10:01 deskdac node[978]: *** WARNING *** For more information see Mar 13 19:10:01 deskdac volumio[978]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 13 19:10:01 deskdac volumio[978]: info: Discovery: Started advertising with name: DeskDAC Mar 13 19:10:01 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 13 19:10:01 deskdac volumio[978]: info: Loading plugin "spop"... Mar 13 19:10:02 deskdac volumio[978]: info: Loading plugin "outputs"... Mar 13 19:10:02 deskdac volumio[978]: info: Loading plugin "albumart"... Mar 13 19:10:03 deskdac volumio[978]: info: Plugin example_plugin is not enabled Mar 13 19:10:03 deskdac volumio[978]: info: Loading plugin "inputs"... Mar 13 19:10:03 deskdac volumio[978]: info: Loading plugin "updater_comm"... Mar 13 19:10:03 deskdac volumio[978]: info: Plugin mpdemulation is not enabled Mar 13 19:10:03 deskdac volumio[978]: info: Loading plugin "rest_api"... Mar 13 19:10:03 deskdac volumio[978]: info: Loading plugin "websocket"... Mar 13 19:10:03 deskdac volumio[978]: info: Starting Socket.io Server version 2.3.0 Mar 13 19:10:03 deskdac volumio[978]: info: Loading plugin "radio_paradise"... Mar 13 19:10:03 deskdac volumio[978]: Forking 3 albumart workers Mar 13 19:10:03 deskdac volumio[978]: info: Applying required configuration parameters for plugin radio_paradise Mar 13 19:10:03 deskdac volumio[978]: info: [1741911003462] [RadioParadise] API delay: 5 Mar 13 19:10:03 deskdac volumio[978]: info: Loading plugin "backup_restore"... Mar 13 19:10:03 deskdac volumio[978]: info: Applying required configuration parameters for plugin backup_restore Mar 13 19:10:03 deskdac volumio[978]: info: Loading plugin "rotaryencoder2"... Mar 13 19:10:03 deskdac volumio[978]: Starting albumart workers Mar 13 19:10:03 deskdac volumio[978]: Starting albumart workers Mar 13 19:10:03 deskdac volumio[978]: Starting albumart workers Mar 13 19:10:04 deskdac volumio[978]: info: Loading plugin "Systeminfo"... Mar 13 19:10:04 deskdac volumio[978]: info: Loading plugin "touch_display"... Mar 13 19:10:04 deskdac volumio[978]: info: Applying required configuration parameters for plugin touch_display Mar 13 19:10:04 deskdac sudo[1109]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:04 deskdac volumio[978]: info: Loading i18n strings for locale en Mar 13 19:10:04 deskdac volumio[978]: Updating browse sources language Mar 13 19:10:04 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::initPlayerControls Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 19:10:05 deskdac volumio[978]: Express server listening on port 3000 Mar 13 19:10:05 deskdac volumio[978]: [Metrics] WebUI: 7s 697.94ms Mar 13 19:10:05 deskdac volumio[978]: info: CoreStateMachine::resetVolumioState Mar 13 19:10:05 deskdac volumio[978]: info: CoreStateMachine::getcurrentVolume Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 19:10:05 deskdac volumio[978]: info: Volumio Network Manager: Network status updated: 2 Mar 13 19:10:05 deskdac volumio-remote-updater[548]: [2025-03-13 19:10:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1741911000 101 Mar 13 19:10:05 deskdac volumio[978]: 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 Mar 13 19:10:05 deskdac volumio[978]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 13 19:10:05 deskdac volumio[978]: info: Reloading queue from file Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 19:10:05 deskdac volumio[978]: info: VolumeController:: Volume=78 Mute =false Mar 13 19:10:05 deskdac volumio[978]: info: CoreStateMachine::pushState Mar 13 19:10:05 deskdac volumio[978]: info: CorePlayQueue::getTrack 0 Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::volumioPushState Mar 13 19:10:05 deskdac volumio[978]: info: CoreStateMachine::updateTrackBlock Mar 13 19:10:05 deskdac volumio[978]: info: CorePlayQueue::getTrackBlock Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::volumioRetrievevolume Mar 13 19:10:05 deskdac volumio[978]: info: CoreStateMachine::setRepeat false single undefined Mar 13 19:10:05 deskdac volumio[978]: info: CoreStateMachine::pushState Mar 13 19:10:05 deskdac volumio[978]: info: CorePlayQueue::getTrack 0 Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::volumioPushState Mar 13 19:10:05 deskdac volumio[978]: info: CoreStateMachine::setRandom false Mar 13 19:10:05 deskdac volumio[978]: info: CoreStateMachine::pushState Mar 13 19:10:05 deskdac volumio[978]: info: CorePlayQueue::getTrack 0 Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::volumioPushState Mar 13 19:10:05 deskdac volumio[978]: info: Setting Device type: Raspberry PI Mar 13 19:10:05 deskdac volumio[978]: info: Completed loading Core Plugins Mar 13 19:10:05 deskdac volumio[978]: info: Preparing to generate the ALSA configuration file Mar 13 19:10:05 deskdac volumio[978]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Mar 13 19:10:05 deskdac volumio[978]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03115 Mar 13 19:10:05 deskdac volumio[978]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Mar 13 19:10:05 deskdac volumio[978]: info: VolumeController:: Volume=78 Mute =false Mar 13 19:10:05 deskdac volumio[978]: info: CoreStateMachine::pushState Mar 13 19:10:05 deskdac volumio[978]: info: CorePlayQueue::getTrack 0 Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::volumioPushState Mar 13 19:10:05 deskdac volumio[978]: info: Asound.conf file unchanged, so no further update is needed Mar 13 19:10:05 deskdac volumio[978]: info: Output device has changed, restarting MPD Mar 13 19:10:05 deskdac volumio[978]: info: Output device has changed, restarting Shairport Sync Mar 13 19:10:05 deskdac sudo[1268]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:05 deskdac sudo[1268]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 19:10:05 deskdac sudo[1268]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:05 deskdac sudo[1270]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 13 19:10:05 deskdac sudo[1270]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:05 deskdac systemd[1]: Stopping Music Player Daemon... Mar 13 19:10:05 deskdac volumio[978]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 19:10:05 deskdac volumio[978]: info: ___________ START PLUGINS ___________ Mar 13 19:10:05 deskdac volumio[978]: info: ControllerMpd::onStart: Initializing MPD Mar 13 19:10:05 deskdac volumio[978]: info: Creating MPD Configuration file Mar 13 19:10:05 deskdac sudo[1277]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 13 19:10:05 deskdac sudo[1277]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 19:10:05 deskdac volumio[978]: info: [1741911005425] CoreMusicLibrary::Adding element Media Servers Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 19:10:05 deskdac sudo[1277]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:05 deskdac sudo[1279]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 13 19:10:05 deskdac sudo[1279]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 19:10:05 deskdac volumio[978]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 19:10:05 deskdac systemd[1]: mpd.service: Succeeded. Mar 13 19:10:05 deskdac systemd[1]: Stopped Music Player Daemon. Mar 13 19:10:05 deskdac volumio[978]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 19:10:05 deskdac volumio[978]: info: [1741911005511] CoreMusicLibrary::Adding element Last_100 Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 19:10:05 deskdac volumio[978]: info: [1741911005514] CoreMusicLibrary::Adding element Webradio Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 19:10:05 deskdac volumio[978]: info: Initializing BBC Radios Mar 13 19:10:05 deskdac systemd[1]: Starting Music Player Daemon... Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 19:10:05 deskdac volumio[978]: info: Creating Spotify config file Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:05 deskdac sudo[1286]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 13 19:10:05 deskdac sudo[1286]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:05 deskdac sudo[1286]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 19:10:05 deskdac volumio[978]: info: [1741911005633] CoreMusicLibrary::Adding element Radio Paradise Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 19:10:05 deskdac volumio[978]: Cannot find translation for source Radio Paradise Mar 13 19:10:05 deskdac systemd[1]: systemd-fsckd.service: Succeeded. Mar 13 19:10:05 deskdac volumio[978]: info: Loading i18n strings for locale en Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 13 19:10:05 deskdac volumio[978]: info: Volumio Calling Home Mar 13 19:10:05 deskdac sudo[1305]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay rotary-encoder pin_a=27 pin_b=22 relative_axis=true steps-per-period=2 Mar 13 19:10:05 deskdac sudo[1305]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:05 deskdac sudo[1308]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service Mar 13 19:10:05 deskdac sudo[1308]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:05 deskdac sudo[1310]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service Mar 13 19:10:05 deskdac sudo[1310]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:05 deskdac sudo[1314]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload Mar 13 19:10:05 deskdac sudo[1314]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:05 deskdac systemd[1]: Reloading. Mar 13 19:10:05 deskdac kernel: rotary-encoder rotary@1b: gray Mar 13 19:10:05 deskdac kernel: input: rotary@1b as /devices/platform/rotary@1b/input/input1 Mar 13 19:10:05 deskdac volumio[978]: info: Discovery: adding 8d0a8225-e5d8-4521-97ac-b274d3d4396f Mar 13 19:10:05 deskdac volumio[978]: info: Discovery: Found device DeskDAC Mar 13 19:10:05 deskdac volumio[978]: info: CoreCommandRouter::volumioGetState Mar 13 19:10:05 deskdac volumio[978]: info: CorePlayQueue::getTrack 0 Mar 13 19:10:05 deskdac sudo[1305]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:05 deskdac volumio[978]: info: touch_display: Backlight interface detected. Mar 13 19:10:06 deskdac volumio[978]: info: MPD Permissions set Mar 13 19:10:06 deskdac volumio[978]: info: MPD Permissions set Mar 13 19:10:06 deskdac volumio[978]: info: Spotify config file written Mar 13 19:10:06 deskdac systemd-udevd[1322]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Mar 13 19:10:06 deskdac sudo[1343]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 13 19:10:06 deskdac sudo[1343]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:06 deskdac volumio[978]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Mar 13 19:10:06 deskdac volumio[978]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 13 19:10:06 deskdac volumio[978]: info: No need to fix Spotify hosts Mar 13 19:10:06 deskdac 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. Mar 13 19:10:06 deskdac volumio[978]: info: Volumio called home Mar 13 19:10:06 deskdac sudo[1354]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+w /sys/class/backlight/rpi_backlight/brightness Mar 13 19:10:06 deskdac volumio[978]: info: touch_display: Raspberry Pi Foundation touch screen detected. Mar 13 19:10:06 deskdac sudo[1354]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:06 deskdac volumio[978]: info: Starting Shairport Sync Mar 13 19:10:06 deskdac sudo[1356]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf Mar 13 19:10:06 deskdac sudo[1354]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:06 deskdac sudo[1356]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:06 deskdac volumio[978]: info: Starting Shairport Sync Mar 13 19:10:06 deskdac sudo[1356]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:06 deskdac volumio[978]: info: Starting Shairport Sync Mar 13 19:10:06 deskdac systemd[1]: ifup@eth0.service: Current command vanished from the unit file, execution of the command list won't be resumed. Mar 13 19:10:06 deskdac sudo[1360]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 13 19:10:06 deskdac sudo[1360]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:06 deskdac sudo[1362]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 13 19:10:06 deskdac sudo[1362]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:06 deskdac sudo[1365]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 13 19:10:06 deskdac sudo[1365]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::volumioGetState Mar 13 19:10:06 deskdac volumio[978]: info: CorePlayQueue::getTrack 0 Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::volumioGetState Mar 13 19:10:06 deskdac volumio[978]: info: CorePlayQueue::getTrack 0 Mar 13 19:10:06 deskdac mpd[1300]: Mar 13 19:10 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 13 19:10:06 deskdac sudo[1310]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:06 deskdac volumio[978]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set. Mar 13 19:10:06 deskdac volumio[978]: info: touch_display: File permissions for backlight brightness control set. Mar 13 19:10:06 deskdac volumio[978]: info: touch_display: systemctl disable getty@tty1.service succeeded. Mar 13 19:10:06 deskdac systemd[1]: Started Music Player Daemon. Mar 13 19:10:06 deskdac sudo[1279]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:06 deskdac sudo[1270]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:06 deskdac volumio[978]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 13 19:10:06 deskdac volumio[978]: SPOTIFY: BQBVarTnFns_zfX351GUDiVsrWuSHHKG29S_a5aEKKtTWxCOPuNMRaTcs2c227ZbvvzwcUWJAqeHkuW8FKUv6eQKSy0xHjvy1REiBZQVPqLHRF2JPhEq4WZmNMjD5ZIDSIF2PGqzI4_L36AgkUopOzviL7H6cDnby0igkpWiW0GJQ2j3nuy4y0e7jceY8WKWiTooyokAkkpyXQUSIjqFzO_pZ8C9_2dgaXCQUqghgPRK0Pj3CMAXlybs39zYW1RYSVMNmsbZh8ftWOk Mar 13 19:10:06 deskdac volumio[978]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 13 19:10:06 deskdac volumio[978]: info: New Spotify access token = BQBVarTnFns_zfX351GUDiVsrWuSHHKG29S_a5aEKKtTWxCOPuNMRaTcs2c227ZbvvzwcUWJAqeHkuW8FKUv6eQKSy0xHjvy1REiBZQVPqLHRF2JPhEq4WZmNMjD5ZIDSIF2PGqzI4_L36AgkUopOzviL7H6cDnby0igkpWiW0GJQ2j3nuy4y0e7jceY8WKWiTooyokAkkpyXQUSIjqFzO_pZ8C9_2dgaXCQUqghgPRK0Pj3CMAXlybs39zYW1RYSVMNmsbZh8ftWOk Mar 13 19:10:06 deskdac volumio[978]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 13 19:10:06 deskdac systemd[1]: Reloading. Mar 13 19:10:06 deskdac sudo[1308]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:06 deskdac volumio[978]: info: touch_display: systemctl stop getty@tty1.service succeeded. Mar 13 19:10:06 deskdac volumio[978]: error: MPD error: The expression evaluated to a falsy value: Mar 13 19:10:06 deskdac volumio[978]: assert.ok(self.idling) Mar 13 19:10:06 deskdac volumio[978]: error: The expression evaluated to a falsy value: Mar 13 19:10:06 deskdac volumio[978]: assert.ok(self.idling) Mar 13 19:10:06 deskdac volumio[978]: error: updateQueue error: null Mar 13 19:10:06 deskdac volumio[978]: info: MPD running with PID1300 Mar 13 19:10:06 deskdac volumio[978]: ,establishing connection Mar 13 19:10:06 deskdac volumio[978]: error: updateQueue error: null Mar 13 19:10:06 deskdac 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. Mar 13 19:10:06 deskdac volumio[978]: SPOTIFY: User informations: {"country":"US","display_name":"Eric","email":"eric@halfsun.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/dcom222"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/dcom222","id":"dcom222","images":[],"product":"premium","type":"user","uri":"spotify:user:dcom222"} Mar 13 19:10:06 deskdac volumio[978]: info: Spotify Successfully logged in Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 13 19:10:06 deskdac volumio[978]: info: [1741911006924] CoreMusicLibrary::Adding element Spotify Mar 13 19:10:06 deskdac volumio[978]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 13 19:10:06 deskdac volumio[978]: Cannot find translation for source Radio Paradise Mar 13 19:10:06 deskdac volumio[978]: Cannot find translation for source Spotify Mar 13 19:10:07 deskdac sudo[1388]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay gpio-key gpio=25 active_low=1 gpio_pull=up keycode=20 Mar 13 19:10:07 deskdac kernel: input: button@19 as /devices/platform/button@19/input/input2 Mar 13 19:10:07 deskdac sudo[1388]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:07 deskdac sudo[1388]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:07 deskdac sudo[1314]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:07 deskdac volumio[978]: info: touch_display: systemctl daemon-reload succeeded. Mar 13 19:10:07 deskdac sudo[1398]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio-kiosk.service Mar 13 19:10:07 deskdac sudo[1398]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:07 deskdac systemd[1]: Started Volumio Kiosk. Mar 13 19:10:07 deskdac systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 13 19:10:07 deskdac systemd[1]: Started go-librespot Daemon. Mar 13 19:10:07 deskdac sudo[1343]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:07 deskdac systemd[1]: shairport-sync.service: Succeeded. Mar 13 19:10:07 deskdac systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 13 19:10:07 deskdac go-librespot[1402]: go-librespot daemon starting... Mar 13 19:10:07 deskdac systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 13 19:10:07 deskdac sudo[1360]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:07 deskdac sudo[1362]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:07 deskdac sudo[1365]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:07 deskdac sudo[1398]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:07 deskdac volumio[978]: info: Shairport-Sync Started Mar 13 19:10:07 deskdac volumio[978]: Error adding Membership: Error: addMembership EINVAL Mar 13 19:10:07 deskdac volumio[978]: info: Shairport-Sync Started Mar 13 19:10:07 deskdac volumio[978]: info: touch_display: systemctl start volumio-kiosk.service succeeded. Mar 13 19:10:07 deskdac volumio[978]: info: touch_display: Volumio Kiosk started. Mar 13 19:10:07 deskdac volumio[978]: info: CoreCommandRouter::volumioGetState Mar 13 19:10:07 deskdac volumio[978]: info: CorePlayQueue::getTrack 0 Mar 13 19:10:07 deskdac volumio[978]: info: CoreCommandRouter::volumioGetState Mar 13 19:10:07 deskdac volumio[978]: info: CorePlayQueue::getTrack 0 Mar 13 19:10:07 deskdac volumio[978]: info: Shairport-Sync Started Mar 13 19:10:07 deskdac volumio[978]: info: touch_display: X display number found: Mar 13 19:10:07 deskdac sh[504]: timed out Mar 13 19:10:07 deskdac dhcpcd[539]: timed out Mar 13 19:10:07 deskdac sh[504]: dhcpcd exited Mar 13 19:10:07 deskdac dhcpcd[539]: dhcpcd exited Mar 13 19:10:07 deskdac sh[504]: ifup: failed to bring up eth0 Mar 13 19:10:07 deskdac systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Mar 13 19:10:07 deskdac systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Mar 13 19:10:07 deskdac systemd-udevd[1322]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Mar 13 19:10:07 deskdac volumio[978]: info: touch_display: X display number found: 0 Mar 13 19:10:07 deskdac startx[1400]: X.Org X Server 1.20.4 Mar 13 19:10:07 deskdac startx[1400]: X Protocol Version 11, Revision 0 Mar 13 19:10:07 deskdac startx[1400]: Build Operating System: Linux 5.4.0-109-generic armv8l Raspbian Mar 13 19:10:07 deskdac startx[1400]: Current Operating System: Linux deskdac 6.6.62-v7l+ #1816 SMP Mon Nov 18 15:33:33 GMT 2024 armv7l Mar 13 19:10:07 deskdac startx[1400]: 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=800 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 smsc95xx.macaddr=D8:3A:DD:EC:84:74 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=af3faec2-9654-4fec-8791-d5638a5837ad imgfile=/volumio_current.sqsh bootpart=UUID=2E0A-AE55 datapart=UUID=660717eb-e471-4727-aac1-2c263938c365 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 Mar 13 19:10:07 deskdac startx[1400]: Build Date: 04 April 2023 07:50:56AM Mar 13 19:10:07 deskdac startx[1400]: xorg-server 2:1.20.4-1+rpt4+deb10u9 (https://www.debian.org/support) Mar 13 19:10:07 deskdac startx[1400]: Current version of pixman: 0.36.0 Mar 13 19:10:07 deskdac startx[1400]: Before reporting problems, check http://wiki.x.org Mar 13 19:10:07 deskdac startx[1400]: to make sure that you have the latest version. Mar 13 19:10:07 deskdac startx[1400]: Markers: (--) probed, (**) from config file, (==) default setting, Mar 13 19:10:07 deskdac startx[1400]: (++) from command line, (!!) notice, (II) informational, Mar 13 19:10:07 deskdac startx[1400]: (WW) warning, (EE) error, (NI) not implemented, (??) unknown. Mar 13 19:10:07 deskdac startx[1400]: (==) Log file: "/var/log/Xorg.0.log", Time: Thu Mar 13 19:10:07 2025 Mar 13 19:10:07 deskdac startx[1400]: (==) Using config directory: "/etc/X11/xorg.conf.d" Mar 13 19:10:07 deskdac startx[1400]: (==) Using system config directory "/usr/share/X11/xorg.conf.d" Mar 13 19:10:07 deskdac volumio[978]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Mar 13 19:10:07 deskdac volumio[978]: info: touch_display: X display number found: 0 Mar 13 19:10:07 deskdac go-librespot[1402]: time="2025-03-13T19:10:07-05:00" level=info msg="running go-librespot 0.2.0" Mar 13 19:10:07 deskdac go-librespot[1402]: time="2025-03-13T19:10:07-05:00" level=debug msg="app state loaded" Mar 13 19:10:07 deskdac go-librespot[1402]: time="2025-03-13T19:10:07-05:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=info msg="zeroconf server listening on port 44143" Mar 13 19:10:08 deskdac sudo[1446]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Mar 13 19:10:08 deskdac sudo[1446]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:08 deskdac sudo[1446]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=debug msg="obtained new client token: AACXcftL2qt5vEvPgESIRNC5CH4cJ+XieLaOWx9xqMDgRyTmoGS4wtKJqrFn/uAhD8mthTfpNuryjxT7JmpyAqzvQtnLC+TpESsScELaSu860rqp6XT+Z+Ks7zuuIlG3DTiJSrsS2aLMyXiNZEgANCyd3sOI2LS2dtJ4pRnXBRHBF0qUTyhz2viSBV5bUp8FyMQdm2uUbWQEkSONWLTZ+3puXQP3qadlM06CgdH2Osezp6jgZUrluA==" Mar 13 19:10:08 deskdac sudo[1450]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Mar 13 19:10:08 deskdac sudo[1450]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:08 deskdac sudo[1450]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:08 deskdac systemd[1]: systemd-hostnamed.service: Succeeded. Mar 13 19:10:08 deskdac volumio[978]: info: Completed starting Core Plugins Mar 13 19:10:08 deskdac volumio[978]: info: ------------------------------------------- Mar 13 19:10:08 deskdac volumio[978]: info: ----- MyVolumio plugins startup ---- Mar 13 19:10:08 deskdac volumio[978]: info: ------------------------------------------- Mar 13 19:10:08 deskdac volumio[978]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=debug msg="completed keyexchange" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=debug msg="completed challenge" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=info msg="authenticated AP as dcom222" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=info msg="authenticated Login5 as dcom222" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=debug msg="initializing zeroconf session, username: dcom222" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=debug msg="dealer connection opened" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=trace msg="starting accesspoint recv loop" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=trace msg="starting dealer recv loop" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=trace msg="received accesspoint ping" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=debug msg="received connection id: YzY3ODYwZjgtN2U0NC00ZWU3LThlNDctNDdlNzViYzVjMTA3K2RlYWxlcit0Y3A6Ly8wYWNiZmE0ZC5pcC5ndWUxLnNwb3RpZnkubmV0OjU3MDArQzJDQUYzOEE3MDk4QTIyOTc1NUY1ODQ2MjkwMTQ5RTZENzNFNTRFRDhBRkQyMEY0Qzg3Rjg2MTEzNTlGNjM0Nw==" Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=trace msg="received accesspoint pong ack" Mar 13 19:10:08 deskdac volumio[978]: info: CoreCommandRouter::volumioGetState Mar 13 19:10:08 deskdac volumio[978]: info: CorePlayQueue::getTrack 0 Mar 13 19:10:08 deskdac volumio[978]: info: touch_display: Setting screensaver timeout to 120 seconds. Mar 13 19:10:08 deskdac go-librespot[1402]: time="2025-03-13T19:10:08-05:00" level=debug msg="put connect state because NEW_DEVICE" Mar 13 19:10:10 deskdac volumio[978]: info: go-librespot daemon successfully initialized Mar 13 19:10:10 deskdac sudo[1553]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 13 19:10:10 deskdac sudo[1553]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:10 deskdac sudo[1555]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 13 19:10:10 deskdac sudo[1553]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:10 deskdac sudo[1555]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:10 deskdac sudo[1555]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:10 deskdac sudo[1559]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 13 19:10:10 deskdac sudo[1559]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 13 19:10:11 deskdac systemd[1]: Started UPnP Renderer front-end to MPD. Mar 13 19:10:11 deskdac sudo[1559]: pam_unix(sudo:session): session closed for user root Mar 13 19:10:11 deskdac volumio[978]: info: Upmpdcli Daemon Started Mar 13 19:10:11 deskdac volumio[1561]: Generating RSA private key, 4096 bit long modulus (2 primes) Mar 13 19:10:11 deskdac volumio[1561]: .....++++ Mar 13 19:10:11 deskdac volumio[978]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 13 19:10:11 deskdac volumio[978]: Cannot compose Albumart path Mar 13 19:10:11 deskdac volumio[978]: Cannot compose Albumart path Mar 13 19:10:13 deskdac volumio[978]: info: Initializing connection to go-librespot Websocket Mar 13 19:10:13 deskdac go-librespot[1402]: time="2025-03-13T19:10:13-05:00" level=debug msg="new websocket client" Mar 13 19:10:13 deskdac volumio[978]: info: Connection to go-librespot Websocket established Mar 13 19:10:14 deskdac go-librespot[1402]: time="2025-03-13T19:10:14-05:00" level=debug msg="handling transfer player command from 95d4c976173e0c6ca8788f4a612b9a7c922f7174" Mar 13 19:10:14 deskdac go-librespot[1402]: time="2025-03-13T19:10:14-05:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZF1EIXSTFdxWjggO" Mar 13 19:10:14 deskdac go-librespot[1402]: time="2025-03-13T19:10:14-05:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:playlist:37i9dQZF1EIXSTFdxWjggO" Mar 13 19:10:14 deskdac go-librespot[1402]: time="2025-03-13T19:10:14-05:00" level=debug msg="loading track (paused: false, position: 23373ms)" uri="spotify:track:5qFoUVRGE6dQuT3ogCF6OO" Mar 13 19:10:14 deskdac go-librespot[1402]: time="2025-03-13T19:10:14-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 13 19:10:14 deskdac go-librespot[1402]: time="2025-03-13T19:10:14-05:00" level=trace msg="emitting websocket event: will_play" Mar 13 19:10:14 deskdac volumio[978]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5qFoUVRGE6dQuT3ogCF6OO","play_origin":"playlist"}} Mar 13 19:10:14 deskdac go-librespot[1402]: time="2025-03-13T19:10:14-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Mar 13 19:10:14 deskdac go-librespot[1402]: time="2025-03-13T19:10:14-05:00" level=debug msg="selected format OGG_VORBIS_320 (841dcca090eee0fd15004fb89513a7d29e617896)" uri="spotify:track:5qFoUVRGE6dQuT3ogCF6OO" Mar 13 19:10:14 deskdac go-librespot[1402]: time="2025-03-13T19:10:14-05:00" level=debug msg="requested aes key for file 841dcca090eee0fd15004fb89513a7d29e617896, gid: 5qFoUVRGE6dQuT3ogCF6OO" Mar 13 19:10:14 deskdac go-librespot[1402]: time="2025-03-13T19:10:14-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1322" Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1105" Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=debug msg="fetched first chunk of 25, total size is 12712604 bytes" uri="spotify:track:5qFoUVRGE6dQuT3ogCF6OO" Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=debug msg="fetched chunk 1/24, size: 524288" uri="spotify:track:5qFoUVRGE6dQuT3ogCF6OO" Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=trace msg="seek to 23373ms (diff: 154ms, samples: 1030749, bytes: 914918)" uri="spotify:track:5qFoUVRGE6dQuT3ogCF6OO" Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=debug msg="created new output device" Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames" Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=info msg="loaded track \"Locomotive\" (paused: false, position: 23373ms, duration: 300729ms, prefetched: false)" uri="spotify:track:5qFoUVRGE6dQuT3ogCF6OO" Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=trace msg="scheduling prefetch in 247s" Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=trace msg="emitting websocket event: metadata" Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=trace msg="emitting websocket event: active" Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=debug msg="sending successful reply for dealer request" Mar 13 19:10:15 deskdac volumio[978]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5qFoUVRGE6dQuT3ogCF6OO","name":"Locomotive","artist_names":["Big Wreck"],"album_name":"...but for the sun","album_cover_url":"https://i.scdn.co/image/ab67616d00001e024d4a9bc34c2aa2ab4d42b32d","position":23373,"duration":300729,"release_date":"year:2019 month:8 day:30","track_number":2,"disc_number":1}} Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Mar 13 19:10:15 deskdac volumio[978]: SPOTIFY: received: {"type":"active","data":null} Mar 13 19:10:15 deskdac volumio[978]: info: Aligning Spotify Volume to Volumio Volume Mar 13 19:10:15 deskdac volumio[978]: info: CoreCommandRouter::volumioGetState Mar 13 19:10:15 deskdac volumio[978]: info: CorePlayQueue::getTrack 0 Mar 13 19:10:15 deskdac volumio[978]: info: Setting Spotify Volume from Volumio: 78 Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=debug msg="fetched chunk 3/24, size: 524288" uri="spotify:track:5qFoUVRGE6dQuT3ogCF6OO" Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=debug msg="fetched chunk 2/24, size: 524288" uri="spotify:track:5qFoUVRGE6dQuT3ogCF6OO" Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=trace msg="emitting websocket event: playing" Mar 13 19:10:15 deskdac volumio[978]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5qFoUVRGE6dQuT3ogCF6OO","play_origin":"playlist"}} Mar 13 19:10:15 deskdac volumio[978]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 13 19:10:15 deskdac volumio[978]: TypeError: Cannot read property 'service' of undefined Mar 13 19:10:15 deskdac volumio[978]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:340:50) Mar 13 19:10:15 deskdac volumio[978]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:266:18) Mar 13 19:10:15 deskdac volumio[978]: at WebSocket.message (/data/plugins/music_service/spop/index.js:193:14) Mar 13 19:10:15 deskdac volumio[978]: at WebSocket.emit (events.js:315:20) Mar 13 19:10:15 deskdac volumio[978]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Mar 13 19:10:15 deskdac volumio[978]: at Receiver.emit (events.js:315:20) Mar 13 19:10:15 deskdac volumio[978]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Mar 13 19:10:15 deskdac volumio[978]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Mar 13 19:10:15 deskdac volumio[978]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Mar 13 19:10:15 deskdac volumio[978]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Mar 13 19:10:15 deskdac volumio[978]: at writeOrBuffer (internal/streams/writable.js:358:12) Mar 13 19:10:15 deskdac volumio[978]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Mar 13 19:10:15 deskdac volumio[978]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Mar 13 19:10:15 deskdac volumio[978]: at Socket.emit (events.js:315:20) Mar 13 19:10:15 deskdac volumio[978]: at addChunk (internal/streams/readable.js:309:12) Mar 13 19:10:15 deskdac volumio[978]: at readableAddChunk (internal/streams/readable.js:284:9) Mar 13 19:10:15 deskdac volumio[978]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 13 19:10:15 deskdac go-librespot[1402]: time="2025-03-13T19:10:15-05:00" level=debug msg="fetched chunk 4/24, size: 524288" uri="spotify:track:5qFoUVRGE6dQuT3ogCF6OO" Mar 13 19:10:16 deskdac sudo[1695]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-13 19:09 Mar 13 19:10:16 deskdac sudo[1695]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"