Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: Express server listening on port 3000 Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: [Metrics] WebUI: 5s 282.92ms Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CoreStateMachine::resetVolumioState Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CoreStateMachine::getcurrentVolume Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::volumioRetrievevolume Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CoreStateMachine::pushState Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CorePlayQueue::getTrack 0 Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::volumioPushState Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: Volumio Network Manager: Network status updated: 1 Nov 23 18:53:00 pioneer-av-volumio volumio-remote-updater[740]: [2025-11-23 18:53:00] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1763920377 101 Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: Reloading queue from file Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CoreStateMachine::setRepeat null single undefined Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CoreStateMachine::pushState Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CorePlayQueue::getTrack 0 Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::volumioPushState Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CoreStateMachine::setRandom true Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CoreStateMachine::pushState Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CorePlayQueue::getTrack 0 Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::volumioPushState Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: Setting Device type: Raspberry PI Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: Completed loading Core Plugins Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: Preparing to generate the ALSA configuration file Nov 23 18:53:00 pioneer-av-volumio volumio[2825]: Forking 3 albumart workers Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03115 Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: Asound.conf file unchanged, so no further update is needed Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: Output device has changed, restarting MPD Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: Output device has changed, restarting Shairport Sync Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:00 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 18:53:00 pioneer-av-volumio sudo[2853]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 23 18:53:00 pioneer-av-volumio sudo[2853]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:53:00 pioneer-av-volumio sudo[2853]: pam_unix(sudo:session): session closed for user root Nov 23 18:53:00 pioneer-av-volumio sudo[2863]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 23 18:53:00 pioneer-av-volumio sudo[2863]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: ___________ START PLUGINS ___________ Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: ControllerMpd::onStart: Initializing MPD Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: Creating MPD Configuration file Nov 23 18:53:01 pioneer-av-volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Nov 23 18:53:01 pioneer-av-volumio systemd[1]: mpd.service: Deactivated successfully. Nov 23 18:53:01 pioneer-av-volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 23 18:53:01 pioneer-av-volumio systemd[1]: mpd.service: Consumed 1.468s CPU time. Nov 23 18:53:01 pioneer-av-volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 23 18:53:01 pioneer-av-volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 23 18:53:01 pioneer-av-volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 23 18:53:01 pioneer-av-volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: [1763920381197] CoreMusicLibrary::Adding element Media Servers Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 18:53:01 pioneer-av-volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 23 18:53:01 pioneer-av-volumio sudo[2886]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 23 18:53:01 pioneer-av-volumio sudo[2886]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:53:01 pioneer-av-volumio sudo[2890]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 23 18:53:01 pioneer-av-volumio sudo[2890]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 23 18:53:01 pioneer-av-volumio sudo[2889]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 23 18:53:01 pioneer-av-volumio sudo[2889]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:53:01 pioneer-av-volumio sudo[2886]: pam_unix(sudo:session): session closed for user root Nov 23 18:53:01 pioneer-av-volumio sudo[2890]: pam_unix(sudo:session): session closed for user root Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 18:53:01 pioneer-av-volumio systemd[1]: mpd.service: Deactivated successfully. Nov 23 18:53:01 pioneer-av-volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 23 18:53:01 pioneer-av-volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 23 18:53:01 pioneer-av-volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 23 18:53:01 pioneer-av-volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 23 18:53:01 pioneer-av-volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 23 18:53:01 pioneer-av-volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 18:53:01 pioneer-av-volumio sudo[2902]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 23 18:53:01 pioneer-av-volumio sudo[2902]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 23 18:53:01 pioneer-av-volumio sudo[2902]: pam_unix(sudo:session): session closed for user root Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: [1763920381711] CoreMusicLibrary::Adding element Last_100 Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: [1763920381744] CoreMusicLibrary::Adding element Webradio Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 23 18:53:01 pioneer-av-volumio volumio[2762]: info: Initializing BBC Radios Nov 23 18:53:02 pioneer-av-volumio go-librespot[2745]: time="2025-11-23T18:53:02+01:00" level=fatal msg="failed running zeroconf" 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" Nov 23 18:53:02 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 23 18:53:02 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 23 18:53:02 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 23 18:53:02 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 18:53:02 pioneer-av-volumio volumio[2762]: info: Creating Spotify config file Nov 23 18:53:02 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:02 pioneer-av-volumio volumio[2762]: info: Volumio Calling Home Nov 23 18:53:03 pioneer-av-volumio mpd[2906]: 2025-11-23T18:53:03 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 23 18:53:03 pioneer-av-volumio systemd[1]: Started mpd.service - Music Player Daemon. Nov 23 18:53:03 pioneer-av-volumio sudo[2863]: pam_unix(sudo:session): session closed for user root Nov 23 18:53:03 pioneer-av-volumio sudo[2889]: pam_unix(sudo:session): session closed for user root Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: info: Completed starting Core Plugins Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: info: ------------------------------------------- Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: info: ----- MyVolumio plugins startup ---- Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: info: ------------------------------------------- Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: info: [MyVolumio PluginManager] Fetching plans data.... Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: info: MPD Permissions set Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: info: MPD Permissions set Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: info: Spotify config file written Nov 23 18:53:05 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Nov 23 18:53:05 pioneer-av-volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 23 18:53:05 pioneer-av-volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 23 18:53:05 pioneer-av-volumio go-librespot[2931]: go-librespot daemon starting... Nov 23 18:53:05 pioneer-av-volumio sudo[2930]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 23 18:53:05 pioneer-av-volumio sudo[2930]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:53:05 pioneer-av-volumio go-librespot[2932]: time="2025-11-23T18:53:05+01:00" level=info msg="running go-librespot 0.4.0" Nov 23 18:53:05 pioneer-av-volumio go-librespot[2932]: time="2025-11-23T18:53:05+01:00" level=debug msg="app state loaded" Nov 23 18:53:05 pioneer-av-volumio go-librespot[2932]: time="2025-11-23T18:53:05+01:00" level=debug msg="stored credentials not found" Nov 23 18:53:05 pioneer-av-volumio go-librespot[2932]: time="2025-11-23T18:53:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 23 18:53:05 pioneer-av-volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Nov 23 18:53:05 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Nov 23 18:53:05 pioneer-av-volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 23 18:53:05 pioneer-av-volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 23 18:53:05 pioneer-av-volumio go-librespot[2939]: go-librespot daemon starting... Nov 23 18:53:05 pioneer-av-volumio sudo[2930]: pam_unix(sudo:session): session closed for user root Nov 23 18:53:05 pioneer-av-volumio go-librespot[2940]: time="2025-11-23T18:53:05+01:00" level=info msg="running go-librespot 0.4.0" Nov 23 18:53:05 pioneer-av-volumio go-librespot[2940]: time="2025-11-23T18:53:05+01:00" level=debug msg="app state loaded" Nov 23 18:53:05 pioneer-av-volumio go-librespot[2940]: time="2025-11-23T18:53:05+01:00" level=debug msg="stored credentials not found" Nov 23 18:53:05 pioneer-av-volumio go-librespot[2940]: time="2025-11-23T18:53:05+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: error: MPD error: The expression evaluated to a falsy value: Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: assert.ok(self.idling) Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: error: The expression evaluated to a falsy value: Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: assert.ok(self.idling) Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:05 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: No need to fix Spotify hosts Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: error: updateQueue error: null Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: MPD running with PID2906 Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: ,establishing connection Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: error: updateQueue error: null Nov 23 18:53:06 pioneer-av-volumio volumio[2844]: Starting albumart workers Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: Starting Shairport Sync Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: Starting Shairport Sync Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: Starting Shairport Sync Nov 23 18:53:06 pioneer-av-volumio sudo[2957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 23 18:53:06 pioneer-av-volumio sudo[2959]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 23 18:53:06 pioneer-av-volumio sudo[2959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:53:06 pioneer-av-volumio sudo[2957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:53:06 pioneer-av-volumio sudo[2961]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 23 18:53:06 pioneer-av-volumio sudo[2961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:53:06 pioneer-av-volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 23 18:53:06 pioneer-av-volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 23 18:53:06 pioneer-av-volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 23 18:53:06 pioneer-av-volumio systemd[1]: shairport-sync.service: Consumed 1.685s CPU time. Nov 23 18:53:06 pioneer-av-volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 23 18:53:06 pioneer-av-volumio sudo[2957]: pam_unix(sudo:session): session closed for user root Nov 23 18:53:06 pioneer-av-volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 23 18:53:06 pioneer-av-volumio volumio[2762]: info: Shairport-Sync Started Nov 23 18:53:06 pioneer-av-volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 23 18:53:06 pioneer-av-volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 23 18:53:06 pioneer-av-volumio volumio[2849]: Starting albumart workers Nov 23 18:53:06 pioneer-av-volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 23 18:53:06 pioneer-av-volumio sudo[2959]: pam_unix(sudo:session): session closed for user root Nov 23 18:53:07 pioneer-av-volumio volumio[2762]: Error adding Membership: Error: addMembership EINVAL Nov 23 18:53:07 pioneer-av-volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 23 18:53:07 pioneer-av-volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 23 18:53:07 pioneer-av-volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 23 18:53:07 pioneer-av-volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 23 18:53:07 pioneer-av-volumio volumio[2762]: info: Shairport-Sync Started Nov 23 18:53:07 pioneer-av-volumio sudo[2961]: pam_unix(sudo:session): session closed for user root Nov 23 18:53:07 pioneer-av-volumio volumio[2762]: info: Shairport-Sync Started Nov 23 18:53:07 pioneer-av-volumio volumio[2845]: Starting albumart workers Nov 23 18:53:07 pioneer-av-volumio sudo[2984]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 23 18:53:07 pioneer-av-volumio sudo[2984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:53:07 pioneer-av-volumio sudo[2986]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 23 18:53:07 pioneer-av-volumio sudo[2986]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:53:07 pioneer-av-volumio sudo[2984]: pam_unix(sudo:session): session closed for user root Nov 23 18:53:07 pioneer-av-volumio sudo[2986]: pam_unix(sudo:session): session closed for user root Nov 23 18:53:07 pioneer-av-volumio sudo[3002]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 23 18:53:08 pioneer-av-volumio sudo[3002]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:53:08 pioneer-av-volumio sudo[3002]: pam_unix(sudo:session): session closed for user root Nov 23 18:53:08 pioneer-av-volumio volumio[2762]: info: Upmpdcli Daemon Started Nov 23 18:53:08 pioneer-av-volumio sudo[3006]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 23 18:53:08 pioneer-av-volumio sudo[3008]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 23 18:53:08 pioneer-av-volumio sudo[3006]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:53:08 pioneer-av-volumio sudo[3008]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:53:08 pioneer-av-volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Nov 23 18:53:08 pioneer-av-volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Nov 23 18:53:08 pioneer-av-volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Nov 23 18:53:08 pioneer-av-volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Nov 23 18:53:08 pioneer-av-volumio sudo[3008]: pam_unix(sudo:session): session closed for user root Nov 23 18:53:08 pioneer-av-volumio mpd_monitor.sh[3011]: MPD Monitor Service: Starting MPD Monitor Service Nov 23 18:53:08 pioneer-av-volumio volumio[2762]: info: Successfully started MPD Monitor Nov 23 18:53:08 pioneer-av-volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Nov 23 18:53:08 pioneer-av-volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Nov 23 18:53:08 pioneer-av-volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Nov 23 18:53:08 pioneer-av-volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Nov 23 18:53:08 pioneer-av-volumio mpd_monitor.sh[3015]: MPD Monitor Service: Starting MPD Monitor Service Nov 23 18:53:08 pioneer-av-volumio sudo[3006]: pam_unix(sudo:session): session closed for user root Nov 23 18:53:08 pioneer-av-volumio volumio[2762]: info: Successfully started MPD Monitor Nov 23 18:53:09 pioneer-av-volumio volumio[2762]: info: go-librespot daemon successfully initialized Nov 23 18:53:10 pioneer-av-volumio volumio[2762]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Nov 23 18:53:12 pioneer-av-volumio volumio[2762]: info: Initializing connection to go-librespot Websocket Nov 23 18:53:17 pioneer-av-volumio go-librespot[2940]: time="2025-11-23T18:53:17+01:00" level=fatal msg="failed running zeroconf" 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" Nov 23 18:53:17 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 23 18:53:17 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 23 18:53:20 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Nov 23 18:53:20 pioneer-av-volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 23 18:53:20 pioneer-av-volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 23 18:53:20 pioneer-av-volumio go-librespot[3052]: go-librespot daemon starting... Nov 23 18:53:20 pioneer-av-volumio go-librespot[3053]: time="2025-11-23T18:53:20+01:00" level=info msg="running go-librespot 0.4.0" Nov 23 18:53:20 pioneer-av-volumio go-librespot[3053]: time="2025-11-23T18:53:20+01:00" level=debug msg="app state loaded" Nov 23 18:53:20 pioneer-av-volumio go-librespot[3053]: time="2025-11-23T18:53:20+01:00" level=debug msg="stored credentials not found" Nov 23 18:53:20 pioneer-av-volumio go-librespot[3053]: time="2025-11-23T18:53:20+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 23 18:53:21 pioneer-av-volumio volumio[2762]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.071&uuid=b577c2f0b7d30556816d97d628918353" http://updates.volumio.org/downloader-v1/track-device Nov 23 18:53:21 pioneer-av-volumio volumio[2762]: % Total % Received % Xferd Average Speed Time Time Time Current Nov 23 18:53:21 pioneer-av-volumio volumio[2762]: Dload Upload Total Spent Left Speed Nov 23 18:53:21 pioneer-av-volumio volumio[2762]: [764B blob data] Nov 23 18:53:21 pioneer-av-volumio volumio[2762]: retrying in 5 seconds, trial 0 Nov 23 18:53:21 pioneer-av-volumio volumio[2762]: info: Volumio Calling Home Nov 23 18:53:23 pioneer-av-volumio volumio[2762]: info: Discovery: adding ddf4105b-269f-4298-ae29-b112ccaf4438 Nov 23 18:53:23 pioneer-av-volumio volumio[2762]: info: Discovery: Found device Pioneer AV Volumio Nov 23 18:53:23 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::volumioGetState Nov 23 18:53:23 pioneer-av-volumio volumio[2762]: info: CorePlayQueue::getTrack 0 Nov 23 18:53:25 pioneer-av-volumio volumio[2762]: error: MyVolumio Plugin failed to start in a timely fashion Nov 23 18:53:25 pioneer-av-volumio volumio[2762]: [Metrics] CommandRouter: 29s 897.76ms Nov 23 18:53:25 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::volumiosetStartupVolume Nov 23 18:53:25 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:53:25 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 18:53:25 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::Close All Modals sent Nov 23 18:53:25 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::Close All Modals sent Nov 23 18:53:25 pioneer-av-volumio kernel: bcm2835-i2s fe203000.i2s: I2S SYNC error! Nov 23 18:53:26 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Nov 23 18:53:26 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 23 18:53:26 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Nov 23 18:53:32 pioneer-av-volumio volumio[2762]: info: BOOT COMPLETED Nov 23 18:53:32 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 23 18:53:32 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 18:53:32 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 23 18:53:33 pioneer-av-volumio go-librespot[3053]: time="2025-11-23T18:53:33+01:00" level=fatal msg="failed running zeroconf" 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" Nov 23 18:53:33 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 23 18:53:33 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 23 18:53:33 pioneer-av-volumio volumio[2762]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Nov 23 18:53:36 pioneer-av-volumio volumio[2762]: info: Initializing connection to go-librespot Websocket Nov 23 18:53:36 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Nov 23 18:53:36 pioneer-av-volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 23 18:53:36 pioneer-av-volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 23 18:53:36 pioneer-av-volumio go-librespot[3086]: go-librespot daemon starting... Nov 23 18:53:36 pioneer-av-volumio go-librespot[3087]: time="2025-11-23T18:53:36+01:00" level=info msg="running go-librespot 0.4.0" Nov 23 18:53:36 pioneer-av-volumio go-librespot[3087]: time="2025-11-23T18:53:36+01:00" level=debug msg="app state loaded" Nov 23 18:53:36 pioneer-av-volumio go-librespot[3087]: time="2025-11-23T18:53:36+01:00" level=debug msg="stored credentials not found" Nov 23 18:53:36 pioneer-av-volumio go-librespot[3087]: time="2025-11-23T18:53:36+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 23 18:53:43 pioneer-av-volumio volumio[2762]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=pi&variante=volumio&version=4.071&uuid=b577c2f0b7d30556816d97d628918353" http://updates.volumio.org/downloader-v1/track-device Nov 23 18:53:43 pioneer-av-volumio volumio[2762]: % Total % Received % Xferd Average Speed Time Time Time Current Nov 23 18:53:43 pioneer-av-volumio volumio[2762]: Dload Upload Total Spent Left Speed Nov 23 18:53:43 pioneer-av-volumio volumio[2762]: [1.0K blob data] Nov 23 18:53:43 pioneer-av-volumio volumio[2762]: retrying in 5 seconds, trial 1 Nov 23 18:53:43 pioneer-av-volumio volumio[2762]: info: Volumio Calling Home Nov 23 18:53:48 pioneer-av-volumio volumio[2762]: info: Discovery: this is already registered, ddf4105b-269f-4298-ae29-b112ccaf4438 Nov 23 18:53:48 pioneer-av-volumio go-librespot[3087]: time="2025-11-23T18:53:48+01:00" level=fatal msg="failed running zeroconf" 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" Nov 23 18:53:48 pioneer-av-volumio volumio[2762]: info: Discovery: Found device Pioneer AV Volumio Nov 23 18:53:48 pioneer-av-volumio volumio[2762]: info: CoreCommandRouter::volumioGetState Nov 23 18:53:48 pioneer-av-volumio volumio[2762]: info: CorePlayQueue::getTrack 0 Nov 23 18:53:48 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 23 18:53:48 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 23 18:53:52 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Nov 23 18:53:52 pioneer-av-volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 23 18:53:52 pioneer-av-volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 23 18:53:52 pioneer-av-volumio go-librespot[3127]: go-librespot daemon starting... Nov 23 18:53:52 pioneer-av-volumio go-librespot[3128]: time="2025-11-23T18:53:52+01:00" level=info msg="running go-librespot 0.4.0" Nov 23 18:53:52 pioneer-av-volumio go-librespot[3128]: time="2025-11-23T18:53:52+01:00" level=debug msg="app state loaded" Nov 23 18:53:52 pioneer-av-volumio go-librespot[3128]: time="2025-11-23T18:53:52+01:00" level=debug msg="stored credentials not found" Nov 23 18:53:52 pioneer-av-volumio go-librespot[3128]: time="2025-11-23T18:53:52+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 23 18:53:58 pioneer-av-volumio go-librespot[3128]: time="2025-11-23T18:53:58+01:00" level=debug msg="new websocket client" Nov 23 18:53:58 pioneer-av-volumio volumio[2762]: info: Connection to go-librespot Websocket established Nov 23 18:54:01 pioneer-av-volumio volumio[2762]: info: Getting Spotify volume Nov 23 18:54:04 pioneer-av-volumio go-librespot[3128]: time="2025-11-23T18:54:04+01:00" level=fatal msg="failed running zeroconf" 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" Nov 23 18:54:04 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 23 18:54:04 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 23 18:54:04 pioneer-av-volumio volumio[2762]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 23 18:54:04 pioneer-av-volumio volumio[2762]: Error: socket hang up Nov 23 18:54:04 pioneer-av-volumio volumio[2762]: at connResetException (node:internal/errors:720:14) Nov 23 18:54:04 pioneer-av-volumio volumio[2762]: at Socket.socketOnEnd (node:_http_client:519:23) Nov 23 18:54:04 pioneer-av-volumio volumio[2762]: at Socket.emit (node:events:526:35) Nov 23 18:54:04 pioneer-av-volumio volumio[2762]: at endReadableNT (node:internal/streams/readable:1376:12) Nov 23 18:54:04 pioneer-av-volumio volumio[2762]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Nov 23 18:54:04 pioneer-av-volumio volumio[2762]: code: 'ECONNRESET', Nov 23 18:54:04 pioneer-av-volumio volumio[2762]: response: undefined Nov 23 18:54:04 pioneer-av-volumio volumio[2762]: } Nov 23 18:54:04 pioneer-av-volumio volumio[2762]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 23 18:54:05 pioneer-av-volumio sudo[3164]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-11-23 18:53' Nov 23 18:54:05 pioneer-av-volumio sudo[3164]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:54:05 pioneer-av-volumio sudo[3164]: pam_unix(sudo:session): session closed for user root Nov 23 18:54:07 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Nov 23 18:54:07 pioneer-av-volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 23 18:54:07 pioneer-av-volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 23 18:54:07 pioneer-av-volumio go-librespot[3174]: go-librespot daemon starting... Nov 23 18:54:07 pioneer-av-volumio go-librespot[3175]: time="2025-11-23T18:54:07+01:00" level=info msg="running go-librespot 0.4.0" Nov 23 18:54:07 pioneer-av-volumio go-librespot[3175]: time="2025-11-23T18:54:07+01:00" level=debug msg="app state loaded" Nov 23 18:54:07 pioneer-av-volumio go-librespot[3175]: time="2025-11-23T18:54:07+01:00" level=debug msg="stored credentials not found" Nov 23 18:54:07 pioneer-av-volumio go-librespot[3175]: time="2025-11-23T18:54:07+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 23 18:54:20 pioneer-av-volumio go-librespot[3175]: time="2025-11-23T18:54:20+01:00" level=fatal msg="failed running zeroconf" 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" Nov 23 18:54:20 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Nov 23 18:54:20 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Nov 23 18:54:23 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Nov 23 18:54:23 pioneer-av-volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 23 18:54:23 pioneer-av-volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 23 18:54:23 pioneer-av-volumio go-librespot[3214]: go-librespot daemon starting... Nov 23 18:54:23 pioneer-av-volumio go-librespot[3215]: time="2025-11-23T18:54:23+01:00" level=info msg="running go-librespot 0.4.0" Nov 23 18:54:23 pioneer-av-volumio go-librespot[3215]: time="2025-11-23T18:54:23+01:00" level=debug msg="app state loaded" Nov 23 18:54:23 pioneer-av-volumio go-librespot[3215]: time="2025-11-23T18:54:23+01:00" level=debug msg="stored credentials not found" Nov 23 18:54:23 pioneer-av-volumio go-librespot[3215]: time="2025-11-23T18:54:23+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 23 18:54:25 pioneer-av-volumio dhcpcd[833]: eth0: offered 192.168.2.187 from 192.168.2.1 Speedport-Pro-Plus-120141-6-5-021-0 Nov 23 18:54:25 pioneer-av-volumio dhcpcd[833]: eth0: probing address 192.168.2.187/24 Nov 23 18:54:26 pioneer-av-volumio volumio-remote-updater[740]: [2025-11-23 18:54:26] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Nov 23 18:54:26 pioneer-av-volumio volumio-remote-updater[740]: [2025-11-23 18:54:26] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Nov 23 18:54:26 pioneer-av-volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Nov 23 18:54:26 pioneer-av-volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Nov 23 18:54:26 pioneer-av-volumio systemd[1]: volumio.service: Consumed 1min 25.320s CPU time. Nov 23 18:54:26 pioneer-av-volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Nov 23 18:54:26 pioneer-av-volumio systemd[1]: dynamicswap.service: Deactivated successfully. Nov 23 18:54:26 pioneer-av-volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4. Nov 23 18:54:26 pioneer-av-volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Nov 23 18:54:26 pioneer-av-volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Nov 23 18:54:26 pioneer-av-volumio systemd[1]: volumio.service: Consumed 1min 25.320s CPU time. Nov 23 18:54:26 pioneer-av-volumio systemd[1]: Started volumio.service - Volumio Backend Module. Nov 23 18:54:26 pioneer-av-volumio systemd[1]: dynamicswap.service: Deactivated successfully. Nov 23 18:54:27 pioneer-av-volumio volumio[3239]: info: ------------------------------------------- Nov 23 18:54:27 pioneer-av-volumio volumio[3239]: info: ----- Volumio3 ---- Nov 23 18:54:27 pioneer-av-volumio volumio[3239]: info: ------------------------------------------- Nov 23 18:54:27 pioneer-av-volumio volumio[3239]: info: ----- System startup ---- Nov 23 18:54:27 pioneer-av-volumio volumio[3239]: info: ------------------------------------------- Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: MYVOLUMIO Environment detected Nov 23 18:54:28 pioneer-av-volumio dhcpcd[668]: eth0: offered 192.168.2.187 from 192.168.2.1 Speedport-Pro-Plus-120141-6-5-021-0 Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Plugin folders cleanup Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Scanning into folder /volumio/app/plugins/ Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Scanning category audio_interface Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Scanning category miscellanea Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Scanning category music_service Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Scanning category plugins.json Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Scanning category system_controller Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Scanning category user_interface Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Scanning into folder /data/plugins/ Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Scanning category music_service Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Plugin folders cleanup completed Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: ------------------------------------------- Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: ----- Core plugins startup ---- Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: ------------------------------------------- Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Loading plugins from folder /volumio/app/plugins/ Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Adding plugin upnp to MyMusic Plugins Nov 23 18:54:28 pioneer-av-volumio dhcpcd[668]: eth0: probing address 192.168.2.187/24 Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Adding plugin airplay_emulation to MyMusic Plugins Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Adding plugin upnp_browser to MyMusic Plugins Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Loading plugins from folder /data/plugins/ Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Loading plugin "system"... Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Loading plugin "appearance"... Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Loading plugin "network"... Nov 23 18:54:28 pioneer-av-volumio volumio[3239]: info: Refreshing Cached IP Addresses Nov 23 18:54:28 pioneer-av-volumio sudo[3271]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 23 18:54:28 pioneer-av-volumio sudo[3271]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:54:29 pioneer-av-volumio sudo[3273]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 23 18:54:29 pioneer-av-volumio sudo[3271]: pam_unix(sudo:session): session closed for user root Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: Loading plugin "services"... Nov 23 18:54:29 pioneer-av-volumio sudo[3273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: Loading plugin "alsa_controller"... Nov 23 18:54:29 pioneer-av-volumio sudo[3273]: pam_unix(sudo:session): session closed for user root Nov 23 18:54:29 pioneer-av-volumio sudo[3281]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 23 18:54:29 pioneer-av-volumio sudo[3281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: Loading plugin "wizard"... Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: Loading plugin "networkfs"... Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: Starting Udev Watcher for removable devices Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: Ignoring mount for partition: boot Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: Ignoring mount for partition: volumio Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: Ignoring mount for partition: volumio_data Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: Loading plugin "volumio_command_line_client"... Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: Loading plugin "upnp"... Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: [1763920469098] Starting Upmpd Daemon Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: Loading plugin "my_music"... Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: Loading plugin "mpd"... Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: Loading plugin "upnp_browser"... Nov 23 18:54:29 pioneer-av-volumio volumio[3239]: info: Loading plugin "alarm-clock"... Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Loading plugin "airplay_emulation"... Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Starting Shairport Sync Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Loading plugin "last_100"... Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Loading plugin "webradio"... Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Loading plugin "i2s_dacs"... Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Loading plugin "volumiodiscovery"... Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: *** WARNING *** For more information see Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: *** WARNING *** For more information see Nov 23 18:54:30 pioneer-av-volumio node[3239]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 23 18:54:30 pioneer-av-volumio node[3239]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 23 18:54:30 pioneer-av-volumio node[3239]: *** WARNING *** For more information see Nov 23 18:54:30 pioneer-av-volumio node[3239]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 23 18:54:30 pioneer-av-volumio node[3239]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 23 18:54:30 pioneer-av-volumio node[3239]: *** WARNING *** For more information see Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Discovery: Started advertising with name: Pioneer AV Volumio Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Loading plugin "spop"... Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Loading plugin "outputs"... Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Loading plugin "albumart"... Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Plugin example_plugin is not enabled Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Loading plugin "inputs"... Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Loading plugin "updater_comm"... Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Plugin mpdemulation is not enabled Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Loading plugin "rest_api"... Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Loading plugin "websocket"... Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Starting Socket.io Server version 1.7.4 Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Loading i18n strings for locale en Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: Updating browse sources language Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::initPlayerControls Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: Express server listening on port 3000 Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: [Metrics] WebUI: 3s 264.38ms Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreStateMachine::resetVolumioState Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreStateMachine::getcurrentVolume Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::volumioRetrievevolume Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreStateMachine::pushState Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CorePlayQueue::getTrack 0 Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::volumioPushState Nov 23 18:54:30 pioneer-av-volumio volumio[3239]: info: Volumio Network Manager: Network status updated: 1 Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: Reloading queue from file Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreStateMachine::setRepeat null single undefined Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreStateMachine::pushState Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CorePlayQueue::getTrack 0 Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::volumioPushState Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreStateMachine::setRandom true Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreStateMachine::pushState Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CorePlayQueue::getTrack 0 Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::volumioPushState Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: Setting Device type: Raspberry PI Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03115 Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Nov 23 18:54:31 pioneer-av-volumio volumio[3303]: Forking 3 albumart workers Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: Completed loading Core Plugins Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: Preparing to generate the ALSA configuration file Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: Asound.conf file unchanged, so no further update is needed Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: Output device has changed, restarting MPD Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: Output device has changed, restarting Shairport Sync Nov 23 18:54:31 pioneer-av-volumio sudo[3327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 18:54:31 pioneer-av-volumio sudo[3327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:54:31 pioneer-av-volumio sudo[3327]: pam_unix(sudo:session): session closed for user root Nov 23 18:54:31 pioneer-av-volumio sudo[3332]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 23 18:54:31 pioneer-av-volumio sudo[3332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: ___________ START PLUGINS ___________ Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: ControllerMpd::onStart: Initializing MPD Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: Creating MPD Configuration file Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: [1763920471171] CoreMusicLibrary::Adding element Media Servers Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 18:54:31 pioneer-av-volumio systemd[1]: mpd.service: Deactivated successfully. Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 23 18:54:31 pioneer-av-volumio systemd[1]: mpd.service: Consumed 1.476s CPU time. Nov 23 18:54:31 pioneer-av-volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 23 18:54:31 pioneer-av-volumio sudo[3365]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 23 18:54:31 pioneer-av-volumio sudo[3365]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 18:54:31 pioneer-av-volumio sudo[3363]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 23 18:54:31 pioneer-av-volumio sudo[3363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:54:31 pioneer-av-volumio sudo[3363]: pam_unix(sudo:session): session closed for user root Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: [1763920471266] CoreMusicLibrary::Adding element Last_100 Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: [1763920471268] CoreMusicLibrary::Adding element Webradio Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: Initializing BBC Radios Nov 23 18:54:31 pioneer-av-volumio dhcpcd[833]: eth0: leased 192.168.2.187 for 1814400 seconds Nov 23 18:54:31 pioneer-av-volumio avahi-daemon[715]: Registering new address record for 192.168.2.187 on eth0.IPv4. Nov 23 18:54:31 pioneer-av-volumio dhcpcd[833]: eth0: adding route to 192.168.2.0/24 Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 23 18:54:31 pioneer-av-volumio dhcpcd[833]: eth0: changing default route via 192.168.2.1 Nov 23 18:54:31 pioneer-av-volumio dhcpcd[668]: eth0: pid 833 deleted default route Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Nov 23 18:54:31 pioneer-av-volumio systemd[1]: welcome.service: Deactivated successfully. Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Nov 23 18:54:31 pioneer-av-volumio systemd[1]: mpd.service: Deactivated successfully. Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Nov 23 18:54:31 pioneer-av-volumio avahi-daemon[715]: Withdrawing address record for 169.254.143.124 on eth0. Nov 23 18:54:31 pioneer-av-volumio dhcpcd[668]: eth0: pid 833 deleted IP address 169.254.143.124/16 Nov 23 18:54:31 pioneer-av-volumio avahi-daemon[715]: Leaving mDNS multicast group on interface eth0.IPv4 with address 169.254.143.124. Nov 23 18:54:31 pioneer-av-volumio avahi-daemon[715]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.2.187. Nov 23 18:54:31 pioneer-av-volumio dhcpcd[668]: eth0: deleting route to 169.254.0.0/16 Nov 23 18:54:31 pioneer-av-volumio dhcpcd[833]: eth0: deleting route to 169.254.0.0/16 Nov 23 18:54:31 pioneer-av-volumio welcome[3410]: Resolved ip:[1] 192.168.2.187 Nov 23 18:54:31 pioneer-av-volumio systemd[1]: mpd.socket: Deactivated successfully. Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Starting mpd.service - Music Player Daemon... Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Nov 23 18:54:31 pioneer-av-volumio dhcpcd[668]: eth0: probing for an IPv4LL address Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Nov 23 18:54:31 pioneer-av-volumio systemd[1]: welcome.service: Deactivated successfully. Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: Creating Spotify config file Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:31 pioneer-av-volumio volumio[3239]: info: Volumio Calling Home Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Nov 23 18:54:31 pioneer-av-volumio welcome[3457]: Resolved ip:[1] 192.168.2.187 Nov 23 18:54:31 pioneer-av-volumio sudo[3430]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 23 18:54:31 pioneer-av-volumio sudo[3430]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Nov 23 18:54:31 pioneer-av-volumio sudo[3430]: pam_unix(sudo:session): session closed for user root Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Nov 23 18:54:31 pioneer-av-volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Nov 23 18:54:31 pioneer-av-volumio sudo[3281]: pam_unix(sudo:session): session closed for user root Nov 23 18:54:31 pioneer-av-volumio volumio-remote-updater[740]: [2025-11-23 18:54:31] [connect] Successful connection Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: MPD Permissions set Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: MPD Permissions set Nov 23 18:54:32 pioneer-av-volumio volumio[3322]: Starting albumart workers Nov 23 18:54:32 pioneer-av-volumio volumio[3323]: Starting albumart workers Nov 23 18:54:32 pioneer-av-volumio volumio-remote-updater[740]: [2025-11-23 18:54:32] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1763920471 101 Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: Spotify config file written Nov 23 18:54:32 pioneer-av-volumio volumio[3321]: Starting albumart workers Nov 23 18:54:32 pioneer-av-volumio sudo[3470]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 23 18:54:32 pioneer-av-volumio sudo[3470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:54:32 pioneer-av-volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Nov 23 18:54:32 pioneer-av-volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Nov 23 18:54:32 pioneer-av-volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: Volumio called home Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Nov 23 18:54:32 pioneer-av-volumio go-librespot[3473]: go-librespot daemon starting... Nov 23 18:54:32 pioneer-av-volumio sudo[3470]: pam_unix(sudo:session): session closed for user root Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio go-librespot[3479]: time="2025-11-23T18:54:32+01:00" level=info msg="running go-librespot 0.4.0" Nov 23 18:54:32 pioneer-av-volumio go-librespot[3479]: time="2025-11-23T18:54:32+01:00" level=debug msg="app state loaded" Nov 23 18:54:32 pioneer-av-volumio go-librespot[3479]: time="2025-11-23T18:54:32+01:00" level=debug msg="stored credentials not found" Nov 23 18:54:32 pioneer-av-volumio go-librespot[3479]: time="2025-11-23T18:54:32+01:00" level=info msg="api server listening on 127.0.0.1:9879" Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: No need to fix Spotify hosts Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: Starting Shairport Sync Nov 23 18:54:32 pioneer-av-volumio ntpd[998]: IO: Listen normally on 4 eth0 192.168.2.187:123 Nov 23 18:54:32 pioneer-av-volumio ntpd[998]: IO: Deleting interface #3 eth0, 169.254.143.124#123, interface stats: received=0, sent=0, dropped=0, active_time=312 secs Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: Starting Shairport Sync Nov 23 18:54:32 pioneer-av-volumio ntpd[998]: IO: new interface(s) found: waking up resolver Nov 23 18:54:32 pioneer-av-volumio ntpd[998]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Nov 23 18:54:32 pioneer-av-volumio ntpd[998]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Nov 23 18:54:32 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 217.160.19.219 Nov 23 18:54:32 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 213.172.105.106 Nov 23 18:54:32 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 5.45.97.204 Nov 23 18:54:32 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 172.104.149.161 Nov 23 18:54:32 pioneer-av-volumio ntpd[998]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Nov 23 18:54:32 pioneer-av-volumio sudo[3492]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 23 18:54:32 pioneer-av-volumio sudo[3492]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: Starting Shairport Sync Nov 23 18:54:32 pioneer-av-volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 23 18:54:32 pioneer-av-volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 23 18:54:32 pioneer-av-volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: Discovery: adding ddf4105b-269f-4298-ae29-b112ccaf4438 Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: Discovery: Found device Pioneer AV Volumio Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::volumioGetState Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CorePlayQueue::getTrack 0 Nov 23 18:54:32 pioneer-av-volumio systemd[1]: shairport-sync.service: Consumed 1.666s CPU time. Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: Discovery: this is already registered, ddf4105b-269f-4298-ae29-b112ccaf4438 Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: Discovery: Found device Pioneer AV Volumio Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::volumioGetState Nov 23 18:54:32 pioneer-av-volumio volumio[3239]: info: CorePlayQueue::getTrack 0 Nov 23 18:54:32 pioneer-av-volumio sudo[3497]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 23 18:54:32 pioneer-av-volumio sudo[3497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:54:32 pioneer-av-volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 23 18:54:32 pioneer-av-volumio go-librespot[3479]: time="2025-11-23T18:54:32+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]" Nov 23 18:54:32 pioneer-av-volumio go-librespot[3479]: time="2025-11-23T18:54:32+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]" Nov 23 18:54:32 pioneer-av-volumio go-librespot[3479]: time="2025-11-23T18:54:32+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]" Nov 23 18:54:33 pioneer-av-volumio go-librespot[3479]: time="2025-11-23T18:54:33+01:00" level=info msg="zeroconf server listening on port 35735" Nov 23 18:54:33 pioneer-av-volumio sudo[3499]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 23 18:54:33 pioneer-av-volumio sudo[3499]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 23 18:54:33 pioneer-av-volumio sudo[3492]: pam_unix(sudo:session): session closed for user root Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: info: Shairport-Sync Started Nov 23 18:54:33 pioneer-av-volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: Error adding Membership: Error: addMembership EINVAL Nov 23 18:54:33 pioneer-av-volumio systemd[1]: shairport-sync.service: Deactivated successfully. Nov 23 18:54:33 pioneer-av-volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: info: CoreCommandRouter::volumioGetState Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: info: CorePlayQueue::getTrack 0 Nov 23 18:54:33 pioneer-av-volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 23 18:54:33 pioneer-av-volumio sudo[3499]: pam_unix(sudo:session): session closed for user root Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: info: Shairport-Sync Started Nov 23 18:54:33 pioneer-av-volumio sudo[3497]: pam_unix(sudo:session): session closed for user root Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: info: Shairport-Sync Started Nov 23 18:54:33 pioneer-av-volumio mpd[3466]: 2025-11-23T18:54:33 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 23 18:54:33 pioneer-av-volumio systemd[1]: Started mpd.service - Music Player Daemon. Nov 23 18:54:33 pioneer-av-volumio sudo[3332]: pam_unix(sudo:session): session closed for user root Nov 23 18:54:33 pioneer-av-volumio sudo[3365]: pam_unix(sudo:session): session closed for user root Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: info: Completed starting Core Plugins Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: info: ------------------------------------------- Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: info: ----- MyVolumio plugins startup ---- Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: info: ------------------------------------------- Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: info: [MyVolumio PluginManager] Fetching plans data.... Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: error: MPD error: The expression evaluated to a falsy value: Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: assert.ok(self.idling) Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: error: The expression evaluated to a falsy value: Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: assert.ok(self.idling) Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: info: MPD running with PID3466 Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: ,establishing connection Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: error: updateQueue error: null Nov 23 18:54:33 pioneer-av-volumio volumio[3239]: error: updateQueue error: null Nov 23 18:54:33 pioneer-av-volumio ntpd[998]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Nov 23 18:54:33 pioneer-av-volumio ntpd[998]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Nov 23 18:54:33 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 217.154.196.35 Nov 23 18:54:33 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 185.248.188.98 Nov 23 18:54:33 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 178.63.67.56 Nov 23 18:54:33 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 185.252.140.126 Nov 23 18:54:33 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 2a02:8106:21:9400::8 Nov 23 18:54:33 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 2603:c020:8017:3eee:123:123:123:123 Nov 23 18:54:33 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 2a01:4f8:160:43aa::2 Nov 23 18:54:33 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 2003:a:87f:c37c::6 Nov 23 18:54:33 pioneer-av-volumio ntpd[998]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Nov 23 18:54:34 pioneer-av-volumio dhcpcd[668]: eth0: leased 192.168.2.187 for 1814400 seconds Nov 23 18:54:34 pioneer-av-volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. Nov 23 18:54:34 pioneer-av-volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... Nov 23 18:54:34 pioneer-av-volumio systemd[1]: welcome.service: Deactivated successfully. Nov 23 18:54:34 pioneer-av-volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. Nov 23 18:54:34 pioneer-av-volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... Nov 23 18:54:34 pioneer-av-volumio dhcpcd[668]: eth0: adding route to 192.168.2.0/24 Nov 23 18:54:34 pioneer-av-volumio dhcpcd[668]: eth0: adding default route via 192.168.2.1 Nov 23 18:54:34 pioneer-av-volumio systemd[1]: Starting welcome.service - Show a welcome message on console... Nov 23 18:54:34 pioneer-av-volumio welcome[3568]: Resolved ip:[1] 192.168.2.187 Nov 23 18:54:34 pioneer-av-volumio systemd[1]: Finished welcome.service - Show a welcome message on console. Nov 23 18:54:34 pioneer-av-volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. Nov 23 18:54:34 pioneer-av-volumio ntpd[998]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Nov 23 18:54:34 pioneer-av-volumio ntpd[998]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Nov 23 18:54:34 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 193.99.165.216 Nov 23 18:54:34 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 129.70.132.35 Nov 23 18:54:34 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 91.98.23.146 Nov 23 18:54:34 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 144.76.43.40 Nov 23 18:54:34 pioneer-av-volumio ntpd[998]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Nov 23 18:54:35 pioneer-av-volumio volumio[3239]: info: go-librespot daemon successfully initialized Nov 23 18:54:35 pioneer-av-volumio ntpd[998]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Nov 23 18:54:35 pioneer-av-volumio ntpd[998]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Nov 23 18:54:35 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 79.133.44.142 Nov 23 18:54:35 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 141.144.241.16 Nov 23 18:54:35 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 185.248.189.10 Nov 23 18:54:35 pioneer-av-volumio ntpd[998]: DNS: Pool taking: 131.188.3.223 Nov 23 18:54:35 pioneer-av-volumio ntpd[998]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Nov 23 18:54:36 pioneer-av-volumio volumio[3239]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 23 18:54:36 pioneer-av-volumio volumio[3239]: Error: addMembership ENODEV Nov 23 18:54:36 pioneer-av-volumio volumio[3239]: at Socket.addMembership (node:dgram:860:11) Nov 23 18:54:36 pioneer-av-volumio volumio[3239]: at addMembership (/volumio/node_modules/node-ssdp/lib/index.js:264:16) { Nov 23 18:54:36 pioneer-av-volumio volumio[3239]: errno: -19, Nov 23 18:54:36 pioneer-av-volumio volumio[3239]: code: 'ENODEV', Nov 23 18:54:36 pioneer-av-volumio volumio[3239]: syscall: 'addMembership' Nov 23 18:54:36 pioneer-av-volumio volumio[3239]: } Nov 23 18:54:36 pioneer-av-volumio volumio[3239]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 23 18:54:36 pioneer-av-volumio sudo[3597]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-11-23 18:53' Nov 23 18:54:36 pioneer-av-volumio sudo[3597]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="ec1ce6b3390e13e82b9cc0453f957c4f5298419e" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon Nov 17 16:31:40 UTC 2025" VOLUMIO_VERSION="4.071" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5fbe1bcf6936184712979c0bfaf061f2"