-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Sat 2025-01-11 21:24:48 CET. -- Jan 11 21:23:59 volumio systemd-timedated[1039]: Changed local time to Sat Jan 11 21:23:59 2025 Jan 11 21:23:59 volumio sudo[1037]: pam_unix(sudo:session): session closed for user root Jan 11 21:23:59 volumio volumio-time-update[622]: volumio-time-update-util: System time updated successfully. Jan 11 21:23:59 volumio systemd[1]: Starting Daily apt download activities... Jan 11 21:23:59 volumio systemd[1]: Started Volumio Time Update Utility. Jan 11 21:23:59 volumio volumio[1007]: info: MYVOLUMIO Environment detected Jan 11 21:23:59 volumio volumio[1007]: info: Plugin folders cleanup Jan 11 21:23:59 volumio volumio[1007]: info: Scanning into folder /volumio/app/plugins/ Jan 11 21:23:59 volumio volumio[1007]: info: Scanning category audio_interface Jan 11 21:23:59 volumio volumio[1007]: info: Scanning category miscellanea Jan 11 21:23:59 volumio volumio[1007]: info: Scanning category music_service Jan 11 21:23:59 volumio volumio[1007]: info: Scanning category plugins.json Jan 11 21:23:59 volumio volumio[1007]: info: Scanning category system_controller Jan 11 21:23:59 volumio volumio[1007]: info: Scanning category user_interface Jan 11 21:23:59 volumio volumio[1007]: info: Scanning into folder /data/plugins/ Jan 11 21:23:59 volumio volumio[1007]: info: Scanning category audio_interface Jan 11 21:23:59 volumio volumio[1007]: info: Scanning category music_service Jan 11 21:23:59 volumio volumio[1007]: info: Plugin folders cleanup completed Jan 11 21:23:59 volumio volumio[1007]: info: ------------------------------------------- Jan 11 21:23:59 volumio volumio[1007]: info: ----- Core plugins startup ---- Jan 11 21:23:59 volumio volumio[1007]: info: ------------------------------------------- Jan 11 21:23:59 volumio volumio[1007]: info: Loading plugins from folder /volumio/app/plugins/ Jan 11 21:23:59 volumio volumio[1007]: info: Adding plugin upnp to MyMusic Plugins Jan 11 21:23:59 volumio volumio[1007]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 11 21:23:59 volumio volumio[1007]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 11 21:23:59 volumio volumio[1007]: info: Loading plugins from folder /data/plugins/ Jan 11 21:23:59 volumio volumio[1007]: info: Loading plugin "system"... Jan 11 21:23:59 volumio volumio[1007]: info: No id defined. Creating one Jan 11 21:23:59 volumio volumio[1007]: info: Loading plugin "appearance"... Jan 11 21:23:59 volumio nmbd[757]: [2025/01/11 21:23:59.990108, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 11 21:23:59 volumio systemd[1]: Started Samba NMB Daemon. Jan 11 21:23:59 volumio nmbd[757]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jan 11 21:24:00 volumio systemd[1]: Starting Samba Winbind Daemon... Jan 11 21:24:00 volumio nmbd[757]: [2025/01/11 21:24:00.112201, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Jan 11 21:24:00 volumio nmbd[757]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.10.200 for name WORKGROUP<1d>. Jan 11 21:24:00 volumio nmbd[757]: This response was from IP 192.168.10.145, reporting an IP address of 192.168.10.145. Jan 11 21:24:00 volumio winbindd[1065]: [2025/01/11 21:24:00.340904, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jan 11 21:24:00 volumio winbindd[1065]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jan 11 21:24:00 volumio winbindd[1065]: [2025/01/11 21:24:00.365787, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 11 21:24:00 volumio winbindd[1065]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jan 11 21:24:00 volumio systemd[1]: Started Samba Winbind Daemon. Jan 11 21:24:00 volumio systemd[1]: Starting Samba SMB Daemon... Jan 11 21:24:00 volumio volumio[1007]: info: Loading plugin "network"... Jan 11 21:24:00 volumio volumio[1007]: info: Refreshing Cached IP Addresses Jan 11 21:24:00 volumio sudo[1076]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 21:24:00 volumio sudo[1076]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:00 volumio sudo[1076]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:00 volumio sudo[1078]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 21:24:00 volumio sudo[1078]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:00 volumio sudo[1078]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:00 volumio volumio[1007]: info: Loading plugin "services"... Jan 11 21:24:00 volumio volumio[1007]: info: Loading plugin "alsa_controller"... Jan 11 21:24:00 volumio sudo[1085]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 11 21:24:00 volumio sudo[1085]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:00 volumio smbd[1070]: [2025/01/11 21:24:00.806729, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 11 21:24:00 volumio smbd[1070]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jan 11 21:24:00 volumio systemd[1]: Started Samba SMB Daemon. Jan 11 21:24:00 volumio systemd[1]: Reached target Multi-User System. Jan 11 21:24:00 volumio systemd[1]: Reached target Graphical Interface. Jan 11 21:24:00 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Jan 11 21:24:00 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jan 11 21:24:00 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Jan 11 21:24:00 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 21:24:00 volumio volumio[1007]: info: Loading plugin "wizard"... Jan 11 21:24:00 volumio volumio[1007]: info: Loading plugin "networkfs"... Jan 11 21:24:00 volumio volumio[1007]: info: Starting Udev Watcher for removable devices Jan 11 21:24:00 volumio sudo[1110]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.10.85/Music/Flac-Files /mnt/NAS/Musik Jan 11 21:24:00 volumio sudo[1110]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:01 volumio volumio[1007]: info: Ignoring mount for partition: boot Jan 11 21:24:01 volumio volumio[1007]: info: Ignoring mount for partition: volumio Jan 11 21:24:01 volumio volumio[1007]: info: Ignoring mount for partition: volumio_data Jan 11 21:24:01 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 21:24:01 volumio volumio[1007]: info: Loading plugin "volumio_command_line_client"... Jan 11 21:24:01 volumio volumio-remote-updater[639]: [2025-01-11 21:24:01] [connect] Successful connection Jan 11 21:24:01 volumio volumio[1007]: info: Loading plugin "upnp"... Jan 11 21:24:01 volumio volumio[1007]: info: [1736627041025] Starting Upmpd Daemon Jan 11 21:24:01 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 21:24:01 volumio volumio[1007]: info: Loading plugin "my_music"... Jan 11 21:24:01 volumio volumio[1007]: info: Loading plugin "mpd"... Jan 11 21:24:01 volumio kernel: Key type cifs.spnego registered Jan 11 21:24:01 volumio kernel: Key type cifs.idmap registered Jan 11 21:24:01 volumio kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Jan 11 21:24:01 volumio kernel: CIFS: Attempting to mount //192.168.10.85/Music/Flac-Files Jan 11 21:24:01 volumio systemd[1]: apt-daily.service: Succeeded. Jan 11 21:24:01 volumio systemd[1]: Started Daily apt download activities. Jan 11 21:24:01 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Jan 11 21:24:01 volumio volumio[1007]: info: Loading plugin "upnp_browser"... Jan 11 21:24:01 volumio volumio[1007]: info: Loading plugin "alarm-clock"... Jan 11 21:24:01 volumio volumio[1007]: info: Loading plugin "airplay_emulation"... Jan 11 21:24:01 volumio volumio[1007]: info: Starting Shairport Sync Jan 11 21:24:01 volumio volumio[1007]: info: Loading plugin "last_100"... Jan 11 21:24:01 volumio volumio[1007]: info: Loading plugin "webradio"... Jan 11 21:24:01 volumio volumio[1007]: info: Loading plugin "i2s_dacs"... Jan 11 21:24:01 volumio volumio[1007]: info: I2S DAC not set, start Auto-detection Jan 11 21:24:01 volumio volumio[1007]: info: Loading plugin "volumiodiscovery"... Jan 11 21:24:02 volumio volumio[1007]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 21:24:02 volumio volumio[1007]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 21:24:02 volumio node[1007]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 21:24:02 volumio volumio[1007]: *** WARNING *** For more information see Jan 11 21:24:02 volumio volumio[1007]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 21:24:02 volumio volumio[1007]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 21:24:02 volumio volumio[1007]: *** WARNING *** For more information see Jan 11 21:24:02 volumio node[1007]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 21:24:02 volumio node[1007]: *** WARNING *** For more information see Jan 11 21:24:02 volumio node[1007]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 21:24:02 volumio node[1007]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 21:24:02 volumio node[1007]: *** WARNING *** For more information see Jan 11 21:24:02 volumio volumio[1007]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 11 21:24:02 volumio volumio[1007]: info: Discovery: Started advertising with name: Volumio Jan 11 21:24:02 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 21:24:02 volumio volumio[1007]: info: Loading plugin "spop"... Jan 11 21:24:02 volumio kernel: cryptd: max_cpu_qlen set to 1000 Jan 11 21:24:02 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Jan 11 21:24:02 volumio systemd[1]: Started Daily apt upgrade and clean activities. Jan 11 21:24:02 volumio systemd[1]: Startup finished in 11.847s (kernel) + 27.701s (userspace) = 39.548s. Jan 11 21:24:02 volumio sudo[1110]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:03 volumio volumio[1007]: info: Loading plugin "outputs"... Jan 11 21:24:03 volumio volumio[1007]: info: Loading plugin "albumart"... Jan 11 21:24:03 volumio volumio[1007]: info: Plugin example_plugin is not enabled Jan 11 21:24:03 volumio volumio[1007]: info: Loading plugin "inputs"... Jan 11 21:24:03 volumio volumio[1007]: info: Loading plugin "updater_comm"... Jan 11 21:24:03 volumio volumio[1007]: info: Plugin mpdemulation is not enabled Jan 11 21:24:03 volumio volumio[1007]: info: Loading plugin "rest_api"... Jan 11 21:24:03 volumio volumio[1007]: Forking 3 albumart workers Jan 11 21:24:03 volumio volumio[1007]: info: Loading plugin "websocket"... Jan 11 21:24:03 volumio volumio[1007]: info: Starting Socket.io Server version 2.3.0 Jan 11 21:24:03 volumio volumio[1007]: info: Loading plugin "fusiondsp"... Jan 11 21:24:03 volumio volumio[1007]: info: Applying required configuration parameters for plugin fusiondsp Jan 11 21:24:03 volumio volumio[1007]: info: Loading i18n strings for locale da Jan 11 21:24:03 volumio volumio[1007]: Updating browse sources language Jan 11 21:24:03 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 21:24:04 volumio volumio[1007]: Starting albumart workers Jan 11 21:24:04 volumio volumio[1007]: Starting albumart workers Jan 11 21:24:04 volumio volumio[1007]: Starting albumart workers Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::initPlayerControls Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: Express server listening on port 3000 Jan 11 21:24:04 volumio volumio[1007]: [Metrics] WebUI: 6s 497.99ms Jan 11 21:24:04 volumio volumio[1007]: info: CoreStateMachine::resetVolumioState Jan 11 21:24:04 volumio volumio[1007]: info: CoreStateMachine::getcurrentVolume Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: Volumio Network Manager: Network status updated: 2 Jan 11 21:24:04 volumio volumio-remote-updater[639]: [2025-01-11 21:24:04] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1736627041 101 Jan 11 21:24:04 volumio volumio[1007]: 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 Jan 11 21:24:04 volumio sudo[1085]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:04 volumio volumio[1007]: info: Reloading queue from file Jan 11 21:24:04 volumio volumio[1007]: info: Setting Device type: Raspberry PI Jan 11 21:24:04 volumio volumio[1007]: info: CoreStateMachine::setRepeat null single undefined Jan 11 21:24:04 volumio volumio[1007]: info: CoreStateMachine::pushState Jan 11 21:24:04 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jan 11 21:24:04 volumio volumio[1007]: info: CoreStateMachine::setRandom null Jan 11 21:24:04 volumio volumio[1007]: info: CoreStateMachine::pushState Jan 11 21:24:04 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jan 11 21:24:04 volumio volumio[1007]: info: VolumeController:: Volume=63 Mute =false Jan 11 21:24:04 volumio volumio[1007]: info: CoreStateMachine::pushState Jan 11 21:24:04 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jan 11 21:24:04 volumio volumio[1007]: info: CoreStateMachine::updateTrackBlock Jan 11 21:24:04 volumio volumio[1007]: info: CorePlayQueue::getTrackBlock Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 21:24:04 volumio volumio[1007]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jan 11 21:24:04 volumio volumio[1007]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d03114 Jan 11 21:24:04 volumio volumio[1007]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jan 11 21:24:04 volumio volumio[1007]: info: Completed loading Core Plugins Jan 11 21:24:04 volumio volumio[1007]: info: Preparing to generate the ALSA configuration file Jan 11 21:24:04 volumio volumio[1007]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 11 21:24:04 volumio volumio[1007]: info: Reading ALSA contributions from plugins. Jan 11 21:24:04 volumio volumio[1007]: info: Discovery: adding 042b604b-850b-49a5-bb72-d24fc067b41f Jan 11 21:24:04 volumio volumio[1007]: info: Discovery: Found device Volumio Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jan 11 21:24:04 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jan 11 21:24:04 volumio volumio[1007]: info: Asound.conf file unchanged, so no further update is needed Jan 11 21:24:04 volumio volumio[1007]: info: Output device has changed, restarting MPD Jan 11 21:24:04 volumio sudo[1294]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 21:24:04 volumio sudo[1294]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:04 volumio volumio[1007]: info: Output device has changed, restarting Shairport Sync Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:04 volumio sudo[1294]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:04 volumio sudo[1296]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 21:24:04 volumio sudo[1296]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:04 volumio systemd[1]: Stopping Music Player Daemon... Jan 11 21:24:04 volumio volumio[1007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 21:24:04 volumio volumio[1007]: info: ___________ START PLUGINS ___________ Jan 11 21:24:04 volumio volumio[1007]: info: Setting Hotspot Unique name on first start: Volumio-AD8E7 Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: network , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getConfigParam] in plugin network Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: network , saveHotspotSettings Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::Reload Ui Jan 11 21:24:04 volumio volumio[1007]: info: ControllerMpd::onStart: Initializing MPD Jan 11 21:24:04 volumio volumio[1007]: info: Creating MPD Configuration file Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 21:24:04 volumio volumio[1007]: info: [1736627044722] CoreMusicLibrary::Adding element Medieservere Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 21:24:04 volumio sudo[1303]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 21:24:04 volumio sudo[1303]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:04 volumio sudo[1303]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:04 volumio sudo[1305]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 21:24:04 volumio sudo[1305]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:04 volumio systemd[1]: mpd.service: Succeeded. Jan 11 21:24:04 volumio systemd[1]: Stopped Music Player Daemon. Jan 11 21:24:04 volumio volumio[1007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 21:24:04 volumio volumio[1007]: info: [1736627044811] CoreMusicLibrary::Adding element Last_100 Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 21:24:04 volumio volumio[1007]: info: [1736627044813] CoreMusicLibrary::Adding element Webradio Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 21:24:04 volumio volumio[1007]: info: Initializing BBC Radios Jan 11 21:24:04 volumio systemd[1]: Starting Music Player Daemon... Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: Creating Spotify config file Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:04 volumio sudo[1311]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 21:24:04 volumio sudo[1311]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:04 volumio sudo[1311]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:04 volumio volumio[1007]: info: Loading i18n strings for locale da Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 11 21:24:04 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:04 volumio volumio[1007]: info: FusionDsp - mixtype--------------------- Hardware Jan 11 21:24:04 volumio volumio[1007]: info: Volumio Calling Home Jan 11 21:24:05 volumio volumio[1007]: info: Preparing to generate the ALSA configuration file Jan 11 21:24:05 volumio volumio[1007]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 11 21:24:05 volumio volumio[1007]: info: Reading ALSA contributions from plugins. Jan 11 21:24:05 volumio volumio[1007]: info: MPD Permissions set Jan 11 21:24:05 volumio volumio[1007]: info: MPD Permissions set Jan 11 21:24:05 volumio volumio[1007]: info: VolumeController:: Volume=63 Mute =false Jan 11 21:24:05 volumio volumio[1007]: info: CoreStateMachine::pushState Jan 11 21:24:05 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::volumioPushState Jan 11 21:24:05 volumio volumio[1007]: info: Spotify config file written Jan 11 21:24:05 volumio volumio[1007]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 11 21:24:05 volumio sudo[1331]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 11 21:24:05 volumio sudo[1331]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: No need to fix Spotify hosts Jan 11 21:24:05 volumio systemd[1]: Started go-librespot Daemon. Jan 11 21:24:05 volumio go-librespot[1337]: Librespot-go daemon starting... Jan 11 21:24:05 volumio sudo[1331]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:05 volumio volumio[1007]: info: Volumio called home Jan 11 21:24:05 volumio volumio[1007]: info: Starting Shairport Sync Jan 11 21:24:05 volumio volumio[1007]: info: Starting Shairport Sync Jan 11 21:24:05 volumio volumio[1007]: info: Starting Shairport Sync Jan 11 21:24:05 volumio sudo[1344]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 21:24:05 volumio sudo[1344]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:05 volumio sudo[1348]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 21:24:05 volumio sudo[1348]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::volumioGetState Jan 11 21:24:05 volumio volumio[1007]: info: CorePlayQueue::getTrack 0 Jan 11 21:24:05 volumio sudo[1354]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 21:24:05 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 21:24:05 volumio sudo[1354]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:05 volumio systemd[1]: shairport-sync.service: Succeeded. Jan 11 21:24:05 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 21:24:05 volumio volumio[1007]: info: Asound.conf file unchanged, so no further update is needed Jan 11 21:24:05 volumio volumio[1007]: info: Output device has changed, restarting MPD Jan 11 21:24:05 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 11 21:24:05 volumio sudo[1344]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:05 volumio sudo[1354]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:05 volumio sudo[1348]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:05 volumio sudo[1359]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 21:24:05 volumio volumio[1007]: info: Output device has changed, restarting Shairport Sync Jan 11 21:24:05 volumio sudo[1359]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:05 volumio sudo[1359]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:05 volumio sudo[1362]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 21:24:05 volumio sudo[1362]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:05 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jan 11 21:24:05 volumio systemd[1]: mpd.service: Succeeded. Jan 11 21:24:05 volumio systemd[1]: Stopped Music Player Daemon. Jan 11 21:24:05 volumio volumio[1007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 21:24:05 volumio systemd[1]: Starting Music Player Daemon... Jan 11 21:24:05 volumio go-librespot[1337]: time="2025-01-11T21:24:05+01:00" level=info msg="generated new device id: 6b1787e3808c23e0c049e3ba889823bf851e8643" Jan 11 21:24:05 volumio go-librespot[1337]: time="2025-01-11T21:24:05+01:00" level=debug msg="stored credentials found for tangthomsen" Jan 11 21:24:05 volumio volumio[1007]: info: MPD Permissions set Jan 11 21:24:05 volumio volumio[1007]: info: Shairport-Sync Started Jan 11 21:24:05 volumio volumio[1007]: Error adding Membership: Error: addMembership EINVAL Jan 11 21:24:05 volumio volumio[1007]: info: Shairport-Sync Started Jan 11 21:24:05 volumio volumio[1007]: info: Shairport-Sync Started Jan 11 21:24:05 volumio volumio[1007]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 11 21:24:05 volumio volumio[1007]: SPOTIFY: BQDFd31n6_Vc5A2wKexyl0yp9HtLYjSlM6z1woxAkUAtWPylWPaZwTALfsWCUf-2NfkYwdDIBPLVeEMnCWydCxOcUafyynUfA32MlBnp-eAFHoJcND-h2Byap6Q2vo8rP0UsgKS5RfBiy30pgcnuhvRpcxt_TsmgubtvoeMwtuKX3bMMyiwYMv6lge9-iEtJI-B_kB2mHETreFQvF7xKpBaUxmYiMSJ47zuoBdVUu7fd-tXyGm5bvxphDA Jan 11 21:24:05 volumio volumio[1007]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 11 21:24:05 volumio volumio[1007]: info: New Spotify access token = BQDFd31n6_Vc5A2wKexyl0yp9HtLYjSlM6z1woxAkUAtWPylWPaZwTALfsWCUf-2NfkYwdDIBPLVeEMnCWydCxOcUafyynUfA32MlBnp-eAFHoJcND-h2Byap6Q2vo8rP0UsgKS5RfBiy30pgcnuhvRpcxt_TsmgubtvoeMwtuKX3bMMyiwYMv6lge9-iEtJI-B_kB2mHETreFQvF7xKpBaUxmYiMSJ47zuoBdVUu7fd-tXyGm5bvxphDA Jan 11 21:24:05 volumio volumio[1007]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 11 21:24:05 volumio sudo[1369]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 21:24:05 volumio sudo[1369]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:05 volumio sudo[1369]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:05 volumio volumio[1007]: info: Starting Shairport Sync Jan 11 21:24:05 volumio sudo[1377]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 21:24:05 volumio sudo[1377]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:05 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 21:24:05 volumio systemd[1]: shairport-sync.service: Succeeded. Jan 11 21:24:05 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 21:24:05 volumio sudo[1381]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hostapd/hostapd.conf Jan 11 21:24:05 volumio sudo[1381]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:05 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 11 21:24:05 volumio sudo[1381]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:05 volumio sudo[1377]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:05 volumio volumio[1007]: info: Shairport-Sync Started Jan 11 21:24:05 volumio volumio[1007]: info: Permissions for /etc/hostapd/hostapd.conf Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Jan 11 21:24:05 volumio volumio[1007]: info: Discovery: Restarting Advertising due to device name change Jan 11 21:24:05 volumio sudo[1387]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service Jan 11 21:24:05 volumio sudo[1387]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:05 volumio volumio[1007]: SPOTIFY: User informations: {"country":"DK","display_name":"tangthomsen","email":"tangthomsen@outlook.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/tangthomsen"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/tangthomsen","id":"tangthomsen","images":[],"product":"premium","type":"user","uri":"spotify:user:tangthomsen"} Jan 11 21:24:05 volumio volumio[1007]: info: Spotify Successfully logged in Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 21:24:05 volumio volumio[1007]: info: [1736627045829] CoreMusicLibrary::Adding element Spotify Jan 11 21:24:05 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 21:24:05 volumio volumio[1007]: Cannot find translation for source Spotify Jan 11 21:24:05 volumio systemd[1]: wireless.service: Killing process 906 (wpa_supplicant) with signal SIGKILL. Jan 11 21:24:05 volumio systemd[1]: wireless.service: Killing process 918 (dhcpcd) with signal SIGKILL. Jan 11 21:24:05 volumio systemd[1]: Stopping Wireless Services... Jan 11 21:24:05 volumio go-librespot[1337]: time="2025-01-11T21:24:05+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 11 21:24:05 volumio go-librespot[1337]: time="2025-01-11T21:24:05+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 11 21:24:05 volumio go-librespot[1337]: time="2025-01-11T21:24:05+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 11 21:24:05 volumio go-librespot[1337]: time="2025-01-11T21:24:05+01:00" level=debug msg="zeroconf server listening on port 42469" Jan 11 21:24:06 volumio go-librespot[1337]: time="2025-01-11T21:24:06+01:00" level=debug msg="obtained new client token: AABwu6J806S/i8cu6i+2EMNoiAg23kIIyoSruM2VhfRTn1z9g38zVI4mJcrer43Ln/Xv0HL43qPeLaiF+ru2BPsin/rrwemkBns146qHmkaAvAvuE7gG16Dr9n44VZkhDV0HUmUmNITUJzC2xzLO2B/BjYpaoJ3FbUaYCuYmiq9T38pm5pnxi2tDjG7mWUmI8T8yjmNDDAsokGI3rqgMm8yagE5qFpKl40HbFXFUl/y05hbQIhDyUzfBEC7kkao=" Jan 11 21:24:06 volumio systemd[1]: wireless.service: Succeeded. Jan 11 21:24:06 volumio systemd[1]: Stopped Wireless Services. Jan 11 21:24:06 volumio systemd[1]: Starting Wireless Services... Jan 11 21:24:06 volumio mpd[1371]: Jan 11 21:24 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 21:24:06 volumio systemd[1]: Started Music Player Daemon. Jan 11 21:24:06 volumio sudo[1296]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:06 volumio sudo[1362]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:06 volumio sudo[1305]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:06 volumio volumio[1007]: error: MPD error: The expression evaluated to a falsy value: Jan 11 21:24:06 volumio volumio[1007]: assert.ok(self.idling) Jan 11 21:24:06 volumio volumio[1007]: error: The expression evaluated to a falsy value: Jan 11 21:24:06 volumio volumio[1007]: assert.ok(self.idling) Jan 11 21:24:06 volumio volumio[1007]: info: Completed starting Core Plugins Jan 11 21:24:06 volumio volumio[1007]: info: ------------------------------------------- Jan 11 21:24:06 volumio volumio[1007]: info: ----- MyVolumio plugins startup ---- Jan 11 21:24:06 volumio volumio[1007]: info: ------------------------------------------- Jan 11 21:24:06 volumio volumio[1007]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 11 21:24:06 volumio volumio[1007]: error: MPD error: The expression evaluated to a falsy value: Jan 11 21:24:06 volumio volumio[1007]: assert.ok(self.idling) Jan 11 21:24:06 volumio volumio[1007]: error: The expression evaluated to a falsy value: Jan 11 21:24:06 volumio volumio[1007]: assert.ok(self.idling) Jan 11 21:24:06 volumio volumio[1007]: info: MPD running with PID1371 Jan 11 21:24:06 volumio volumio[1007]: ,establishing connection Jan 11 21:24:06 volumio volumio[1007]: error: MPD error: The expression evaluated to a falsy value: Jan 11 21:24:06 volumio volumio[1007]: assert.ok(self.idling) Jan 11 21:24:06 volumio volumio[1007]: error: The expression evaluated to a falsy value: Jan 11 21:24:06 volumio volumio[1007]: assert.ok(self.idling) Jan 11 21:24:06 volumio volumio[1007]: error: updateQueue error: null Jan 11 21:24:06 volumio wireless.js[1390]: Cleaning previous... Jan 11 21:24:06 volumio sudo[1408]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jan 11 21:24:06 volumio sudo[1408]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:06 volumio avahi-daemon[609]: Withdrawing address record for 192.168.10.200 on wlan0. Jan 11 21:24:06 volumio avahi-daemon[609]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.10.200. Jan 11 21:24:06 volumio avahi-daemon[609]: Interface wlan0.IPv4 no longer relevant for mDNS. Jan 11 21:24:06 volumio sudo[1408]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:06 volumio volumio[1007]: info: Discovery: A device disappeared from network Jan 11 21:24:06 volumio volumio[1007]: info: Discovery: Device volumio disappeared from network Jan 11 21:24:06 volumio sudo[1410]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jan 11 21:24:06 volumio sudo[1410]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:06 volumio volumio[1007]: info: camilladsp spawned new process with pid undefined, instance 1, run: true Jan 11 21:24:06 volumio volumio[1007]: info: camilladsp service started and running in background, instance 1 Jan 11 21:24:06 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:07 volumio volumio[1007]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Jan 11 21:24:07 volumio volumio[1007]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Jan 11 21:24:07 volumio volumio[1007]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Jan 11 21:24:07 volumio volumio[1007]: info: FusionDsp loaded Jan 11 21:24:07 volumio volumio[1007]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 21:24:07 volumio volumio[1007]: info: FusionDsp - Reporting Fusion DSP Enabled Jan 11 21:24:07 volumio volumio[1007]: info: Adding Signal Path Element [object Object] Jan 11 21:24:07 volumio volumio[1007]: info: Adding fusiondspeq DSP Signal Path Element Jan 11 21:24:07 volumio volumio[1007]: info: FusionDsp - ---- installed callbackRead Jan 11 21:24:07 volumio volumio[1007]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 21:24:07 volumio volumio[1007]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp ENOENT Jan 11 21:24:07 volumio volumio[1007]: at Process.ChildProcess._handle.onexit (internal/child_process.js:269:19) Jan 11 21:24:07 volumio volumio[1007]: at onErrorNT (internal/child_process.js:465:16) Jan 11 21:24:07 volumio volumio[1007]: at processTicksAndRejections (internal/process/task_queues.js:80:21) { Jan 11 21:24:07 volumio volumio[1007]: errno: -2, Jan 11 21:24:07 volumio volumio[1007]: code: 'ENOENT', Jan 11 21:24:07 volumio volumio[1007]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', Jan 11 21:24:07 volumio volumio[1007]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', Jan 11 21:24:07 volumio volumio[1007]: spawnargs: [ Jan 11 21:24:07 volumio volumio[1007]: '-p', Jan 11 21:24:07 volumio volumio[1007]: 9876, Jan 11 21:24:07 volumio volumio[1007]: '-o', Jan 11 21:24:07 volumio volumio[1007]: '/tmp/camilladsp.log', Jan 11 21:24:07 volumio volumio[1007]: '-l', Jan 11 21:24:07 volumio volumio[1007]: 'warn', Jan 11 21:24:07 volumio volumio[1007]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' Jan 11 21:24:07 volumio volumio[1007]: ] Jan 11 21:24:07 volumio volumio[1007]: } Jan 11 21:24:07 volumio volumio[1007]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 21:24:07 volumio sudo[1410]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:07 volumio sudo[1422]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jan 11 21:24:07 volumio sudo[1422]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:07 volumio sudo[1422]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:07 volumio wireless.js[1390]: Stopped aP Jan 11 21:24:07 volumio sudo[1437]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Jan 11 21:24:07 volumio sudo[1437]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:07 volumio sudo[1437]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:07 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jan 11 21:24:07 volumio sudo[1439]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Jan 11 21:24:07 volumio sudo[1439]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:07 volumio sudo[1439]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:07 volumio sudo[1446]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Jan 11 21:24:07 volumio sudo[1446]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:07 volumio sudo[1446]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:07 volumio sudo[1448]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Jan 11 21:24:07 volumio sudo[1448]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:07 volumio sudo[1453]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-11 21:23 Jan 11 21:24:07 volumio sudo[1453]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:07 volumio sudo[1453]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:07 volumio volumio-remote-updater[639]: [2025-01-11 21:24:07] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 11 21:24:07 volumio volumio-remote-updater[639]: [2025-01-11 21:24:07] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 11 21:24:07 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 11 21:24:07 volumio sudo[1387]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:07 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 11 21:24:07 volumio systemd[1]: Started dynamicswap service. Jan 11 21:24:07 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 21:24:07 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jan 11 21:24:07 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Jan 11 21:24:07 volumio systemd[1]: Started dynamicswap service. Jan 11 21:24:07 volumio systemd[1]: Stopped Volumio Backend Module. Jan 11 21:24:07 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 21:24:07 volumio systemd[1]: systemd-fsckd.service: Succeeded. Jan 11 21:24:08 volumio ntpd[810]: Deleting interface #3 wlan0, 192.168.10.200#123, interface stats: received=0, sent=0, dropped=0, active_time=10 secs Jan 11 21:24:08 volumio sh[542]: timed out Jan 11 21:24:08 volumio dhcpcd[579]: timed out Jan 11 21:24:08 volumio sh[542]: dhcpcd exited Jan 11 21:24:08 volumio dhcpcd[579]: dhcpcd exited Jan 11 21:24:08 volumio sh[542]: ifup: failed to bring up eth0 Jan 11 21:24:08 volumio systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Jan 11 21:24:08 volumio systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Jan 11 21:24:09 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Jan 11 21:24:09 volumio sudo[1448]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:09 volumio wireless.js[1390]: SETTING APPROPRIATE REG DOMAIN: DE Jan 11 21:24:09 volumio sudo[1476]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Jan 11 21:24:09 volumio sudo[1476]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:09 volumio sudo[1476]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:09 volumio sudo[1478]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set DE Jan 11 21:24:09 volumio sudo[1478]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:09 volumio sudo[1478]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:09 volumio wireless.js[1390]: SUCCESSFULLY SET NEW REGDOMAIN: DE Jan 11 21:24:09 volumio wireless.js[1390]: Start wireless flow Jan 11 21:24:09 volumio wireless.js[1390]: Stopped hotspot (if there).. Jan 11 21:24:09 volumio sudo[1483]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Jan 11 21:24:09 volumio sudo[1483]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:09 volumio sudo[1483]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:09 volumio sudo[1486]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Jan 11 21:24:09 volumio sudo[1486]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:10 volumio sudo[1486]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:10 volumio wireless.js[1390]: DHCP IP Jan 11 21:24:10 volumio wireless.js[1390]: Start ap Jan 11 21:24:10 volumio wpa_supplicant[1488]: Successfully initialized wpa_supplicant Jan 11 21:24:10 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jan 11 21:24:10 volumio sudo[1489]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Jan 11 21:24:10 volumio sudo[1489]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:10 volumio dhcpcd[1490]: main: control_open: Connection refused Jan 11 21:24:10 volumio dhcpcd[1490]: dev: loaded udev Jan 11 21:24:10 volumio dhcpcd-run-hooks[1515]: wlan0: starting wpa_supplicant Jan 11 21:24:10 volumio dhcpcd-run-hooks[1520]: wlan0: failed to start wpa_supplicant Jan 11 21:24:10 volumio dhcpcd-run-hooks[1521]: wlan0: Successfully initialized wpa_supplicant nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Ma Jan 11 21:24:10 volumio dhcpcd[1490]: wlan0: connected to Access Point `' Jan 11 21:24:10 volumio dhcpcd[1490]: no interfaces have a carrier Jan 11 21:24:10 volumio dhcpcd[1490]: forked to background, child pid 1539 Jan 11 21:24:10 volumio dhcpcd[1539]: eth0: waiting for carrier Jan 11 21:24:10 volumio dhcpcd[1539]: wlan0: waiting for carrier Jan 11 21:24:10 volumio sudo[1489]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:11 volumio go-librespot[1337]: time="2025-01-11T21:24:11+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070 (error: dial tcp: lookup ap-gew4.spotify.com: device or resource busy), retrying with a different AP" Jan 11 21:24:11 volumio go-librespot[1337]: time="2025-01-11T21:24:11+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443 (error: dial tcp: lookup ap-gew4.spotify.com: device or resource busy), retrying with a different AP" Jan 11 21:24:11 volumio go-librespot[1337]: time="2025-01-11T21:24:11+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80 (error: dial tcp: lookup ap-gew4.spotify.com: device or resource busy), retrying with a different AP" Jan 11 21:24:11 volumio go-librespot[1337]: time="2025-01-11T21:24:11+01:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070 (error: dial tcp: lookup ap-guc3.spotify.com: device or resource busy), retrying with a different AP" Jan 11 21:24:11 volumio go-librespot[1337]: time="2025-01-11T21:24:11+01:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443 (error: dial tcp: lookup ap-gue1.spotify.com: device or resource busy), retrying with a different AP" Jan 11 21:24:11 volumio go-librespot[1337]: time="2025-01-11T21:24:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed to connect to AP ap-gae2.spotify.com:80: &{%!e(string=dial) %!e(string=tcp) %!e(*net.DNSError=&{device or resource busy ap-gae2.spotify.com false false false})}" Jan 11 21:24:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 21:24:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 21:24:11 volumio wireless.js[1390]: trying... Jan 11 21:24:11 volumio sudo[1541]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:11 volumio sudo[1541]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:11 volumio sudo[1541]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:12 volumio wireless.js[1390]: trying... Jan 11 21:24:12 volumio sudo[1547]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:12 volumio sudo[1547]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:12 volumio sudo[1547]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:12 volumio volumio-remote-updater[639]: [2025-01-11 21:24:12] [info] asio async_connect error: system:111 (Connection refused) Jan 11 21:24:12 volumio volumio-remote-updater[639]: [2025-01-11 21:24:12] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jan 11 21:24:12 volumio volumio-remote-updater[639]: [2025-01-11 21:24:12] [error] handle_connect error: Underlying Transport Error Jan 11 21:24:13 volumio wireless.js[1390]: trying... Jan 11 21:24:13 volumio sudo[1550]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:13 volumio sudo[1550]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:13 volumio sudo[1550]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 11 21:24:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 11 21:24:14 volumio systemd[1]: Stopped go-librespot Daemon. Jan 11 21:24:14 volumio wireless.js[1390]: trying... Jan 11 21:24:14 volumio sudo[1553]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:14 volumio sudo[1553]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:14 volumio sudo[1553]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:14 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd022 fail, reason -52 Jan 11 21:24:14 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd026 fail, reason -52 Jan 11 21:24:14 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02a fail, reason -52 Jan 11 21:24:14 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd02e fail, reason -52 Jan 11 21:24:15 volumio wireless.js[1390]: trying... Jan 11 21:24:15 volumio sudo[1556]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:15 volumio sudo[1556]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:15 volumio sudo[1556]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:16 volumio wireless.js[1390]: trying... Jan 11 21:24:16 volumio sudo[1559]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:16 volumio sudo[1559]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:16 volumio sudo[1559]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:16 volumio wpa_supplicant[1519]: wlan0: Trying to associate with SSID 'dc8a36' Jan 11 21:24:16 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd090 fail, reason -52 Jan 11 21:24:16 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd095 fail, reason -52 Jan 11 21:24:16 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd099 fail, reason -52 Jan 11 21:24:16 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd09d fail, reason -52 Jan 11 21:24:16 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a1 fail, reason -52 Jan 11 21:24:16 volumio kernel: brcmfmac: brcmf_set_channel: set chanspec 0xd0a5 fail, reason -52 Jan 11 21:24:17 volumio wireless.js[1390]: trying... Jan 11 21:24:17 volumio sudo[1562]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:17 volumio sudo[1562]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:17 volumio sudo[1562]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:18 volumio wireless.js[1390]: trying... Jan 11 21:24:18 volumio sudo[1565]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:18 volumio sudo[1565]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:18 volumio sudo[1565]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:19 volumio wireless.js[1390]: trying... Jan 11 21:24:19 volumio sudo[1568]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:19 volumio sudo[1568]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:19 volumio sudo[1568]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:19 volumio dhcpcd[1539]: wlan0: carrier acquired Jan 11 21:24:19 volumio dhcpcd[1539]: wlan0: connected to Access Point `dc8a36' Jan 11 21:24:19 volumio wpa_supplicant[1519]: wlan0: Associated with ac:15:a2:d4:38:fe Jan 11 21:24:19 volumio wpa_supplicant[1519]: wlan0: CTRL-EVENT-CONNECTED - Connection to ac:15:a2:d4:38:fe completed [id=0 id_str=] Jan 11 21:24:19 volumio wpa_supplicant[1519]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jan 11 21:24:19 volumio wpa_supplicant[1519]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE Jan 11 21:24:19 volumio dhcpcd[1539]: DUID 00:01:00:01:2e:f2:a4:28:dc:a6:32:b4:db:40 Jan 11 21:24:19 volumio dhcpcd[1539]: wlan0: IAID 32:b4:db:41 Jan 11 21:24:19 volumio dhcpcd[1539]: wlan0: adding address fe80::b09c:5849:9a18:fa6f Jan 11 21:24:19 volumio dhcpcd[1539]: ipv6_addaddr1: Permission denied Jan 11 21:24:19 volumio dhcpcd[1539]: wlan0: carrier lost Jan 11 21:24:19 volumio dhcpcd[1539]: wlan0: carrier acquired Jan 11 21:24:19 volumio dhcpcd[1539]: wlan0: IAID 32:b4:db:41 Jan 11 21:24:19 volumio dhcpcd[1539]: wlan0: soliciting an IPv6 router Jan 11 21:24:19 volumio volumio-remote-updater[639]: [2025-01-11 21:24:19] [info] asio async_connect error: system:111 (Connection refused) Jan 11 21:24:19 volumio volumio-remote-updater[639]: [2025-01-11 21:24:19] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jan 11 21:24:19 volumio volumio-remote-updater[639]: [2025-01-11 21:24:19] [error] handle_connect error: Underlying Transport Error Jan 11 21:24:20 volumio wireless.js[1390]: trying... Jan 11 21:24:20 volumio sudo[1590]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:20 volumio sudo[1590]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:20 volumio sudo[1590]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:20 volumio dhcpcd[1539]: wlan0: soliciting a DHCP lease Jan 11 21:24:21 volumio wireless.js[1390]: trying... Jan 11 21:24:21 volumio sudo[1593]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:21 volumio sudo[1593]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:21 volumio sudo[1593]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:22 volumio wireless.js[1390]: trying... Jan 11 21:24:22 volumio sudo[1599]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:22 volumio sudo[1599]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:22 volumio sudo[1599]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:23 volumio wireless.js[1390]: trying... Jan 11 21:24:23 volumio sudo[1602]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:23 volumio sudo[1602]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:23 volumio sudo[1602]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:24 volumio wireless.js[1390]: trying... Jan 11 21:24:24 volumio sudo[1605]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:24 volumio sudo[1605]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:24 volumio sudo[1605]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:25 volumio wireless.js[1390]: trying... Jan 11 21:24:25 volumio sudo[1608]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:25 volumio sudo[1608]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:25 volumio sudo[1608]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:25 volumio dhcpcd[1539]: wlan0: probing for an IPv4LL address Jan 11 21:24:25 volumio dhcpcd[1539]: wlan0: offered 192.168.10.200 from 192.168.10.1 Jan 11 21:24:25 volumio dhcpcd[1539]: wlan0: probing address 192.168.10.200/24 Jan 11 21:24:26 volumio wireless.js[1390]: trying... Jan 11 21:24:26 volumio sudo[1611]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:26 volumio sudo[1611]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:26 volumio sudo[1611]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:27 volumio wireless.js[1390]: trying... Jan 11 21:24:27 volumio sudo[1614]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:27 volumio sudo[1614]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:27 volumio sudo[1614]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:28 volumio wireless.js[1390]: trying... Jan 11 21:24:28 volumio sudo[1617]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:28 volumio sudo[1617]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:28 volumio sudo[1617]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:29 volumio systemd[1]: systemd-timedated.service: Succeeded. Jan 11 21:24:29 volumio wireless.js[1390]: trying... Jan 11 21:24:29 volumio sudo[1622]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:29 volumio sudo[1622]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:29 volumio sudo[1622]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:29 volumio volumio-remote-updater[639]: [2025-01-11 21:24:29] [info] asio async_connect error: system:111 (Connection refused) Jan 11 21:24:29 volumio volumio-remote-updater[639]: [2025-01-11 21:24:29] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Jan 11 21:24:29 volumio volumio-remote-updater[639]: [2025-01-11 21:24:29] [error] handle_connect error: Underlying Transport Error Jan 11 21:24:30 volumio dhcpcd[1539]: wlan0: using IPv4LL address 169.254.16.3 Jan 11 21:24:30 volumio avahi-daemon[609]: Joining mDNS multicast group on interface wlan0.IPv4 with address 169.254.16.3. Jan 11 21:24:30 volumio avahi-daemon[609]: New relevant interface wlan0.IPv4 for mDNS. Jan 11 21:24:30 volumio dhcpcd[1539]: wlan0: adding route to 169.254.0.0/16 Jan 11 21:24:30 volumio avahi-daemon[609]: Registering new address record for 169.254.16.3 on wlan0.IPv4. Jan 11 21:24:30 volumio dhcpcd[1539]: wlan0: adding default route Jan 11 21:24:30 volumio wireless.js[1390]: trying... Jan 11 21:24:30 volumio sudo[1643]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Jan 11 21:24:30 volumio sudo[1643]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:30 volumio sudo[1643]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:30 volumio wireless.js[1390]: Connected to: ----dc8a36 Jan 11 21:24:30 volumio wireless.js[1390]: ---- Jan 11 21:24:30 volumio dhcpcd[1539]: wlan0: leased 192.168.10.200 for 3600 seconds Jan 11 21:24:30 volumio avahi-daemon[609]: Registering new address record for 192.168.10.200 on wlan0.IPv4. Jan 11 21:24:30 volumio dhcpcd[1539]: wlan0: adding route to 192.168.10.0/24 Jan 11 21:24:30 volumio dhcpcd[1539]: wlan0: changing default route via 192.168.10.1 Jan 11 21:24:30 volumio sudo[1646]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 21:24:30 volumio sudo[1646]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:30 volumio sudo[1646]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:30 volumio wireless.js[1390]: ... joined AP, wlan0 IPv4 is 169.254.16.3, ipV6 is undefined Jan 11 21:24:30 volumio wireless.js[1390]: It's done! AP Jan 11 21:24:30 volumio avahi-daemon[609]: Withdrawing address record for 169.254.16.3 on wlan0. Jan 11 21:24:30 volumio avahi-daemon[609]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 169.254.16.3. Jan 11 21:24:30 volumio avahi-daemon[609]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.10.200. Jan 11 21:24:30 volumio dhcpcd[1539]: wlan0: deleting route to 169.254.0.0/16 Jan 11 21:24:30 volumio systemd[1]: Started Wireless Services. Jan 11 21:24:30 volumio systemd[1]: Started Volumio Backend Module. Jan 11 21:24:30 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Jan 11 21:24:30 volumio systemd[1]: Started go-librespot Daemon. Jan 11 21:24:30 volumio go-librespot[1680]: Librespot-go daemon starting... Jan 11 21:24:30 volumio dhcpcd[1539]: wlan0: pid 1539 deleted default route via 192.168.10.1 Jan 11 21:24:30 volumio go-librespot[1680]: time="2025-01-11T21:24:30+01:00" level=info msg="generated new device id: 15bab4bf0db1e4e4309b3fa5fa10b80ef9a965b2" Jan 11 21:24:30 volumio go-librespot[1680]: time="2025-01-11T21:24:30+01:00" level=debug msg="stored credentials found for tangthomsen" Jan 11 21:24:30 volumio go-librespot[1680]: time="2025-01-11T21:24:30+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 11 21:24:30 volumio go-librespot[1680]: time="2025-01-11T21:24:30+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 11 21:24:30 volumio go-librespot[1680]: time="2025-01-11T21:24:30+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 11 21:24:30 volumio go-librespot[1680]: time="2025-01-11T21:24:30+01:00" level=debug msg="zeroconf server listening on port 37767" Jan 11 21:24:30 volumio wpa_supplicant[1519]: RRM: Ignoring radio measurement request: Not RRM network Jan 11 21:24:31 volumio go-librespot[1680]: time="2025-01-11T21:24:31+01:00" level=debug msg="obtained new client token: AAChFcmej0LE8iOnutELedgiEYqPkNTNSGFpM8XwPXo8Y9fiDmSnC3HO5eUnBbvMyuu1fwKJmCvRscEId3UzUm1+1ADjF6htzFpRcQlaEjM0YCvpOHOady0qKJvIDMWRfQZAXycC6p1EFcODJihzcIHJ3hbVWiEI/DicehEDKni2AFbaWudkOFmxAD+FFBKuZTd5bmOSILk9dmsY7ZIzb/7FAf0Jzf4731sSXJB4kUg1E+x0XOaf3XWv1z9NFx0=" Jan 11 21:24:31 volumio wpa_supplicant[1519]: wlan0: CTRL-EVENT-DISCONNECTED bssid=ac:15:a2:d4:38:fe reason=6 Jan 11 21:24:31 volumio wpa_supplicant[1519]: wlan0: Trying to associate with SSID 'dc8a36' Jan 11 21:24:31 volumio dhcpcd[1539]: wlan0: carrier lost Jan 11 21:24:31 volumio wpa_supplicant[1519]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Jan 11 21:24:31 volumio wpa_supplicant[1519]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=DE Jan 11 21:24:31 volumio avahi-daemon[609]: Withdrawing address record for 192.168.10.200 on wlan0. Jan 11 21:24:31 volumio avahi-daemon[609]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.10.200. Jan 11 21:24:31 volumio dhcpcd[1539]: wlan0: deleting route to 192.168.10.0/24 Jan 11 21:24:31 volumio avahi-daemon[609]: Interface wlan0.IPv4 no longer relevant for mDNS. Jan 11 21:24:31 volumio volumio[1677]: info: ------------------------------------------- Jan 11 21:24:31 volumio volumio[1677]: info: ----- Volumio3 ---- Jan 11 21:24:31 volumio volumio[1677]: info: ------------------------------------------- Jan 11 21:24:31 volumio volumio[1677]: info: ----- System startup ---- Jan 11 21:24:31 volumio volumio[1677]: info: ------------------------------------------- Jan 11 21:24:31 volumio volumio[1677]: info: MYVOLUMIO Environment detected Jan 11 21:24:31 volumio volumio[1677]: info: Plugin folders cleanup Jan 11 21:24:31 volumio volumio[1677]: info: Scanning into folder /volumio/app/plugins/ Jan 11 21:24:31 volumio volumio[1677]: info: Scanning category audio_interface Jan 11 21:24:31 volumio volumio[1677]: info: Scanning category miscellanea Jan 11 21:24:31 volumio volumio[1677]: info: Scanning category music_service Jan 11 21:24:31 volumio volumio[1677]: info: Scanning category plugins.json Jan 11 21:24:31 volumio volumio[1677]: info: Scanning category system_controller Jan 11 21:24:31 volumio volumio[1677]: info: Scanning category user_interface Jan 11 21:24:31 volumio volumio[1677]: info: Scanning into folder /data/plugins/ Jan 11 21:24:31 volumio volumio[1677]: info: Scanning category audio_interface Jan 11 21:24:31 volumio volumio[1677]: info: Scanning category music_service Jan 11 21:24:31 volumio volumio[1677]: info: Plugin folders cleanup completed Jan 11 21:24:32 volumio volumio[1677]: info: ------------------------------------------- Jan 11 21:24:32 volumio volumio[1677]: info: ----- Core plugins startup ---- Jan 11 21:24:32 volumio volumio[1677]: info: ------------------------------------------- Jan 11 21:24:32 volumio volumio[1677]: info: Loading plugins from folder /volumio/app/plugins/ Jan 11 21:24:32 volumio volumio[1677]: info: Adding plugin upnp to MyMusic Plugins Jan 11 21:24:32 volumio volumio[1677]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 11 21:24:32 volumio volumio[1677]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 11 21:24:32 volumio volumio[1677]: info: Loading plugins from folder /data/plugins/ Jan 11 21:24:32 volumio volumio[1677]: info: Loading plugin "system"... Jan 11 21:24:32 volumio volumio[1677]: info: Loading plugin "appearance"... Jan 11 21:24:32 volumio volumio[1677]: info: Loading plugin "network"... Jan 11 21:24:32 volumio volumio[1677]: info: Refreshing Cached IP Addresses Jan 11 21:24:32 volumio sudo[1751]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 21:24:32 volumio sudo[1751]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:32 volumio sudo[1751]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:32 volumio sudo[1753]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 21:24:32 volumio sudo[1753]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:32 volumio sudo[1753]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:32 volumio volumio[1677]: info: Loading plugin "services"... Jan 11 21:24:32 volumio volumio[1677]: info: Loading plugin "alsa_controller"... Jan 11 21:24:32 volumio sudo[1763]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 11 21:24:32 volumio sudo[1763]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:32 volumio kernel: ieee80211 phy0: brcmf_cfg80211_scan: Connecting: status (67) Jan 11 21:24:32 volumio sudo[1763]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:32 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 21:24:32 volumio volumio[1677]: info: Loading plugin "wizard"... Jan 11 21:24:32 volumio volumio[1677]: info: Loading plugin "networkfs"... Jan 11 21:24:32 volumio volumio[1677]: info: Cannot mount NAS Musik at system boot, trial number 1 ,retrying in 5 seconds Jan 11 21:24:32 volumio volumio[1677]: info: Starting Udev Watcher for removable devices Jan 11 21:24:32 volumio volumio[1677]: info: Ignoring mount for partition: boot Jan 11 21:24:32 volumio volumio[1677]: info: Ignoring mount for partition: volumio Jan 11 21:24:32 volumio volumio[1677]: info: Ignoring mount for partition: volumio_data Jan 11 21:24:32 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 21:24:32 volumio volumio[1677]: info: Loading plugin "volumio_command_line_client"... Jan 11 21:24:32 volumio volumio[1677]: info: Loading plugin "upnp"... Jan 11 21:24:32 volumio volumio[1677]: info: [1736627072757] Starting Upmpd Daemon Jan 11 21:24:32 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 21:24:32 volumio volumio[1677]: info: Loading plugin "my_music"... Jan 11 21:24:32 volumio volumio[1677]: info: Loading plugin "mpd"... Jan 11 21:24:32 volumio volumio[1677]: info: Loading plugin "upnp_browser"... Jan 11 21:24:33 volumio volumio[1677]: info: Loading plugin "alarm-clock"... Jan 11 21:24:33 volumio volumio[1677]: info: Loading plugin "airplay_emulation"... Jan 11 21:24:33 volumio volumio[1677]: info: Starting Shairport Sync Jan 11 21:24:33 volumio volumio[1677]: info: Loading plugin "last_100"... Jan 11 21:24:33 volumio volumio[1677]: info: Loading plugin "webradio"... Jan 11 21:24:33 volumio volumio[1677]: info: Loading plugin "i2s_dacs"... Jan 11 21:24:33 volumio volumio[1677]: info: I2S DAC not set, start Auto-detection Jan 11 21:24:33 volumio volumio[1677]: info: Loading plugin "volumiodiscovery"... Jan 11 21:24:33 volumio volumio[1677]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 21:24:33 volumio volumio[1677]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 21:24:33 volumio node[1677]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 21:24:33 volumio volumio[1677]: *** WARNING *** For more information see Jan 11 21:24:33 volumio volumio[1677]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 21:24:33 volumio volumio[1677]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 21:24:33 volumio volumio[1677]: *** WARNING *** For more information see Jan 11 21:24:33 volumio node[1677]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 21:24:33 volumio node[1677]: *** WARNING *** For more information see Jan 11 21:24:33 volumio node[1677]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 21:24:33 volumio node[1677]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 21:24:33 volumio node[1677]: *** WARNING *** For more information see Jan 11 21:24:33 volumio volumio[1677]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 11 21:24:33 volumio volumio[1677]: info: Discovery: Started advertising with name: Volumio Jan 11 21:24:33 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 21:24:33 volumio volumio[1677]: info: Loading plugin "spop"... Jan 11 21:24:33 volumio volumio[1677]: info: Loading plugin "outputs"... Jan 11 21:24:33 volumio volumio[1677]: info: Loading plugin "albumart"... Jan 11 21:24:33 volumio volumio[1677]: info: Plugin example_plugin is not enabled Jan 11 21:24:33 volumio volumio[1677]: info: Loading plugin "inputs"... Jan 11 21:24:33 volumio volumio[1677]: info: Loading plugin "updater_comm"... Jan 11 21:24:34 volumio volumio[1677]: info: Plugin mpdemulation is not enabled Jan 11 21:24:34 volumio volumio[1677]: info: Loading plugin "rest_api"... Jan 11 21:24:34 volumio volumio[1677]: info: Loading plugin "websocket"... Jan 11 21:24:34 volumio volumio[1677]: info: Starting Socket.io Server version 2.3.0 Jan 11 21:24:34 volumio volumio[1677]: info: Loading plugin "fusiondsp"... Jan 11 21:24:34 volumio volumio[1677]: Forking 3 albumart workers Jan 11 21:24:34 volumio volumio[1677]: info: Applying required configuration parameters for plugin fusiondsp Jan 11 21:24:34 volumio volumio[1677]: info: Loading i18n strings for locale da Jan 11 21:24:34 volumio volumio[1677]: Updating browse sources language Jan 11 21:24:34 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 21:24:34 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 21:24:34 volumio volumio[1677]: info: CoreCommandRouter::initPlayerControls Jan 11 21:24:34 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:34 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:34 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:34 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:34 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:34 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:34 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:34 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:34 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 21:24:34 volumio volumio[1677]: Express server listening on port 3000 Jan 11 21:24:34 volumio volumio[1677]: [Metrics] WebUI: 3s 224.17ms Jan 11 21:24:34 volumio volumio[1677]: info: CoreStateMachine::resetVolumioState Jan 11 21:24:34 volumio volumio[1677]: info: CoreStateMachine::getcurrentVolume Jan 11 21:24:34 volumio volumio[1677]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 21:24:34 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:34 volumio volumio[1677]: info: Volumio Network Manager: Network status updated: 0 Jan 11 21:24:34 volumio volumio[1677]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Jan 11 21:24:34 volumio volumio[1677]: wlan0 Interface doesn't support scanning : Resource temporarily unavailable Jan 11 21:24:34 volumio volumio[1677]: info: Cannot use regular scanning, forcing with ap-force Jan 11 21:24:34 volumio dhcpcd[1539]: wlan0: carrier acquired Jan 11 21:24:34 volumio wpa_supplicant[1519]: wlan0: Associated with ac:15:a2:d4:38:fe Jan 11 21:24:34 volumio wpa_supplicant[1519]: wlan0: CTRL-EVENT-CONNECTED - Connection to ac:15:a2:d4:38:fe completed [id=0 id_str=] Jan 11 21:24:34 volumio wpa_supplicant[1519]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Jan 11 21:24:34 volumio wpa_supplicant[1519]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE Jan 11 21:24:34 volumio dhcpcd[1539]: wlan0: IAID 32:b4:db:41 Jan 11 21:24:34 volumio dhcpcd[1539]: wlan0: carrier lost Jan 11 21:24:34 volumio sudo[1813]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Jan 11 21:24:34 volumio sudo[1813]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:34 volumio dhcpcd[1539]: wlan0: carrier acquired Jan 11 21:24:34 volumio dhcpcd[1539]: wlan0: IAID 32:b4:db:41 Jan 11 21:24:34 volumio volumio[1677]: Starting albumart workers Jan 11 21:24:34 volumio volumio[1677]: Starting albumart workers Jan 11 21:24:34 volumio volumio[1677]: Starting albumart workers Jan 11 21:24:34 volumio dhcpcd[1539]: wlan0: rebinding lease of 192.168.10.200 Jan 11 21:24:35 volumio dhcpcd[1539]: wlan0: soliciting an IPv6 router Jan 11 21:24:36 volumio go-librespot[1680]: time="2025-01-11T21:24:36+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070 (error: dial tcp: lookup ap-gew4.spotify.com: device or resource busy), retrying with a different AP" Jan 11 21:24:36 volumio go-librespot[1680]: time="2025-01-11T21:24:36+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:443 (error: dial tcp: lookup ap-gew4.spotify.com: device or resource busy), retrying with a different AP" Jan 11 21:24:36 volumio go-librespot[1680]: time="2025-01-11T21:24:36+01:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80 (error: dial tcp: lookup ap-gew4.spotify.com: device or resource busy), retrying with a different AP" Jan 11 21:24:36 volumio go-librespot[1680]: time="2025-01-11T21:24:36+01:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070 (error: dial tcp: lookup ap-guc3.spotify.com: device or resource busy), retrying with a different AP" Jan 11 21:24:36 volumio go-librespot[1680]: time="2025-01-11T21:24:36+01:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443 (error: dial tcp: lookup ap-gue1.spotify.com: device or resource busy), retrying with a different AP" Jan 11 21:24:36 volumio go-librespot[1680]: time="2025-01-11T21:24:36+01:00" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed to connect to AP ap-gew1.spotify.com:80: &{%!e(string=dial) %!e(string=tcp) %!e(*net.DNSError=&{device or resource busy ap-gew1.spotify.com false false false})}" Jan 11 21:24:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 21:24:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 21:24:38 volumio sudo[1813]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:38 volumio volumio[1677]: info: Cannot mount NAS Musik at system boot, trial number 2 ,retrying in 5 seconds Jan 11 21:24:38 volumio wpa_supplicant[1519]: RRM: Ignoring radio measurement request: Not RRM network Jan 11 21:24:38 volumio volumio[1677]: info: Reloading queue from file Jan 11 21:24:38 volumio volumio[1677]: info: CoreStateMachine::setRepeat null single undefined Jan 11 21:24:38 volumio volumio[1677]: info: CoreStateMachine::pushState Jan 11 21:24:38 volumio volumio[1677]: info: CorePlayQueue::getTrack 0 Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::volumioPushState Jan 11 21:24:38 volumio volumio[1677]: info: CoreStateMachine::setRandom null Jan 11 21:24:38 volumio volumio[1677]: info: CoreStateMachine::pushState Jan 11 21:24:38 volumio volumio[1677]: info: CorePlayQueue::getTrack 0 Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::volumioPushState Jan 11 21:24:38 volumio volumio[1677]: info: Setting Device type: Raspberry PI Jan 11 21:24:38 volumio volumio[1677]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jan 11 21:24:38 volumio volumio[1677]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d03114 Jan 11 21:24:38 volumio volumio[1677]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jan 11 21:24:38 volumio volumio[1677]: info: VolumeController:: Volume=63 Mute =false Jan 11 21:24:38 volumio volumio[1677]: info: CoreStateMachine::pushState Jan 11 21:24:38 volumio volumio[1677]: info: CorePlayQueue::getTrack 0 Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::volumioPushState Jan 11 21:24:38 volumio volumio[1677]: info: CoreStateMachine::updateTrackBlock Jan 11 21:24:38 volumio volumio[1677]: info: CorePlayQueue::getTrackBlock Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 21:24:38 volumio volumio[1677]: info: Completed loading Core Plugins Jan 11 21:24:38 volumio volumio[1677]: info: Preparing to generate the ALSA configuration file Jan 11 21:24:38 volumio volumio[1677]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 11 21:24:38 volumio volumio[1677]: info: Reading ALSA contributions from plugins. Jan 11 21:24:38 volumio volumio[1677]: info: Asound.conf file unchanged, so no further update is needed Jan 11 21:24:38 volumio volumio[1677]: info: Output device has changed, restarting MPD Jan 11 21:24:38 volumio sudo[1875]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 21:24:38 volumio sudo[1875]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:38 volumio volumio[1677]: info: Output device has changed, restarting Shairport Sync Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:38 volumio sudo[1875]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:38 volumio sudo[1883]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 21:24:38 volumio sudo[1883]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:38 volumio systemd[1]: Stopping Music Player Daemon... Jan 11 21:24:38 volumio volumio[1677]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 21:24:38 volumio volumio[1677]: info: ___________ START PLUGINS ___________ Jan 11 21:24:38 volumio volumio[1677]: info: ControllerMpd::onStart: Initializing MPD Jan 11 21:24:38 volumio volumio[1677]: info: Creating MPD Configuration file Jan 11 21:24:38 volumio systemd[1]: mpd.service: Succeeded. Jan 11 21:24:38 volumio systemd[1]: Stopped Music Player Daemon. Jan 11 21:24:38 volumio sudo[1907]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 21:24:38 volumio sudo[1907]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 21:24:38 volumio volumio[1677]: info: [1736627078562] CoreMusicLibrary::Adding element Medieservere Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:38 volumio volumio[1677]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:38 volumio sudo[1907]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:38 volumio sudo[1909]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 21:24:38 volumio sudo[1909]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:38 volumio systemd[1]: Starting Music Player Daemon... Jan 11 21:24:38 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jan 11 21:24:38 volumio systemd[1]: mpd.service: Succeeded. Jan 11 21:24:38 volumio systemd[1]: Stopped Music Player Daemon. Jan 11 21:24:38 volumio systemd[1]: Starting Music Player Daemon... Jan 11 21:24:38 volumio volumio[1677]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 21:24:38 volumio volumio[1677]: info: [1736627078647] CoreMusicLibrary::Adding element Last_100 Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 21:24:38 volumio volumio[1677]: info: [1736627078649] CoreMusicLibrary::Adding element Webradio Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 21:24:38 volumio volumio[1677]: info: Initializing BBC Radios Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:38 volumio sudo[1918]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 21:24:38 volumio sudo[1918]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:38 volumio volumio[1677]: info: Creating Spotify config file Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:38 volumio sudo[1918]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:38 volumio volumio[1677]: info: Loading i18n strings for locale da Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:38 volumio volumio[1677]: info: FusionDsp - mixtype--------------------- Hardware Jan 11 21:24:38 volumio volumio[1677]: info: Volumio Calling Home Jan 11 21:24:38 volumio volumio[1677]: info: Preparing to generate the ALSA configuration file Jan 11 21:24:38 volumio volumio[1677]: Unhandled rejection Error: No sockets available, cannot start. Jan 11 21:24:38 volumio volumio[1677]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Jan 11 21:24:38 volumio volumio[1677]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Jan 11 21:24:38 volumio volumio[1677]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Jan 11 21:24:38 volumio volumio[1677]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Jan 11 21:24:38 volumio volumio[1677]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Jan 11 21:24:38 volumio volumio[1677]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Jan 11 21:24:38 volumio volumio[1677]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Jan 11 21:24:38 volumio volumio[1677]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Jan 11 21:24:38 volumio volumio[1677]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Jan 11 21:24:38 volumio volumio[1677]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Jan 11 21:24:38 volumio volumio[1677]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Jan 11 21:24:38 volumio volumio[1677]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Jan 11 21:24:38 volumio volumio[1677]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Jan 11 21:24:38 volumio volumio[1677]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Jan 11 21:24:38 volumio volumio[1677]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Jan 11 21:24:38 volumio volumio[1677]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jan 11 21:24:38 volumio volumio[1677]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Jan 11 21:24:38 volumio volumio[1677]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 11 21:24:38 volumio volumio[1677]: info: Reading ALSA contributions from plugins. Jan 11 21:24:38 volumio volumio[1677]: info: MPD Permissions set Jan 11 21:24:38 volumio volumio[1677]: info: VolumeController:: Volume=63 Mute =false Jan 11 21:24:38 volumio volumio[1677]: info: CoreStateMachine::pushState Jan 11 21:24:38 volumio volumio[1677]: info: CorePlayQueue::getTrack 0 Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::volumioPushState Jan 11 21:24:38 volumio volumio[1677]: info: Spotify config file written Jan 11 21:24:38 volumio sudo[1935]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 11 21:24:38 volumio sudo[1935]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:38 volumio volumio[1677]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jan 11 21:24:38 volumio systemd[1]: Stopped go-librespot Daemon. Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:38 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio systemd[1]: Started go-librespot Daemon. Jan 11 21:24:39 volumio volumio[1677]: info: No need to fix Spotify hosts Jan 11 21:24:39 volumio go-librespot[1937]: Librespot-go daemon starting... Jan 11 21:24:39 volumio sudo[1935]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:39 volumio go-librespot[1937]: time="2025-01-11T21:24:39+01:00" level=info msg="generated new device id: 18d916d8d14da800afa1c5292fb7cd08aa4e7682" Jan 11 21:24:39 volumio go-librespot[1937]: time="2025-01-11T21:24:39+01:00" level=debug msg="stored credentials found for tangthomsen" Jan 11 21:24:39 volumio go-librespot[1937]: time="2025-01-11T21:24:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jan 11 21:24:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 21:24:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 21:24:39 volumio volumio[1677]: info: Starting Shairport Sync Jan 11 21:24:39 volumio volumio[1677]: info: Starting Shairport Sync Jan 11 21:24:39 volumio sudo[1953]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 21:24:39 volumio volumio[1677]: info: Starting Shairport Sync Jan 11 21:24:39 volumio sudo[1953]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:39 volumio sudo[1955]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 21:24:39 volumio sudo[1955]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:39 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 21:24:39 volumio sudo[1958]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 21:24:39 volumio sudo[1958]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::volumioGetState Jan 11 21:24:39 volumio volumio[1677]: info: CorePlayQueue::getTrack 0 Jan 11 21:24:39 volumio systemd[1]: shairport-sync.service: Succeeded. Jan 11 21:24:39 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 21:24:39 volumio volumio[1677]: info: Asound.conf file unchanged, so no further update is needed Jan 11 21:24:39 volumio volumio[1677]: info: Output device has changed, restarting MPD Jan 11 21:24:39 volumio sudo[1963]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 21:24:39 volumio sudo[1963]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:39 volumio volumio[1677]: info: Output device has changed, restarting Shairport Sync Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:39 volumio sudo[1963]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:39 volumio sudo[1965]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 21:24:39 volumio sudo[1965]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:39 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 11 21:24:39 volumio sudo[1955]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:39 volumio sudo[1953]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:39 volumio volumio[1677]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 21:24:39 volumio volumio[1677]: info: MPD Permissions set Jan 11 21:24:39 volumio volumio[1677]: info: Shairport-Sync Started Jan 11 21:24:39 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 21:24:39 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jan 11 21:24:39 volumio systemd[1]: mpd.service: Succeeded. Jan 11 21:24:39 volumio volumio[1677]: Error adding Membership: Error: addMembership EINVAL Jan 11 21:24:39 volumio systemd[1]: Stopped Music Player Daemon. Jan 11 21:24:39 volumio volumio[1677]: info: Shairport-Sync Started Jan 11 21:24:39 volumio systemd[1]: shairport-sync.service: Succeeded. Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 11 21:24:39 volumio sudo[1958]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:39 volumio systemd[1]: Starting Music Player Daemon... Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:39 volumio volumio[1677]: info: Shairport-Sync Started Jan 11 21:24:39 volumio volumio[1677]: info: Starting Shairport Sync Jan 11 21:24:39 volumio sudo[1981]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 21:24:39 volumio sudo[1981]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:39 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 21:24:39 volumio systemd[1]: shairport-sync.service: Succeeded. Jan 11 21:24:39 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 21:24:39 volumio sudo[1975]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 21:24:39 volumio sudo[1975]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:39 volumio sudo[1975]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:39 volumio dhcpcd[1539]: wlan0: probing address 192.168.10.200/24 Jan 11 21:24:39 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 11 21:24:39 volumio sudo[1981]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:39 volumio volumio[1677]: info: Shairport-Sync Started Jan 11 21:24:40 volumio volumio-remote-updater[639]: [2025-01-11 21:24:40] [connect] Successful connection Jan 11 21:24:40 volumio volumio[1677]: 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: 2 Jan 11 21:24:40 volumio volumio-remote-updater[639]: [2025-01-11 21:24:40] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1736627080 101 Jan 11 21:24:40 volumio mpd[1987]: Jan 11 21:24 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 21:24:40 volumio systemd[1]: Started Music Player Daemon. Jan 11 21:24:40 volumio sudo[1883]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:40 volumio sudo[1965]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:40 volumio sudo[1909]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:40 volumio volumio[1677]: info: Completed starting Core Plugins Jan 11 21:24:40 volumio volumio[1677]: info: ------------------------------------------- Jan 11 21:24:40 volumio volumio[1677]: info: ----- MyVolumio plugins startup ---- Jan 11 21:24:40 volumio volumio[1677]: info: ------------------------------------------- Jan 11 21:24:40 volumio volumio[1677]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 11 21:24:40 volumio volumio[1677]: error: MPD error: The expression evaluated to a falsy value: Jan 11 21:24:40 volumio volumio[1677]: assert.ok(self.idling) Jan 11 21:24:40 volumio volumio[1677]: error: The expression evaluated to a falsy value: Jan 11 21:24:40 volumio volumio[1677]: assert.ok(self.idling) Jan 11 21:24:40 volumio volumio[1677]: error: MPD error: The expression evaluated to a falsy value: Jan 11 21:24:40 volumio volumio[1677]: assert.ok(self.idling) Jan 11 21:24:40 volumio volumio[1677]: error: The expression evaluated to a falsy value: Jan 11 21:24:40 volumio volumio[1677]: assert.ok(self.idling) Jan 11 21:24:40 volumio volumio[1677]: info: MPD running with PID1987 Jan 11 21:24:40 volumio volumio[1677]: ,establishing connection Jan 11 21:24:40 volumio volumio[1677]: error: updateQueue error: null Jan 11 21:24:40 volumio volumio[1677]: error: updateQueue error: null Jan 11 21:24:40 volumio volumio[1677]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Jan 11 21:24:40 volumio volumio[1677]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo Jan 11 21:24:40 volumio volumio[1677]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Jan 11 21:24:40 volumio volumio[1677]: info: camilladsp spawned new process with pid undefined, instance 1, run: true Jan 11 21:24:40 volumio volumio[1677]: info: camilladsp service started and running in background, instance 1 Jan 11 21:24:40 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:40 volumio volumio[1677]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Jan 11 21:24:40 volumio volumio[1677]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Jan 11 21:24:40 volumio volumio[1677]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Jan 11 21:24:40 volumio volumio[1677]: info: FusionDsp loaded Jan 11 21:24:40 volumio volumio[1677]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 21:24:40 volumio sudo[2004]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jan 11 21:24:40 volumio sudo[2004]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:40 volumio volumio[1677]: info: FusionDsp - Reporting Fusion DSP Enabled Jan 11 21:24:40 volumio volumio[1677]: info: Adding Signal Path Element [object Object] Jan 11 21:24:40 volumio volumio[1677]: info: Adding fusiondspeq DSP Signal Path Element Jan 11 21:24:40 volumio volumio[1677]: info: FusionDsp - ---- installed callbackRead Jan 11 21:24:40 volumio volumio[1677]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 21:24:40 volumio sudo[2004]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:40 volumio volumio[1677]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp ENOENT Jan 11 21:24:40 volumio volumio[1677]: at Process.ChildProcess._handle.onexit (internal/child_process.js:269:19) Jan 11 21:24:40 volumio volumio[1677]: at onErrorNT (internal/child_process.js:465:16) Jan 11 21:24:40 volumio volumio[1677]: at processTicksAndRejections (internal/process/task_queues.js:80:21) { Jan 11 21:24:40 volumio volumio[1677]: errno: -2, Jan 11 21:24:40 volumio volumio[1677]: code: 'ENOENT', Jan 11 21:24:40 volumio volumio[1677]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', Jan 11 21:24:40 volumio volumio[1677]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', Jan 11 21:24:40 volumio volumio[1677]: spawnargs: [ Jan 11 21:24:40 volumio volumio[1677]: '-p', Jan 11 21:24:40 volumio volumio[1677]: 9876, Jan 11 21:24:40 volumio volumio[1677]: '-o', Jan 11 21:24:40 volumio volumio[1677]: '/tmp/camilladsp.log', Jan 11 21:24:40 volumio volumio[1677]: '-l', Jan 11 21:24:40 volumio volumio[1677]: 'warn', Jan 11 21:24:40 volumio volumio[1677]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' Jan 11 21:24:40 volumio volumio[1677]: ] Jan 11 21:24:40 volumio volumio[1677]: } Jan 11 21:24:40 volumio volumio[1677]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 21:24:41 volumio sudo[2015]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-11 21:23 Jan 11 21:24:41 volumio sudo[2015]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:41 volumio sudo[2015]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:41 volumio volumio-remote-updater[639]: [2025-01-11 21:24:41] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 11 21:24:41 volumio volumio-remote-updater[639]: [2025-01-11 21:24:41] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 11 21:24:41 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 11 21:24:41 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 11 21:24:41 volumio systemd[1]: Started dynamicswap service. Jan 11 21:24:41 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 21:24:41 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jan 11 21:24:41 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Jan 11 21:24:41 volumio systemd[1]: Stopped Volumio Backend Module. Jan 11 21:24:41 volumio systemd[1]: Started Volumio Backend Module. Jan 11 21:24:41 volumio systemd[1]: Started dynamicswap service. Jan 11 21:24:41 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 11 21:24:42 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 11 21:24:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 11 21:24:42 volumio systemd[1]: Stopped go-librespot Daemon. Jan 11 21:24:42 volumio systemd[1]: Started go-librespot Daemon. Jan 11 21:24:42 volumio go-librespot[2044]: Librespot-go daemon starting... Jan 11 21:24:42 volumio go-librespot[2044]: time="2025-01-11T21:24:42+01:00" level=info msg="generated new device id: 788a98ca8d669be19b6a82dde5a7a89dd9e50fe5" Jan 11 21:24:42 volumio go-librespot[2044]: time="2025-01-11T21:24:42+01:00" level=debug msg="stored credentials found for tangthomsen" Jan 11 21:24:42 volumio go-librespot[2044]: time="2025-01-11T21:24:42+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Jan 11 21:24:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 11 21:24:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 11 21:24:42 volumio volumio[2031]: info: ------------------------------------------- Jan 11 21:24:42 volumio volumio[2031]: info: ----- Volumio3 ---- Jan 11 21:24:42 volumio volumio[2031]: info: ------------------------------------------- Jan 11 21:24:42 volumio volumio[2031]: info: ----- System startup ---- Jan 11 21:24:42 volumio volumio[2031]: info: ------------------------------------------- Jan 11 21:24:43 volumio volumio[2031]: info: MYVOLUMIO Environment detected Jan 11 21:24:43 volumio volumio[2031]: info: Plugin folders cleanup Jan 11 21:24:43 volumio volumio[2031]: info: Scanning into folder /volumio/app/plugins/ Jan 11 21:24:43 volumio volumio[2031]: info: Scanning category audio_interface Jan 11 21:24:43 volumio volumio[2031]: info: Scanning category miscellanea Jan 11 21:24:43 volumio volumio[2031]: info: Scanning category music_service Jan 11 21:24:43 volumio volumio[2031]: info: Scanning category plugins.json Jan 11 21:24:43 volumio volumio[2031]: info: Scanning category system_controller Jan 11 21:24:43 volumio volumio[2031]: info: Scanning category user_interface Jan 11 21:24:43 volumio volumio[2031]: info: Scanning into folder /data/plugins/ Jan 11 21:24:43 volumio volumio[2031]: info: Scanning category audio_interface Jan 11 21:24:43 volumio volumio[2031]: info: Scanning category music_service Jan 11 21:24:43 volumio volumio[2031]: info: Plugin folders cleanup completed Jan 11 21:24:43 volumio volumio[2031]: info: ------------------------------------------- Jan 11 21:24:43 volumio volumio[2031]: info: ----- Core plugins startup ---- Jan 11 21:24:43 volumio volumio[2031]: info: ------------------------------------------- Jan 11 21:24:43 volumio volumio[2031]: info: Loading plugins from folder /volumio/app/plugins/ Jan 11 21:24:43 volumio volumio[2031]: info: Adding plugin upnp to MyMusic Plugins Jan 11 21:24:43 volumio volumio[2031]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 11 21:24:43 volumio volumio[2031]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 11 21:24:43 volumio volumio[2031]: info: Loading plugins from folder /data/plugins/ Jan 11 21:24:43 volumio volumio[2031]: info: Loading plugin "system"... Jan 11 21:24:43 volumio volumio[2031]: info: Loading plugin "appearance"... Jan 11 21:24:43 volumio volumio[2031]: info: Loading plugin "network"... Jan 11 21:24:43 volumio volumio[2031]: info: Refreshing Cached IP Addresses Jan 11 21:24:43 volumio sudo[2066]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 11 21:24:43 volumio sudo[2066]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:43 volumio sudo[2066]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:43 volumio sudo[2068]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 11 21:24:43 volumio sudo[2068]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:43 volumio sudo[2068]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:43 volumio volumio[2031]: info: Loading plugin "services"... Jan 11 21:24:43 volumio volumio[2031]: info: Loading plugin "alsa_controller"... Jan 11 21:24:43 volumio sudo[2077]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 11 21:24:43 volumio sudo[2077]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:43 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 21:24:43 volumio volumio[2031]: info: Loading plugin "wizard"... Jan 11 21:24:43 volumio volumio[2031]: info: Loading plugin "networkfs"... Jan 11 21:24:43 volumio volumio[2031]: info: Cannot mount NAS Musik at system boot, trial number 1 ,retrying in 5 seconds Jan 11 21:24:43 volumio volumio[2031]: info: Starting Udev Watcher for removable devices Jan 11 21:24:43 volumio volumio[2031]: info: Ignoring mount for partition: boot Jan 11 21:24:43 volumio volumio[2031]: info: Ignoring mount for partition: volumio Jan 11 21:24:43 volumio volumio[2031]: info: Ignoring mount for partition: volumio_data Jan 11 21:24:43 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 21:24:43 volumio volumio[2031]: info: Loading plugin "volumio_command_line_client"... Jan 11 21:24:43 volumio volumio[2031]: info: Loading plugin "upnp"... Jan 11 21:24:43 volumio volumio[2031]: info: [1736627083864] Starting Upmpd Daemon Jan 11 21:24:43 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 21:24:43 volumio volumio[2031]: info: Loading plugin "my_music"... Jan 11 21:24:43 volumio volumio[2031]: info: Loading plugin "mpd"... Jan 11 21:24:44 volumio volumio[2031]: info: Loading plugin "upnp_browser"... Jan 11 21:24:44 volumio volumio[2031]: info: Loading plugin "alarm-clock"... Jan 11 21:24:44 volumio volumio[2031]: info: Loading plugin "airplay_emulation"... Jan 11 21:24:44 volumio volumio[2031]: info: Starting Shairport Sync Jan 11 21:24:44 volumio volumio[2031]: info: Loading plugin "last_100"... Jan 11 21:24:44 volumio volumio[2031]: info: Loading plugin "webradio"... Jan 11 21:24:44 volumio volumio[2031]: info: Loading plugin "i2s_dacs"... Jan 11 21:24:44 volumio volumio[2031]: info: I2S DAC not set, start Auto-detection Jan 11 21:24:44 volumio volumio[2031]: info: Loading plugin "volumiodiscovery"... Jan 11 21:24:44 volumio volumio[2031]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 21:24:44 volumio volumio[2031]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 21:24:44 volumio node[2031]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 11 21:24:44 volumio volumio[2031]: *** WARNING *** For more information see Jan 11 21:24:44 volumio volumio[2031]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 21:24:44 volumio volumio[2031]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 21:24:44 volumio volumio[2031]: *** WARNING *** For more information see Jan 11 21:24:44 volumio node[2031]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 21:24:44 volumio node[2031]: *** WARNING *** For more information see Jan 11 21:24:44 volumio node[2031]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 11 21:24:44 volumio node[2031]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 11 21:24:44 volumio node[2031]: *** WARNING *** For more information see Jan 11 21:24:44 volumio volumio[2031]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 11 21:24:44 volumio volumio[2031]: info: Discovery: Started advertising with name: Volumio Jan 11 21:24:44 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 11 21:24:44 volumio volumio[2031]: info: Loading plugin "spop"... Jan 11 21:24:44 volumio dhcpcd[1539]: wlan0: leased 192.168.10.200 for 3600 seconds Jan 11 21:24:44 volumio avahi-daemon[609]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.10.200. Jan 11 21:24:44 volumio dhcpcd[1539]: wlan0: adding route to 192.168.10.0/24 Jan 11 21:24:44 volumio dhcpcd[1539]: wlan0: adding default route via 192.168.10.1 Jan 11 21:24:44 volumio avahi-daemon[609]: New relevant interface wlan0.IPv4 for mDNS. Jan 11 21:24:44 volumio avahi-daemon[609]: Registering new address record for 192.168.10.200 on wlan0.IPv4. Jan 11 21:24:45 volumio volumio[2031]: info: Loading plugin "outputs"... Jan 11 21:24:45 volumio volumio[2031]: info: Loading plugin "albumart"... Jan 11 21:24:45 volumio volumio[2031]: info: Plugin example_plugin is not enabled Jan 11 21:24:45 volumio volumio[2031]: info: Loading plugin "inputs"... Jan 11 21:24:45 volumio volumio[2031]: info: Loading plugin "updater_comm"... Jan 11 21:24:45 volumio volumio[2031]: info: Plugin mpdemulation is not enabled Jan 11 21:24:45 volumio volumio[2031]: info: Loading plugin "rest_api"... Jan 11 21:24:45 volumio volumio[2031]: info: Loading plugin "websocket"... Jan 11 21:24:45 volumio volumio[2031]: info: Starting Socket.io Server version 2.3.0 Jan 11 21:24:45 volumio volumio[2031]: info: Loading plugin "fusiondsp"... Jan 11 21:24:45 volumio volumio[2031]: Forking 3 albumart workers Jan 11 21:24:45 volumio volumio[2031]: info: Applying required configuration parameters for plugin fusiondsp Jan 11 21:24:45 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Jan 11 21:24:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 11 21:24:45 volumio volumio[2031]: info: Loading i18n strings for locale da Jan 11 21:24:45 volumio systemd[1]: Stopped go-librespot Daemon. Jan 11 21:24:45 volumio systemd[1]: Started go-librespot Daemon. Jan 11 21:24:45 volumio go-librespot[2144]: Librespot-go daemon starting... Jan 11 21:24:45 volumio volumio[2031]: Updating browse sources language Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 21:24:45 volumio go-librespot[2144]: time="2025-01-11T21:24:45+01:00" level=info msg="generated new device id: 5db0369615191dced4e3e7671a416a0b802ad605" Jan 11 21:24:45 volumio go-librespot[2144]: time="2025-01-11T21:24:45+01:00" level=debug msg="stored credentials found for tangthomsen" Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::initPlayerControls Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 21:24:45 volumio volumio[2031]: Express server listening on port 3000 Jan 11 21:24:45 volumio volumio[2031]: [Metrics] WebUI: 3s 219.98ms Jan 11 21:24:45 volumio volumio[2031]: info: CoreStateMachine::resetVolumioState Jan 11 21:24:45 volumio volumio[2031]: info: CoreStateMachine::getcurrentVolume Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:45 volumio volumio[2031]: info: Volumio Network Manager: Network status updated: 0 Jan 11 21:24:45 volumio volumio[2031]: Starting albumart workers Jan 11 21:24:45 volumio volumio[2031]: info: Reloading queue from file Jan 11 21:24:45 volumio volumio[2031]: info: CoreStateMachine::setRepeat null single undefined Jan 11 21:24:45 volumio volumio[2031]: info: CoreStateMachine::pushState Jan 11 21:24:45 volumio volumio[2031]: info: CorePlayQueue::getTrack 0 Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::volumioPushState Jan 11 21:24:45 volumio volumio[2031]: info: CoreStateMachine::setRandom null Jan 11 21:24:45 volumio volumio[2031]: info: CoreStateMachine::pushState Jan 11 21:24:45 volumio volumio[2031]: info: CorePlayQueue::getTrack 0 Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::volumioPushState Jan 11 21:24:45 volumio volumio[2031]: info: Setting Device type: Raspberry PI Jan 11 21:24:45 volumio volumio[2031]: info: VolumeController:: Volume=63 Mute =false Jan 11 21:24:45 volumio volumio[2031]: info: CoreStateMachine::pushState Jan 11 21:24:45 volumio volumio[2031]: info: CorePlayQueue::getTrack 0 Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::volumioPushState Jan 11 21:24:45 volumio volumio[2031]: info: CoreStateMachine::updateTrackBlock Jan 11 21:24:45 volumio volumio[2031]: info: CorePlayQueue::getTrackBlock Jan 11 21:24:45 volumio volumio[2031]: info: CoreCommandRouter::volumioRetrievevolume Jan 11 21:24:45 volumio volumio[2031]: Starting albumart workers Jan 11 21:24:45 volumio volumio[2031]: Starting albumart workers Jan 11 21:24:45 volumio volumio[2031]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jan 11 21:24:45 volumio volumio[2031]: info: USB Boot Capable - System SBC Revision found in cpuinfo: d03114 Jan 11 21:24:45 volumio volumio[2031]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jan 11 21:24:45 volumio volumio[2031]: info: Completed loading Core Plugins Jan 11 21:24:46 volumio volumio[2031]: info: Preparing to generate the ALSA configuration file Jan 11 21:24:46 volumio volumio[2031]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 11 21:24:46 volumio volumio[2031]: info: Reading ALSA contributions from plugins. Jan 11 21:24:46 volumio volumio[2031]: info: VolumeController:: Volume=63 Mute =false Jan 11 21:24:46 volumio volumio[2031]: info: CoreStateMachine::pushState Jan 11 21:24:46 volumio volumio[2031]: info: CorePlayQueue::getTrack 0 Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::volumioPushState Jan 11 21:24:46 volumio go-librespot[2144]: time="2025-01-11T21:24:46+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 11 21:24:46 volumio go-librespot[2144]: time="2025-01-11T21:24:46+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 11 21:24:46 volumio go-librespot[2144]: time="2025-01-11T21:24:46+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 11 21:24:46 volumio go-librespot[2144]: time="2025-01-11T21:24:46+01:00" level=debug msg="zeroconf server listening on port 35241" Jan 11 21:24:46 volumio volumio[2031]: info: Asound.conf file unchanged, so no further update is needed Jan 11 21:24:46 volumio volumio[2031]: info: Output device has changed, restarting MPD Jan 11 21:24:46 volumio volumio[2031]: info: Output device has changed, restarting Shairport Sync Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:46 volumio sudo[2165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 21:24:46 volumio sudo[2165]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:46 volumio sudo[2165]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:46 volumio sudo[2168]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 21:24:46 volumio sudo[2168]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:46 volumio systemd[1]: Stopping Music Player Daemon... Jan 11 21:24:46 volumio systemd[1]: mpd.service: Succeeded. Jan 11 21:24:46 volumio systemd[1]: Stopped Music Player Daemon. Jan 11 21:24:46 volumio volumio[2031]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 21:24:46 volumio volumio[2031]: info: ___________ START PLUGINS ___________ Jan 11 21:24:46 volumio volumio[2031]: info: ControllerMpd::onStart: Initializing MPD Jan 11 21:24:46 volumio volumio[2031]: info: Creating MPD Configuration file Jan 11 21:24:46 volumio sudo[2175]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 21:24:46 volumio sudo[2175]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:46 volumio systemd[1]: Starting Music Player Daemon... Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 21:24:46 volumio volumio[2031]: info: [1736627086229] CoreMusicLibrary::Adding element Medieservere Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 21:24:46 volumio ntpd[810]: Listen normally on 4 wlan0 192.168.10.200:123 Jan 11 21:24:46 volumio ntpd[810]: new interface(s) found: waking up resolver Jan 11 21:24:46 volumio sudo[2175]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:46 volumio sudo[2178]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 21:24:46 volumio sudo[2178]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:46 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jan 11 21:24:46 volumio systemd[1]: mpd.service: Succeeded. Jan 11 21:24:46 volumio systemd[1]: Stopped Music Player Daemon. Jan 11 21:24:46 volumio systemd[1]: Starting Music Player Daemon... Jan 11 21:24:46 volumio volumio-remote-updater[639]: [2025-01-11 21:24:46] [connect] Successful connection Jan 11 21:24:46 volumio volumio[2031]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:46 volumio sudo[2183]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 21:24:46 volumio go-librespot[2144]: time="2025-01-11T21:24:46+01:00" level=debug msg="obtained new client token: AADcn6Luy4COy5pI9rff7RAU/RE8D5yme5Tcw6t2wgMzSSNLGtPNciNIS1RIDpQNxVeLzy01o1fjGZBpL667xoyn9CTM2bs8wFNdOsJk1Wk9HK0LgtB6OilzMLDD7VsDYkwD/G7ztNaWB1ctjZ4D9jclh3MwNO2Lgh2oAbXOZzkHIv+pLsfD1ZAuh4NWF6h8vqEyXE8vs1NRkq5lYS50eATd7JXBMpA5MfFFX0V+7dV+uasNnyFHn4am4/fMJQI=" Jan 11 21:24:46 volumio sudo[2183]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:46 volumio sudo[2183]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:46 volumio volumio[2031]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 21:24:46 volumio volumio[2031]: info: [1736627086391] CoreMusicLibrary::Adding element Last_100 Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 21:24:46 volumio volumio[2031]: info: [1736627086395] CoreMusicLibrary::Adding element Webradio Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 21:24:46 volumio volumio[2031]: info: Initializing BBC Radios Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: Creating Spotify config file Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio go-librespot[2144]: time="2025-01-11T21:24:46+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Jan 11 21:24:46 volumio volumio[2031]: info: Loading i18n strings for locale da Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: FusionDsp - mixtype--------------------- Hardware Jan 11 21:24:46 volumio volumio[2031]: info: Volumio Calling Home Jan 11 21:24:46 volumio volumio[2031]: info: Preparing to generate the ALSA configuration file Jan 11 21:24:46 volumio volumio[2031]: info: Discovery: adding 042b604b-850b-49a5-bb72-d24fc067b41f Jan 11 21:24:46 volumio volumio[2031]: info: Discovery: Found device Volumio Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::volumioGetState Jan 11 21:24:46 volumio volumio[2031]: info: CorePlayQueue::getTrack 0 Jan 11 21:24:46 volumio volumio[2031]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jan 11 21:24:46 volumio volumio[2031]: info: Reading ALSA contributions from plugins. Jan 11 21:24:46 volumio volumio[2031]: info: MPD Permissions set Jan 11 21:24:46 volumio volumio[2031]: info: MPD Permissions set Jan 11 21:24:46 volumio volumio-remote-updater[639]: [2025-01-11 21:24:46] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1736627086 101 Jan 11 21:24:46 volumio ntpd[810]: Soliciting pool server 213.32.246.229 Jan 11 21:24:46 volumio volumio[2031]: 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 Jan 11 21:24:46 volumio volumio[2031]: info: Spotify config file written Jan 11 21:24:46 volumio sudo[2227]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 11 21:24:46 volumio volumio[2031]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 11 21:24:46 volumio sudo[2227]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio go-librespot[2144]: time="2025-01-11T21:24:46+01:00" level=debug msg="completed keyexchange" Jan 11 21:24:46 volumio systemd[1]: Stopping go-librespot Daemon... Jan 11 21:24:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Jan 11 21:24:46 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Jan 11 21:24:46 volumio systemd[1]: Stopped go-librespot Daemon. Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:46 volumio volumio[2031]: info: No need to fix Spotify hosts Jan 11 21:24:46 volumio systemd[1]: Started go-librespot Daemon. Jan 11 21:24:46 volumio go-librespot[2233]: Librespot-go daemon starting... Jan 11 21:24:46 volumio sudo[2227]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:46 volumio go-librespot[2233]: time="2025-01-11T21:24:46+01:00" level=info msg="generated new device id: 0c5d55b97eaceadc86b56ed622ee5cb10fb5b4c3" Jan 11 21:24:46 volumio go-librespot[2233]: time="2025-01-11T21:24:46+01:00" level=debug msg="stored credentials found for tangthomsen" Jan 11 21:24:46 volumio volumio[2031]: info: Starting Shairport Sync Jan 11 21:24:46 volumio volumio[2031]: info: Starting Shairport Sync Jan 11 21:24:46 volumio sudo[2246]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 21:24:46 volumio sudo[2246]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:46 volumio volumio[2031]: info: Starting Shairport Sync Jan 11 21:24:46 volumio sudo[2248]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 21:24:46 volumio sudo[2248]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:46 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 21:24:46 volumio systemd[1]: shairport-sync.service: Succeeded. Jan 11 21:24:46 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 21:24:46 volumio sudo[2252]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 21:24:46 volumio sudo[2252]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:46 volumio volumio[2031]: info: CoreCommandRouter::volumioGetState Jan 11 21:24:46 volumio volumio[2031]: info: CorePlayQueue::getTrack 0 Jan 11 21:24:46 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 11 21:24:46 volumio sudo[2246]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:47 volumio volumio[2031]: info: Volumio called home Jan 11 21:24:47 volumio volumio[2031]: info: Asound.conf file unchanged, so no further update is needed Jan 11 21:24:47 volumio volumio[2031]: info: Output device has changed, restarting MPD Jan 11 21:24:47 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 21:24:47 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Jan 11 21:24:47 volumio systemd[1]: shairport-sync.service: Succeeded. Jan 11 21:24:47 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 21:24:47 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jan 11 21:24:47 volumio sudo[2248]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:47 volumio sudo[2252]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:47 volumio sudo[2257]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 11 21:24:47 volumio sudo[2257]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:47 volumio volumio[2031]: info: Output device has changed, restarting Shairport Sync Jan 11 21:24:47 volumio sudo[2257]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:47 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:47 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:47 volumio sudo[2260]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 11 21:24:47 volumio sudo[2260]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:47 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jan 11 21:24:47 volumio systemd[1]: mpd.service: Succeeded. Jan 11 21:24:47 volumio systemd[1]: Stopped Music Player Daemon. Jan 11 21:24:47 volumio systemd[1]: Starting Music Player Daemon... Jan 11 21:24:47 volumio volumio[2031]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 11 21:24:47 volumio volumio[2031]: info: Shairport-Sync Started Jan 11 21:24:47 volumio volumio[2031]: Error adding Membership: Error: addMembership EINVAL Jan 11 21:24:47 volumio volumio[2031]: info: MPD Permissions set Jan 11 21:24:47 volumio volumio[2031]: info: Shairport-Sync Started Jan 11 21:24:47 volumio volumio[2031]: info: Shairport-Sync Started Jan 11 21:24:47 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:47 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:47 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:47 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:47 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:47 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:47 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:47 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:47 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 11 21:24:47 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:47 volumio volumio[2031]: info: Starting Shairport Sync Jan 11 21:24:47 volumio sudo[2267]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 11 21:24:47 volumio sudo[2267]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:47 volumio sudo[2273]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 11 21:24:47 volumio sudo[2273]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:47 volumio sudo[2267]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:47 volumio ntpd[810]: Soliciting pool server 217.198.219.102 Jan 11 21:24:47 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jan 11 21:24:47 volumio systemd[1]: shairport-sync.service: Succeeded. Jan 11 21:24:47 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jan 11 21:24:47 volumio systemd[1]: shairport-sync.service: Start request repeated too quickly. Jan 11 21:24:47 volumio systemd[1]: shairport-sync.service: Failed with result 'start-limit-hit'. Jan 11 21:24:47 volumio systemd[1]: Failed to start Shairport Sync - AirPlay Audio Receiver. Jan 11 21:24:47 volumio sudo[2273]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:47 volumio volumio[2031]: info: Shairport-sync error: Error: Command failed: /usr/bin/sudo /bin/systemctl restart shairport-sync Jan 11 21:24:47 volumio volumio[2031]: Job for shairport-sync.service failed. Jan 11 21:24:47 volumio volumio[2031]: See "systemctl status shairport-sync.service" and "journalctl -xe" for details. Jan 11 21:24:47 volumio volumio[2031]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 11 21:24:47 volumio volumio[2031]: SPOTIFY: BQD3e8_Ed2uuOC6NU7RfhO9KFsRCZ6UYKa36G329fCF5dXq6DEk3Y3-lllL07bEYAfGzXYpwnGfbSN49AAAcKiIURjPA-BsHTHhKR316ZVAh8OMHnfwA2yeUlONfP2ZpcorPkj2346aDKfQu_74cmuATuhkeR95k-nCvLPI5XOdOxTpZoZO3SzmtOCQahx4XVeAC9_LrkL3GQujZu_Il0hBqUyEWP0EBnlef8IMYkUFY4F92g2lmdrorNg Jan 11 21:24:47 volumio volumio[2031]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 11 21:24:47 volumio volumio[2031]: info: New Spotify access token = BQD3e8_Ed2uuOC6NU7RfhO9KFsRCZ6UYKa36G329fCF5dXq6DEk3Y3-lllL07bEYAfGzXYpwnGfbSN49AAAcKiIURjPA-BsHTHhKR316ZVAh8OMHnfwA2yeUlONfP2ZpcorPkj2346aDKfQu_74cmuATuhkeR95k-nCvLPI5XOdOxTpZoZO3SzmtOCQahx4XVeAC9_LrkL3GQujZu_Il0hBqUyEWP0EBnlef8IMYkUFY4F92g2lmdrorNg Jan 11 21:24:47 volumio volumio[2031]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 11 21:24:47 volumio sudo[2077]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:47 volumio ntpd[810]: Soliciting pool server 162.159.200.1 Jan 11 21:24:47 volumio ntpd[810]: Soliciting pool server 193.200.91.90 Jan 11 21:24:47 volumio go-librespot[2233]: time="2025-01-11T21:24:47+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 11 21:24:47 volumio go-librespot[2233]: time="2025-01-11T21:24:47+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 11 21:24:47 volumio go-librespot[2233]: time="2025-01-11T21:24:47+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 11 21:24:47 volumio go-librespot[2233]: time="2025-01-11T21:24:47+01:00" level=debug msg="zeroconf server listening on port 37421" Jan 11 21:24:47 volumio volumio[2031]: SPOTIFY: User informations: {"country":"DK","display_name":"tangthomsen","email":"tangthomsen@outlook.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/tangthomsen"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/tangthomsen","id":"tangthomsen","images":[],"product":"premium","type":"user","uri":"spotify:user:tangthomsen"} Jan 11 21:24:47 volumio volumio[2031]: info: Spotify Successfully logged in Jan 11 21:24:47 volumio volumio[2031]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 11 21:24:47 volumio volumio[2031]: info: [1736627087641] CoreMusicLibrary::Adding element Spotify Jan 11 21:24:47 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 11 21:24:47 volumio volumio[2031]: Cannot find translation for source Spotify Jan 11 21:24:47 volumio wpa_supplicant[1519]: RRM: Ignoring radio measurement request: Not RRM network Jan 11 21:24:47 volumio mpd[2276]: Jan 11 21:24 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 11 21:24:47 volumio systemd[1]: Started Music Player Daemon. Jan 11 21:24:47 volumio sudo[2168]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:47 volumio sudo[2178]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:47 volumio sudo[2260]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:47 volumio volumio[2031]: info: Completed starting Core Plugins Jan 11 21:24:47 volumio volumio[2031]: info: ------------------------------------------- Jan 11 21:24:47 volumio volumio[2031]: info: ----- MyVolumio plugins startup ---- Jan 11 21:24:47 volumio volumio[2031]: info: ------------------------------------------- Jan 11 21:24:47 volumio volumio[2031]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 11 21:24:47 volumio go-librespot[2233]: time="2025-01-11T21:24:47+01:00" level=debug msg="obtained new client token: AACxECm9z5ZZUsHdkEQH8fROx3fc/Ns/ptS78wTCbhNFCM/ywX8i0OLtVFXVCYF9iQ/dsqE8r2WC2J6gYBdvzlmcqfi8gnRxK0ejrmaxrk/MR75/dF+0c4gKUs8Y0RkV/XPfjFe1WcR6f/6wLlm0VX4C5ITKYE6oeUx3kVeOTqy99giThOCVyGwgNshGFkC+mIIGJgL9DBn1XPf4k0LookquRyx2MGU9GyB5zhPrSrCp6lEGDMad0F/c7ZX8xRY=" Jan 11 21:24:47 volumio volumio[2031]: error: MPD error: The expression evaluated to a falsy value: Jan 11 21:24:47 volumio volumio[2031]: assert.ok(self.idling) Jan 11 21:24:47 volumio volumio[2031]: error: The expression evaluated to a falsy value: Jan 11 21:24:47 volumio volumio[2031]: assert.ok(self.idling) Jan 11 21:24:48 volumio volumio[2031]: info: MPD running with PID2276 Jan 11 21:24:48 volumio volumio[2031]: ,establishing connection Jan 11 21:24:48 volumio volumio[2031]: error: MPD error: The expression evaluated to a falsy value: Jan 11 21:24:48 volumio volumio[2031]: assert.ok(self.idling) Jan 11 21:24:48 volumio volumio[2031]: error: The expression evaluated to a falsy value: Jan 11 21:24:48 volumio volumio[2031]: assert.ok(self.idling) Jan 11 21:24:48 volumio volumio[2031]: error: MPD error: The expression evaluated to a falsy value: Jan 11 21:24:48 volumio volumio[2031]: assert.ok(self.idling) Jan 11 21:24:48 volumio volumio[2031]: error: The expression evaluated to a falsy value: Jan 11 21:24:48 volumio volumio[2031]: assert.ok(self.idling) Jan 11 21:24:48 volumio volumio[2031]: error: updateQueue error: null Jan 11 21:24:48 volumio go-librespot[2233]: time="2025-01-11T21:24:48+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Jan 11 21:24:48 volumio go-librespot[2233]: time="2025-01-11T21:24:48+01:00" level=debug msg="completed keyexchange" Jan 11 21:24:48 volumio ntpd[810]: Soliciting pool server 185.181.223.169 Jan 11 21:24:48 volumio ntpd[810]: Soliciting pool server 85.191.193.248 Jan 11 21:24:48 volumio ntpd[810]: Soliciting pool server 213.5.39.34 Jan 11 21:24:48 volumio volumio[2031]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Jan 11 21:24:48 volumio volumio[2031]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo Jan 11 21:24:48 volumio volumio[2031]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Jan 11 21:24:48 volumio volumio[2031]: info: camilladsp spawned new process with pid undefined, instance 1, run: true Jan 11 21:24:48 volumio volumio[2031]: info: camilladsp service started and running in background, instance 1 Jan 11 21:24:48 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 11 21:24:48 volumio volumio[2031]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Jan 11 21:24:48 volumio volumio[2031]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Jan 11 21:24:48 volumio volumio[2031]: /bin/sh: 1: /data/plugins/audio_interface/fusiondsp/hw_params: not found Jan 11 21:24:48 volumio volumio[2031]: info: FusionDsp loaded Jan 11 21:24:48 volumio volumio[2031]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 11 21:24:48 volumio sudo[2293]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jan 11 21:24:48 volumio sudo[2293]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:48 volumio go-librespot[2233]: time="2025-01-11T21:24:48+01:00" level=debug msg="completed challenge" Jan 11 21:24:48 volumio volumio[2031]: info: FusionDsp - Reporting Fusion DSP Enabled Jan 11 21:24:48 volumio volumio[2031]: info: Adding Signal Path Element [object Object] Jan 11 21:24:48 volumio volumio[2031]: info: Adding fusiondspeq DSP Signal Path Element Jan 11 21:24:48 volumio volumio[2031]: info: FusionDsp - ---- installed callbackRead Jan 11 21:24:48 volumio volumio[2031]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 21:24:48 volumio sudo[2293]: pam_unix(sudo:session): session closed for user root Jan 11 21:24:48 volumio volumio[2031]: Error: spawn /data/plugins/audio_interface/fusiondsp/camilladsp ENOENT Jan 11 21:24:48 volumio volumio[2031]: at Process.ChildProcess._handle.onexit (internal/child_process.js:269:19) Jan 11 21:24:48 volumio volumio[2031]: at onErrorNT (internal/child_process.js:465:16) Jan 11 21:24:48 volumio volumio[2031]: at processTicksAndRejections (internal/process/task_queues.js:80:21) { Jan 11 21:24:48 volumio volumio[2031]: errno: -2, Jan 11 21:24:48 volumio volumio[2031]: code: 'ENOENT', Jan 11 21:24:48 volumio volumio[2031]: syscall: 'spawn /data/plugins/audio_interface/fusiondsp/camilladsp', Jan 11 21:24:48 volumio volumio[2031]: path: '/data/plugins/audio_interface/fusiondsp/camilladsp', Jan 11 21:24:48 volumio volumio[2031]: spawnargs: [ Jan 11 21:24:48 volumio volumio[2031]: '-p', Jan 11 21:24:48 volumio volumio[2031]: 9876, Jan 11 21:24:48 volumio volumio[2031]: '-o', Jan 11 21:24:48 volumio volumio[2031]: '/tmp/camilladsp.log', Jan 11 21:24:48 volumio volumio[2031]: '-l', Jan 11 21:24:48 volumio volumio[2031]: 'warn', Jan 11 21:24:48 volumio volumio[2031]: '/data/configuration/audio_interface/fusiondsp/camilladsp.yml' Jan 11 21:24:48 volumio volumio[2031]: ] Jan 11 21:24:48 volumio volumio[2031]: } Jan 11 21:24:48 volumio volumio[2031]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 21:24:48 volumio go-librespot[2233]: time="2025-01-11T21:24:48+01:00" level=debug msg="authenticated as tangthomsen" Jan 11 21:24:48 volumio go-librespot[2233]: time="2025-01-11T21:24:48+01:00" level=debug msg="authenticated as tangthomsen" Jan 11 21:24:48 volumio sudo[2304]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-11 21:23 Jan 11 21:24:48 volumio sudo[2304]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 11 21:24:49 volumio go-librespot[2233]: time="2025-01-11T21:24:49+01:00" level=debug msg="dealer connection opened" Jan 11 21:24:49 volumio go-librespot[2233]: time="2025-01-11T21:24:49+01:00" level=debug msg="initializing zeroconf session, username: tangthomsen" Jan 11 21:24:49 volumio go-librespot[2233]: time="2025-01-11T21:24:49+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 11 21:24:49 volumio go-librespot[2233]: time="2025-01-11T21:24:49+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 11 21:24:49 volumio go-librespot[2233]: time="2025-01-11T21:24:49+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 11 21:24:49 volumio go-librespot[2233]: time="2025-01-11T21:24:49+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 11 21:24:49 volumio go-librespot[2233]: time="2025-01-11T21:24:49+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 11 21:24:49 volumio go-librespot[2233]: time="2025-01-11T21:24:49+01:00" level=debug msg="autoplay enabled: false" Jan 11 21:24:49 volumio go-librespot[2233]: time="2025-01-11T21:24:49+01:00" level=debug msg="received connection id: M2Q5YjQzZmEtYzZiZi00OWI2LThhZmYtNjBlMDU2YzYzMDI5K2RlYWxlcit0Y3A6Ly8wYWNhNTkyYy5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArM0U2Nzg1QjkyQjE1QkVCRDhCREMyQjhFRkY0NTEzNjdBMDdBNUM3NjJDMTM2Q0UwRkE3REQ3NzhBRTI3REQ0MQ==" 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"