-- Logs begin at Sat 2024-05-04 15:13:03 HKT, end at Wed 2024-05-08 15:06:45 HKT. -- May 08 15:05:43 volumio wpa_supplicant[670]: wlan0: CTRL-EVENT-DISCONNECTED bssid=58:11:22:59:89:14 reason=0 locally_generated=1 May 08 15:05:43 volumio dhcpcd[684]: wlan0: carrier lost May 08 15:05:43 volumio wpa_supplicant[670]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD May 08 15:05:43 volumio wpa_supplicant[670]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US May 08 15:05:43 volumio avahi-daemon[460]: Withdrawing address record for 192.168.10.89 on wlan0. May 08 15:05:43 volumio avahi-daemon[460]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.10.89. May 08 15:05:43 volumio avahi-daemon[460]: Interface wlan0.IPv4 no longer relevant for mDNS. May 08 15:05:43 volumio dhcpcd[684]: wlan0: deleting route to 192.168.10.0/24 May 08 15:05:43 volumio dhcpcd[684]: wlan0: deleting default route via 192.168.10.1 May 08 15:05:43 volumio volumio[16775]: info: Discovery: A device disappeared from network May 08 15:05:43 volumio volumio[16775]: info: Discovery: Device volumio disappeared from network May 08 15:05:44 volumio ntpd[563]: Deleting interface #6 wlan0, 192.168.10.89#123, interface stats: received=8792, sent=8950, dropped=0, active_time=1556909 secs May 08 15:05:44 volumio ntpd[563]: 223.255.185.3 local addr 192.168.10.89 -> May 08 15:05:44 volumio ntpd[563]: 203.9.150.169 local addr 192.168.10.89 -> May 08 15:05:44 volumio ntpd[563]: 223.255.185.2 local addr 192.168.10.89 -> May 08 15:05:44 volumio ntpd[563]: 157.119.101.135 local addr 192.168.10.89 -> May 08 15:05:44 volumio ntpd[563]: 45.125.1.20 local addr 192.168.10.89 -> May 08 15:05:44 volumio ntpd[563]: 118.143.17.83 local addr 192.168.10.89 -> May 08 15:05:45 volumio volumio[16775]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 08 15:05:45 volumio volumio[16775]: Error: send ENETUNREACH 255.255.255.255:3483 May 08 15:05:45 volumio volumio[16775]: at doSend (dgram.js:692:16) May 08 15:05:45 volumio volumio[16775]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) May 08 15:05:45 volumio volumio[16775]: at afterDns (dgram.js:638:5) May 08 15:05:45 volumio volumio[16775]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { May 08 15:05:45 volumio volumio[16775]: errno: -101, May 08 15:05:45 volumio volumio[16775]: code: 'ENETUNREACH', May 08 15:05:45 volumio volumio[16775]: syscall: 'send', May 08 15:05:45 volumio volumio[16775]: address: '255.255.255.255', May 08 15:05:45 volumio volumio[16775]: port: 3483 May 08 15:05:45 volumio volumio[16775]: } May 08 15:05:45 volumio volumio[16775]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 08 15:05:45 volumio sudo[15656]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-08 15:04 May 08 15:05:45 volumio sudo[15656]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:05:45 volumio sudo[15656]: pam_unix(sudo:session): session closed for user root May 08 15:05:46 volumio volumio-remote-updater[461]: [2024-05-08 15:05:46] [error] handle_read_frame error: websocketpp.transport:7 (End of File) May 08 15:05:46 volumio volumio-remote-updater[461]: [2024-05-08 15:05:46] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] May 08 15:05:46 volumio go-librespot[19072]: time="2024-05-08T15:05:46+08:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" May 08 15:05:46 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE May 08 15:05:46 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. May 08 15:05:46 volumio systemd[1]: Started dynamicswap service. May 08 15:05:46 volumio systemd[1]: dynamicswap.service: Succeeded. May 08 15:05:46 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. May 08 15:05:46 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 29. May 08 15:05:46 volumio systemd[1]: Started dynamicswap service. May 08 15:05:46 volumio systemd[1]: Stopped Volumio Backend Module. May 08 15:05:46 volumio systemd[1]: Started Volumio Backend Module. May 08 15:05:46 volumio systemd[1]: dynamicswap.service: Succeeded. May 08 15:05:48 volumio volumio[15673]: info: ------------------------------------------- May 08 15:05:48 volumio volumio[15673]: info: ----- Volumio3 ---- May 08 15:05:48 volumio volumio[15673]: info: ------------------------------------------- May 08 15:05:48 volumio volumio[15673]: info: ----- System startup ---- May 08 15:05:48 volumio volumio[15673]: info: ------------------------------------------- May 08 15:05:49 volumio volumio[15673]: info: MYVOLUMIO Environment detected May 08 15:05:50 volumio volumio[15673]: info: Plugin folders cleanup May 08 15:05:50 volumio volumio[15673]: info: Scanning into folder /volumio/app/plugins/ May 08 15:05:50 volumio volumio[15673]: info: Scanning category audio_interface May 08 15:05:50 volumio volumio[15673]: info: Scanning category miscellanea May 08 15:05:50 volumio volumio[15673]: info: Scanning category music_service May 08 15:05:50 volumio volumio[15673]: info: Scanning category plugins.json May 08 15:05:50 volumio volumio[15673]: info: Scanning category system_controller May 08 15:05:50 volumio volumio[15673]: info: Scanning category user_interface May 08 15:05:50 volumio volumio[15673]: info: Scanning into folder /data/plugins/ May 08 15:05:50 volumio volumio[15673]: info: Scanning category music_service May 08 15:05:50 volumio volumio[15673]: info: Plugin folders cleanup completed May 08 15:05:50 volumio volumio[15673]: info: ------------------------------------------- May 08 15:05:50 volumio volumio[15673]: info: ----- Core plugins startup ---- May 08 15:05:50 volumio volumio[15673]: info: ------------------------------------------- May 08 15:05:50 volumio volumio[15673]: info: Loading plugins from folder /volumio/app/plugins/ May 08 15:05:50 volumio volumio[15673]: info: Adding plugin upnp to MyMusic Plugins May 08 15:05:50 volumio volumio[15673]: info: Adding plugin airplay_emulation to MyMusic Plugins May 08 15:05:50 volumio volumio[15673]: info: Adding plugin upnp_browser to MyMusic Plugins May 08 15:05:50 volumio volumio[15673]: info: Loading plugins from folder /data/plugins/ May 08 15:05:50 volumio volumio[15673]: info: Loading plugin "system"... May 08 15:05:50 volumio volumio[15673]: info: Loading plugin "appearance"... May 08 15:05:51 volumio volumio[15673]: info: Loading plugin "network"... May 08 15:05:51 volumio volumio[15673]: info: Refreshing Cached IP Addresses May 08 15:05:51 volumio volumio-remote-updater[461]: [2024-05-08 15:05:51] [connect] Successful connection May 08 15:05:51 volumio sudo[15698]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 08 15:05:51 volumio sudo[15696]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 08 15:05:51 volumio volumio[15673]: info: Loading plugin "services"... May 08 15:05:51 volumio sudo[15696]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:05:51 volumio sudo[15698]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:05:51 volumio volumio[15673]: info: Loading plugin "alsa_controller"... May 08 15:05:51 volumio sudo[15700]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 08 15:05:51 volumio sudo[15698]: pam_unix(sudo:session): session closed for user root May 08 15:05:51 volumio sudo[15700]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:05:51 volumio sudo[15700]: pam_unix(sudo:session): session closed for user root May 08 15:05:51 volumio sudo[15696]: pam_unix(sudo:session): session closed for user root May 08 15:05:51 volumio volumio[15673]: warn: Unable to locate the audio output device FiiO K5 Pro. Please configure a valid output device. May 08 15:05:51 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 08 15:05:51 volumio volumio[15673]: info: Loading plugin "wizard"... May 08 15:05:51 volumio volumio[15673]: info: Loading plugin "volumio_command_line_client"... May 08 15:05:51 volumio volumio[15673]: info: Loading plugin "upnp"... May 08 15:05:51 volumio volumio[15673]: info: [1715151951671] Starting Upmpd Daemon May 08 15:05:51 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 08 15:05:51 volumio volumio[15673]: info: Loading plugin "my_music"... May 08 15:05:51 volumio volumio[15673]: info: Loading plugin "mpd"... May 08 15:05:52 volumio volumio[15673]: info: Creating MPD Configuration file May 08 15:05:52 volumio volumio[15673]: info: Loading plugin "upnp_browser"... May 08 15:05:52 volumio sudo[15710]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 08 15:05:52 volumio sudo[15710]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:05:52 volumio sudo[15712]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 08 15:05:52 volumio sudo[15710]: pam_unix(sudo:session): session closed for user root May 08 15:05:52 volumio sudo[15712]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:05:52 volumio systemd[1]: Stopping Music Player Daemon... May 08 15:05:52 volumio volumio[15673]: info: Loading plugin "networkfs"... May 08 15:05:53 volumio systemd[1]: mpd.service: Succeeded. May 08 15:05:53 volumio systemd[1]: Stopped Music Player Daemon. May 08 15:05:53 volumio systemd[1]: Starting Music Player Daemon... May 08 15:05:53 volumio volumio[15673]: info: Cannot mount NAS pishare at system boot, trial number 1 ,retrying in 5 seconds May 08 15:05:53 volumio volumio[15673]: info: Cannot mount NAS rpi at system boot, trial number 1 ,retrying in 5 seconds May 08 15:05:53 volumio volumio[15673]: info: Cannot mount NAS music at system boot, trial number 1 ,retrying in 5 seconds May 08 15:05:53 volumio volumio[15673]: info: Starting Udev Watcher for removable devices May 08 15:05:53 volumio volumio[15673]: info: Ignoring mount for partition: boot May 08 15:05:53 volumio volumio[15673]: info: Ignoring mount for partition: volumio May 08 15:05:53 volumio volumio[15673]: info: Ignoring mount for partition: volumio_data May 08 15:05:53 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 08 15:05:53 volumio volumio[15673]: info: Loading plugin "alarm-clock"... May 08 15:05:53 volumio volumio[15673]: info: Loading plugin "airplay_emulation"... May 08 15:05:53 volumio volumio[15673]: info: Starting Shairport Sync May 08 15:05:53 volumio volumio[15673]: info: Loading plugin "last_100"... May 08 15:05:53 volumio volumio[15673]: info: Loading plugin "webradio"... May 08 15:05:54 volumio volumio[15673]: info: Loading plugin "i2s_dacs"... May 08 15:05:54 volumio volumio[15673]: info: I2S DAC not set, start Auto-detection May 08 15:05:54 volumio volumio[15673]: info: Loading plugin "volumiodiscovery"... May 08 15:05:54 volumio volumio[15673]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 08 15:05:54 volumio node[15673]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 08 15:05:54 volumio volumio[15673]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 15:05:54 volumio node[15673]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 15:05:54 volumio volumio[15673]: *** WARNING *** For more information see May 08 15:05:54 volumio node[15673]: *** WARNING *** For more information see May 08 15:05:54 volumio volumio[15673]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 08 15:05:54 volumio node[15673]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 08 15:05:54 volumio volumio[15673]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 15:05:54 volumio node[15673]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 15:05:54 volumio volumio[15673]: *** WARNING *** For more information see May 08 15:05:54 volumio node[15673]: *** WARNING *** For more information see May 08 15:05:54 volumio volumio[15673]: info: Applying required configuration parameters for plugin volumiodiscovery May 08 15:05:54 volumio volumio[15673]: info: Discovery: Started advertising with name: Volumio May 08 15:05:54 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 08 15:05:54 volumio volumio[15673]: info: Loading plugin "spop"... May 08 15:05:55 volumio mpd[15719]: May 08 15:05 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 08 15:05:55 volumio mpd[15719]: May 08 15:05 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured May 08 15:05:55 volumio mpd[15719]: May 08 15:05 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured May 08 15:05:55 volumio systemd[1]: Started Music Player Daemon. May 08 15:05:55 volumio sudo[15712]: pam_unix(sudo:session): session closed for user root May 08 15:05:56 volumio volumio[15673]: info: Loading plugin "squeezelite_mc"... May 08 15:05:57 volumio volumio[15673]: info: Loading plugin "ytcr"... May 08 15:05:59 volumio volumio[15673]: info: Loading plugin "outputs"... May 08 15:05:59 volumio volumio[15673]: info: Loading plugin "albumart"... May 08 15:05:59 volumio volumio[15673]: info: Plugin example_plugin is not enabled May 08 15:05:59 volumio volumio[15673]: info: Loading plugin "inputs"... May 08 15:05:59 volumio volumio[15673]: info: Loading plugin "updater_comm"... May 08 15:05:59 volumio volumio[15673]: info: Plugin mpdemulation is not enabled May 08 15:05:59 volumio volumio[15673]: info: Loading plugin "rest_api"... May 08 15:05:59 volumio volumio[15673]: info: Loading plugin "websocket"... May 08 15:05:59 volumio volumio[15673]: info: Loading i18n strings for locale zh_TW May 08 15:05:59 volumio volumio[15673]: Updating browse sources language May 08 15:05:59 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 15:05:59 volumio volumio[15673]: Forking 3 albumart workers May 08 15:05:59 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 15:05:59 volumio volumio[15673]: info: CoreCommandRouter::initPlayerControls May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 15:06:00 volumio volumio[15673]: Express server listening on port 3000 May 08 15:06:00 volumio volumio[15673]: [Metrics] WebUI: 11s 822.99ms May 08 15:06:00 volumio volumio[15673]: info: CoreStateMachine::resetVolumioState May 08 15:06:00 volumio volumio[15673]: info: CoreStateMachine::getcurrentVolume May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::volumioRetrievevolume May 08 15:06:00 volumio volumio[15673]: info: CoreStateMachine::pushState May 08 15:06:00 volumio volumio[15673]: info: CorePlayQueue::getTrack 0 May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::volumioPushState May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: Cannot mount NAS pishare at system boot, trial number 2 ,retrying in 5 seconds May 08 15:06:00 volumio volumio[15673]: info: Cannot mount NAS rpi at system boot, trial number 2 ,retrying in 5 seconds May 08 15:06:00 volumio volumio[15673]: info: Cannot mount NAS music at system boot, trial number 2 ,retrying in 5 seconds May 08 15:06:00 volumio volumio[15673]: info: MPD Permissions set May 08 15:06:00 volumio volumio[15673]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan May 08 15:06:00 volumio volumio[15673]: wlan0 Interface doesn't support scanning : Device or resource busy May 08 15:06:00 volumio volumio[15673]: info: Cannot use regular scanning, forcing with ap-force May 08 15:06:00 volumio sudo[15758]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force May 08 15:06:00 volumio sudo[15758]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:00 volumio sudo[15758]: pam_unix(sudo:session): session closed for user root May 08 15:06:00 volumio volumio[15673]: command failed: Device or resource busy (-16) May 08 15:06:00 volumio volumio[15673]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force May 08 15:06:00 volumio volumio[15673]: command failed: Device or resource busy (-16) May 08 15:06:00 volumio volumio[15673]: info: MPD running with PID15719 May 08 15:06:00 volumio volumio[15673]: ,establishing connection May 08 15:06:00 volumio volumio[15673]: error: MPD error: The expression evaluated to a falsy value: May 08 15:06:00 volumio volumio[15673]: assert.ok(self.idling) May 08 15:06:00 volumio volumio[15673]: error: The expression evaluated to a falsy value: May 08 15:06:00 volumio volumio[15673]: assert.ok(self.idling) May 08 15:06:00 volumio volumio[15673]: info: Reloading queue from file May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: Setting Device type: Raspberry PI May 08 15:06:00 volumio volumio[15673]: info: CoreStateMachine::setRepeat null single undefined May 08 15:06:00 volumio volumio[15673]: info: CoreStateMachine::pushState May 08 15:06:00 volumio volumio[15673]: info: CorePlayQueue::getTrack 0 May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::volumioPushState May 08 15:06:00 volumio volumio[15673]: info: CoreStateMachine::setRandom null May 08 15:06:00 volumio volumio[15673]: info: CoreStateMachine::pushState May 08 15:06:00 volumio volumio[15673]: info: CorePlayQueue::getTrack 0 May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::volumioPushState May 08 15:06:00 volumio volumio[15673]: error: updateQueue error: null May 08 15:06:00 volumio volumio[15673]: info: Completed loading Core Plugins May 08 15:06:00 volumio volumio[15673]: info: Preparing to generate the ALSA configuration file May 08 15:06:00 volumio volumio[15673]: info: Asound.conf file unchanged, so no further update is needed May 08 15:06:00 volumio volumio[15673]: info: Output device has changed, restarting MPD May 08 15:06:00 volumio volumio[15673]: info: Output device has changed, restarting Shairport Sync May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:00 volumio sudo[15771]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 08 15:06:00 volumio sudo[15771]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:00 volumio sudo[15772]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 08 15:06:00 volumio sudo[15772]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:00 volumio sudo[15771]: pam_unix(sudo:session): session closed for user root May 08 15:06:00 volumio systemd[1]: Stopping Music Player Daemon... May 08 15:06:00 volumio systemd[1]: mpd.service: Succeeded. May 08 15:06:00 volumio systemd[1]: Stopped Music Player Daemon. May 08 15:06:00 volumio volumio[15673]: Starting albumart workers May 08 15:06:00 volumio volumio[15673]: Starting albumart workers May 08 15:06:00 volumio volumio[15673]: Starting albumart workers May 08 15:06:00 volumio volumio[15673]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 08 15:06:00 volumio volumio[15673]: info: ___________ START PLUGINS ___________ May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 08 15:06:00 volumio volumio[15673]: info: [1715151960950] CoreMusicLibrary::Adding element Media Servers May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 15:06:00 volumio systemd[1]: Starting Music Player Daemon... May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:00 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:01 volumio volumio[15673]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 08 15:06:01 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:01 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:01 volumio volumio[15673]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 08 15:06:01 volumio volumio[15673]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 08 15:06:01 volumio volumio[15673]: info: [1715151961075] CoreMusicLibrary::Adding element Last_100 May 08 15:06:01 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 15:06:01 volumio volumio[15673]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 08 15:06:01 volumio volumio[15673]: info: [1715151961079] CoreMusicLibrary::Adding element Webradio May 08 15:06:01 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 15:06:01 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 08 15:06:01 volumio volumio[15673]: info: Creating Spotify config file May 08 15:06:01 volumio volumio[15673]: info: Starting Volume Timer Limit Guard May 08 15:06:01 volumio volumio[15673]: info: Loading Spotify Daemon to Volumio volume map May 08 15:06:01 volumio volumio[15673]: info: [squeezelite_mc] Starting proxy server... May 08 15:06:01 volumio volumio[15673]: info: Volumio Calling Home May 08 15:06:01 volumio volumio[15673]: info: [squeezelite_mc] Proxy server started on port 44611 May 08 15:06:01 volumio volumio[15673]: info: CoreCommandRouter::volumioRetrievevolume May 08 15:06:01 volumio volumio[15673]: info: CoreStateMachine::pushState May 08 15:06:01 volumio volumio[15673]: info: CorePlayQueue::getTrack 0 May 08 15:06:01 volumio volumio[15673]: info: CoreCommandRouter::volumioPushState May 08 15:06:01 volumio volumio[15673]: info: [squeezelite_mc] Server discovery started May 08 15:06:01 volumio volumio[15673]: info: [squeezelite_mc] Player finder started May 08 15:06:01 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:01 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:01 volumio volumio[15673]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 15:06:01 volumio volumio[15673]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true May 08 15:06:01 volumio volumio[15673]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 08 15:06:01 volumio volumio[15673]: Error: send ENETUNREACH 255.255.255.255:3483 May 08 15:06:01 volumio volumio[15673]: at doSend (dgram.js:692:16) May 08 15:06:01 volumio volumio[15673]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) May 08 15:06:01 volumio volumio[15673]: at afterDns (dgram.js:638:5) May 08 15:06:01 volumio volumio[15673]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { May 08 15:06:01 volumio volumio[15673]: errno: -101, May 08 15:06:01 volumio volumio[15673]: code: 'ENETUNREACH', May 08 15:06:01 volumio volumio[15673]: syscall: 'send', May 08 15:06:01 volumio volumio[15673]: address: '255.255.255.255', May 08 15:06:01 volumio volumio[15673]: port: 3483 May 08 15:06:01 volumio volumio[15673]: } May 08 15:06:01 volumio volumio[15673]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 08 15:06:01 volumio wpa_supplicant[670]: wlan0: Failed to initiate sched scan May 08 15:06:02 volumio sudo[15826]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-08 15:05 May 08 15:06:02 volumio sudo[15826]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:02 volumio sudo[15826]: pam_unix(sudo:session): session closed for user root May 08 15:06:02 volumio mpd[15787]: May 08 15:06 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 08 15:06:02 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE May 08 15:06:02 volumio sudo[15772]: pam_unix(sudo:session): session closed for user root May 08 15:06:02 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. May 08 15:06:02 volumio systemd[1]: Started dynamicswap service. May 08 15:06:02 volumio systemd[1]: dynamicswap.service: Succeeded. May 08 15:06:02 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. May 08 15:06:02 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 30. May 08 15:06:02 volumio systemd[1]: Started dynamicswap service. May 08 15:06:02 volumio systemd[1]: Stopped Volumio Backend Module. May 08 15:06:02 volumio systemd[1]: Started Volumio Backend Module. May 08 15:06:02 volumio systemd[1]: dynamicswap.service: Succeeded. May 08 15:06:02 volumio mpd[15787]: May 08 15:06 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured May 08 15:06:02 volumio mpd[15787]: May 08 15:06 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured May 08 15:06:02 volumio systemd[1]: Started Music Player Daemon. May 08 15:06:03 volumio volumio-remote-updater[461]: [2024-05-08 15:06:03] [info] asio async_connect error: system:111 (Connection refused) May 08 15:06:03 volumio volumio-remote-updater[461]: [2024-05-08 15:06:03] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) May 08 15:06:03 volumio volumio-remote-updater[461]: [2024-05-08 15:06:03] [error] handle_connect error: Underlying Transport Error May 08 15:06:04 volumio volumio[15841]: info: ------------------------------------------- May 08 15:06:04 volumio volumio[15841]: info: ----- Volumio3 ---- May 08 15:06:04 volumio volumio[15841]: info: ------------------------------------------- May 08 15:06:04 volumio volumio[15841]: info: ----- System startup ---- May 08 15:06:04 volumio volumio[15841]: info: ------------------------------------------- May 08 15:06:05 volumio volumio[15841]: info: MYVOLUMIO Environment detected May 08 15:06:05 volumio volumio[15841]: info: Plugin folders cleanup May 08 15:06:05 volumio volumio[15841]: info: Scanning into folder /volumio/app/plugins/ May 08 15:06:05 volumio volumio[15841]: info: Scanning category audio_interface May 08 15:06:05 volumio volumio[15841]: info: Scanning category miscellanea May 08 15:06:05 volumio volumio[15841]: info: Scanning category music_service May 08 15:06:05 volumio volumio[15841]: info: Scanning category plugins.json May 08 15:06:05 volumio volumio[15841]: info: Scanning category system_controller May 08 15:06:05 volumio volumio[15841]: info: Scanning category user_interface May 08 15:06:05 volumio volumio[15841]: info: Scanning into folder /data/plugins/ May 08 15:06:05 volumio volumio[15841]: info: Scanning category music_service May 08 15:06:05 volumio volumio[15841]: info: Plugin folders cleanup completed May 08 15:06:05 volumio volumio[15841]: info: ------------------------------------------- May 08 15:06:05 volumio volumio[15841]: info: ----- Core plugins startup ---- May 08 15:06:05 volumio volumio[15841]: info: ------------------------------------------- May 08 15:06:05 volumio volumio[15841]: info: Loading plugins from folder /volumio/app/plugins/ May 08 15:06:05 volumio volumio[15841]: info: Adding plugin upnp to MyMusic Plugins May 08 15:06:05 volumio volumio[15841]: info: Adding plugin airplay_emulation to MyMusic Plugins May 08 15:06:05 volumio volumio[15841]: info: Adding plugin upnp_browser to MyMusic Plugins May 08 15:06:05 volumio volumio[15841]: info: Loading plugins from folder /data/plugins/ May 08 15:06:05 volumio volumio[15841]: info: Loading plugin "system"... May 08 15:06:05 volumio volumio[15841]: info: Loading plugin "appearance"... May 08 15:06:06 volumio volumio[15841]: info: Loading plugin "network"... May 08 15:06:06 volumio volumio[15841]: info: Refreshing Cached IP Addresses May 08 15:06:06 volumio sudo[15867]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 08 15:06:06 volumio sudo[15867]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:07 volumio volumio[15841]: info: Loading plugin "services"... May 08 15:06:07 volumio sudo[15869]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 08 15:06:07 volumio sudo[15869]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:07 volumio volumio[15841]: info: Loading plugin "alsa_controller"... May 08 15:06:07 volumio sudo[15869]: pam_unix(sudo:session): session closed for user root May 08 15:06:07 volumio sudo[15872]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 08 15:06:07 volumio sudo[15872]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:07 volumio sudo[15872]: pam_unix(sudo:session): session closed for user root May 08 15:06:07 volumio sudo[15867]: pam_unix(sudo:session): session closed for user root May 08 15:06:07 volumio volumio[15841]: warn: Unable to locate the audio output device FiiO K5 Pro. Please configure a valid output device. May 08 15:06:07 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 08 15:06:07 volumio volumio[15841]: info: Loading plugin "wizard"... May 08 15:06:07 volumio volumio[15841]: info: Loading plugin "volumio_command_line_client"... May 08 15:06:07 volumio volumio[15841]: info: Loading plugin "upnp"... May 08 15:06:07 volumio volumio[15841]: info: [1715151967121] Starting Upmpd Daemon May 08 15:06:07 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 08 15:06:07 volumio volumio[15841]: info: Loading plugin "my_music"... May 08 15:06:07 volumio volumio[15841]: info: Loading plugin "mpd"... May 08 15:06:07 volumio volumio[15841]: info: Creating MPD Configuration file May 08 15:06:07 volumio volumio[15841]: info: Loading plugin "upnp_browser"... May 08 15:06:07 volumio sudo[15880]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 08 15:06:07 volumio sudo[15880]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:07 volumio sudo[15880]: pam_unix(sudo:session): session closed for user root May 08 15:06:07 volumio sudo[15882]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 08 15:06:07 volumio sudo[15882]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:07 volumio systemd[1]: Stopping Music Player Daemon... May 08 15:06:07 volumio systemd[1]: mpd.service: Succeeded. May 08 15:06:07 volumio systemd[1]: Stopped Music Player Daemon. May 08 15:06:07 volumio systemd[1]: Starting Music Player Daemon... May 08 15:06:08 volumio volumio[15841]: info: Loading plugin "networkfs"... May 08 15:06:08 volumio volumio[15841]: info: Cannot mount NAS pishare at system boot, trial number 1 ,retrying in 5 seconds May 08 15:06:08 volumio volumio[15841]: info: Cannot mount NAS rpi at system boot, trial number 1 ,retrying in 5 seconds May 08 15:06:08 volumio volumio[15841]: info: Cannot mount NAS music at system boot, trial number 1 ,retrying in 5 seconds May 08 15:06:08 volumio volumio[15841]: info: Starting Udev Watcher for removable devices May 08 15:06:08 volumio volumio[15841]: info: Ignoring mount for partition: boot May 08 15:06:08 volumio volumio[15841]: info: Ignoring mount for partition: volumio May 08 15:06:08 volumio volumio[15841]: info: Ignoring mount for partition: volumio_data May 08 15:06:08 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 08 15:06:08 volumio volumio[15841]: info: Loading plugin "alarm-clock"... May 08 15:06:08 volumio volumio[15841]: info: Loading plugin "airplay_emulation"... May 08 15:06:08 volumio volumio[15841]: info: Starting Shairport Sync May 08 15:06:08 volumio volumio[15841]: info: Loading plugin "last_100"... May 08 15:06:08 volumio volumio[15841]: info: Loading plugin "webradio"... May 08 15:06:08 volumio volumio[15841]: info: Loading plugin "i2s_dacs"... May 08 15:06:08 volumio volumio[15841]: info: I2S DAC not set, start Auto-detection May 08 15:06:08 volumio volumio[15841]: info: Loading plugin "volumiodiscovery"... May 08 15:06:09 volumio volumio[15841]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 08 15:06:09 volumio volumio[15841]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 15:06:09 volumio volumio[15841]: *** WARNING *** For more information see May 08 15:06:09 volumio volumio[15841]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 08 15:06:09 volumio volumio[15841]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 15:06:09 volumio volumio[15841]: *** WARNING *** For more information see May 08 15:06:09 volumio node[15841]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 08 15:06:09 volumio node[15841]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 15:06:09 volumio node[15841]: *** WARNING *** For more information see May 08 15:06:09 volumio node[15841]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 08 15:06:09 volumio node[15841]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 15:06:09 volumio node[15841]: *** WARNING *** For more information see May 08 15:06:09 volumio volumio[15841]: info: Applying required configuration parameters for plugin volumiodiscovery May 08 15:06:09 volumio volumio[15841]: info: Discovery: Started advertising with name: Volumio May 08 15:06:09 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 08 15:06:09 volumio volumio[15841]: info: Loading plugin "spop"... May 08 15:06:09 volumio mpd[15891]: May 08 15:06 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 08 15:06:09 volumio mpd[15891]: May 08 15:06 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured May 08 15:06:09 volumio mpd[15891]: May 08 15:06 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured May 08 15:06:09 volumio systemd[1]: Started Music Player Daemon. May 08 15:06:09 volumio sudo[15882]: pam_unix(sudo:session): session closed for user root May 08 15:06:09 volumio wpa_supplicant[670]: wlan0: Failed to initiate sched scan May 08 15:06:10 volumio volumio[15841]: info: Loading plugin "squeezelite_mc"... May 08 15:06:11 volumio volumio[15841]: info: Loading plugin "ytcr"... May 08 15:06:13 volumio volumio[15841]: info: Loading plugin "outputs"... May 08 15:06:13 volumio volumio[15841]: info: Loading plugin "albumart"... May 08 15:06:13 volumio volumio[15841]: info: Plugin example_plugin is not enabled May 08 15:06:13 volumio volumio[15841]: info: Loading plugin "inputs"... May 08 15:06:13 volumio volumio[15841]: info: Loading plugin "updater_comm"... May 08 15:06:13 volumio volumio[15841]: info: Plugin mpdemulation is not enabled May 08 15:06:13 volumio volumio[15841]: info: Loading plugin "rest_api"... May 08 15:06:13 volumio volumio[15841]: info: Loading plugin "websocket"... May 08 15:06:13 volumio volumio[15841]: info: Loading i18n strings for locale zh_TW May 08 15:06:13 volumio volumio[15841]: Updating browse sources language May 08 15:06:13 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 15:06:13 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 15:06:13 volumio volumio[15841]: info: CoreCommandRouter::initPlayerControls May 08 15:06:13 volumio volumio[15841]: Forking 3 albumart workers May 08 15:06:13 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:13 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:13 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:13 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:13 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:13 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:13 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:13 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:13 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 15:06:13 volumio volumio[15841]: Express server listening on port 3000 May 08 15:06:13 volumio volumio[15841]: [Metrics] WebUI: 9s 589.21ms May 08 15:06:13 volumio volumio[15841]: info: CoreStateMachine::resetVolumioState May 08 15:06:13 volumio volumio[15841]: info: CoreStateMachine::getcurrentVolume May 08 15:06:13 volumio volumio[15841]: info: CoreCommandRouter::volumioRetrievevolume May 08 15:06:13 volumio volumio[15841]: info: CoreStateMachine::pushState May 08 15:06:13 volumio volumio[15841]: info: CorePlayQueue::getTrack 0 May 08 15:06:13 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 15:06:13 volumio volumio[15841]: info: CoreCommandRouter::volumioPushState May 08 15:06:13 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:13 volumio volumio[15841]: info: Cannot mount NAS pishare at system boot, trial number 2 ,retrying in 5 seconds May 08 15:06:13 volumio volumio[15841]: info: Cannot mount NAS rpi at system boot, trial number 2 ,retrying in 5 seconds May 08 15:06:13 volumio volumio[15841]: info: Cannot mount NAS music at system boot, trial number 2 ,retrying in 5 seconds May 08 15:06:13 volumio volumio-remote-updater[461]: [2024-05-08 15:06:13] [connect] Successful connection May 08 15:06:13 volumio volumio[15841]: info: MPD Permissions set May 08 15:06:13 volumio volumio[15841]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan May 08 15:06:13 volumio volumio[15841]: wlan0 Interface doesn't support scanning : Device or resource busy May 08 15:06:13 volumio volumio[15841]: info: Cannot use regular scanning, forcing with ap-force May 08 15:06:13 volumio sudo[15931]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force May 08 15:06:13 volumio sudo[15931]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:14 volumio volumio[15841]: Starting albumart workers May 08 15:06:14 volumio volumio[15841]: Starting albumart workers May 08 15:06:14 volumio volumio[15841]: Starting albumart workers May 08 15:06:15 volumio go-librespot[19072]: time="2024-05-08T15:06:15+08:00" level=error msg="did not receive last pong from dealer, 60s passed" May 08 15:06:16 volumio sudo[15931]: pam_unix(sudo:session): session closed for user root May 08 15:06:16 volumio volumio[15841]: info: MPD running with PID15891 May 08 15:06:16 volumio volumio[15841]: ,establishing connection May 08 15:06:17 volumio volumio[15841]: error: MPD error: The expression evaluated to a falsy value: May 08 15:06:17 volumio volumio[15841]: assert.ok(self.idling) May 08 15:06:17 volumio volumio[15841]: error: The expression evaluated to a falsy value: May 08 15:06:17 volumio volumio[15841]: assert.ok(self.idling) May 08 15:06:17 volumio volumio-remote-updater[461]: [2024-05-08 15:06:17] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1715151973 101 May 08 15:06:17 volumio volumio[15841]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 1 May 08 15:06:17 volumio volumio[15841]: info: Reloading queue from file May 08 15:06:17 volumio volumio[15841]: info: CoreStateMachine::setRepeat null single undefined May 08 15:06:17 volumio volumio[15841]: info: CoreStateMachine::pushState May 08 15:06:17 volumio volumio[15841]: info: CorePlayQueue::getTrack 0 May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::volumioPushState May 08 15:06:17 volumio volumio[15841]: info: CoreStateMachine::setRandom null May 08 15:06:17 volumio volumio[15841]: info: CoreStateMachine::pushState May 08 15:06:17 volumio volumio[15841]: info: CorePlayQueue::getTrack 0 May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::volumioPushState May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: Setting Device type: Raspberry PI May 08 15:06:17 volumio volumio[15841]: error: updateQueue error: null May 08 15:06:17 volumio sudo[15966]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 08 15:06:17 volumio sudo[15966]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:17 volumio volumio[15841]: info: Completed loading Core Plugins May 08 15:06:17 volumio volumio[15841]: info: Preparing to generate the ALSA configuration file May 08 15:06:17 volumio sudo[15968]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 08 15:06:17 volumio sudo[15968]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:17 volumio sudo[15968]: pam_unix(sudo:session): session closed for user root May 08 15:06:17 volumio sudo[15966]: pam_unix(sudo:session): session closed for user root May 08 15:06:17 volumio volumio[15841]: info: Asound.conf file unchanged, so no further update is needed May 08 15:06:17 volumio volumio[15841]: info: Output device has changed, restarting MPD May 08 15:06:17 volumio sudo[15974]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 08 15:06:17 volumio sudo[15974]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:17 volumio volumio[15841]: info: Output device has changed, restarting Shairport Sync May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:17 volumio sudo[15977]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 08 15:06:17 volumio sudo[15977]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:17 volumio sudo[15974]: pam_unix(sudo:session): session closed for user root May 08 15:06:17 volumio sudo[15977]: pam_unix(sudo:session): session closed for user root May 08 15:06:17 volumio sudo[15979]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 08 15:06:17 volumio sudo[15979]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:17 volumio systemd[1]: Stopping Music Player Daemon... May 08 15:06:17 volumio systemd[1]: mpd.service: Succeeded. May 08 15:06:17 volumio systemd[1]: Stopped Music Player Daemon. May 08 15:06:17 volumio volumio[15841]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 08 15:06:17 volumio volumio[15841]: info: ___________ START PLUGINS ___________ May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 08 15:06:17 volumio volumio[15841]: info: [1715151977442] CoreMusicLibrary::Adding element Media Servers May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:17 volumio systemd[1]: Starting Music Player Daemon... May 08 15:06:17 volumio volumio[15841]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 08 15:06:17 volumio volumio[15841]: info: [1715151977561] CoreMusicLibrary::Adding element Last_100 May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 08 15:06:17 volumio volumio[15841]: info: [1715151977566] CoreMusicLibrary::Adding element Webradio May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 08 15:06:17 volumio volumio[15841]: info: Creating Spotify config file May 08 15:06:17 volumio volumio[15841]: info: Starting Volume Timer Limit Guard May 08 15:06:17 volumio volumio[15841]: info: Loading Spotify Daemon to Volumio volume map May 08 15:06:17 volumio volumio[15841]: info: [squeezelite_mc] Starting proxy server... May 08 15:06:17 volumio volumio[15841]: info: Volumio Calling Home May 08 15:06:17 volumio volumio[15841]: info: [squeezelite_mc] Proxy server started on port 46149 May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::volumioRetrievevolume May 08 15:06:17 volumio volumio[15841]: info: CoreStateMachine::pushState May 08 15:06:17 volumio volumio[15841]: info: CorePlayQueue::getTrack 0 May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::volumioPushState May 08 15:06:17 volumio volumio[15841]: info: [squeezelite_mc] Server discovery started May 08 15:06:17 volumio volumio[15841]: info: [squeezelite_mc] Player finder started May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 15:06:17 volumio volumio[15841]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true May 08 15:06:17 volumio volumio[15841]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 08 15:06:17 volumio volumio[15841]: Error: send ENETUNREACH 255.255.255.255:3483 May 08 15:06:17 volumio volumio[15841]: at doSend (dgram.js:692:16) May 08 15:06:17 volumio volumio[15841]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) May 08 15:06:17 volumio volumio[15841]: at afterDns (dgram.js:638:5) May 08 15:06:17 volumio volumio[15841]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { May 08 15:06:17 volumio volumio[15841]: errno: -101, May 08 15:06:17 volumio volumio[15841]: code: 'ENETUNREACH', May 08 15:06:17 volumio volumio[15841]: syscall: 'send', May 08 15:06:17 volumio volumio[15841]: address: '255.255.255.255', May 08 15:06:17 volumio volumio[15841]: port: 3483 May 08 15:06:17 volumio volumio[15841]: } May 08 15:06:17 volumio volumio[15841]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 08 15:06:18 volumio sudo[16008]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-08 15:05 May 08 15:06:18 volumio sudo[16008]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:18 volumio sudo[16008]: pam_unix(sudo:session): session closed for user root May 08 15:06:18 volumio volumio-remote-updater[461]: [2024-05-08 15:06:18] [error] handle_read_frame error: websocketpp.transport:7 (End of File) May 08 15:06:18 volumio volumio-remote-updater[461]: [2024-05-08 15:06:18] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] May 08 15:06:18 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE May 08 15:06:18 volumio sudo[15979]: pam_unix(sudo:session): session closed for user root May 08 15:06:18 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. May 08 15:06:18 volumio systemd[1]: Started dynamicswap service. May 08 15:06:18 volumio mpd[15993]: May 08 15:06 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 08 15:06:18 volumio systemd[1]: dynamicswap.service: Succeeded. May 08 15:06:18 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. May 08 15:06:18 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 31. May 08 15:06:18 volumio systemd[1]: Started dynamicswap service. May 08 15:06:18 volumio systemd[1]: Stopped Volumio Backend Module. May 08 15:06:18 volumio systemd[1]: Started Volumio Backend Module. May 08 15:06:18 volumio systemd[1]: dynamicswap.service: Succeeded. May 08 15:06:19 volumio mpd[15993]: May 08 15:06 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured May 08 15:06:19 volumio mpd[15993]: May 08 15:06 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured May 08 15:06:19 volumio systemd[1]: Started Music Player Daemon. May 08 15:06:19 volumio wpa_supplicant[670]: wlan0: Trying to associate with SSID 'HomeNetwork' May 08 15:06:20 volumio volumio[16022]: info: ------------------------------------------- May 08 15:06:20 volumio volumio[16022]: info: ----- Volumio3 ---- May 08 15:06:20 volumio volumio[16022]: info: ------------------------------------------- May 08 15:06:20 volumio volumio[16022]: info: ----- System startup ---- May 08 15:06:20 volumio volumio[16022]: info: ------------------------------------------- May 08 15:06:20 volumio go-librespot[19072]: time="2024-05-08T15:06:20+08:00" level=error msg="failed receiving dealer message" error="failed to get reader: WebSocket closed: sent close frame: status = StatusServiceRestart and reason = \"\"" May 08 15:06:20 volumio go-librespot[19072]: time="2024-05-08T15:06:20+08:00" level=warning msg="failed fetching new endpoint for dealer" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=dealer\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 08 15:06:21 volumio go-librespot[19072]: time="2024-05-08T15:06:21+08:00" level=warning msg="failed fetching new endpoint for dealer" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=dealer\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 08 15:06:21 volumio volumio[16022]: info: MYVOLUMIO Environment detected May 08 15:06:21 volumio volumio[16022]: info: Plugin folders cleanup May 08 15:06:21 volumio volumio[16022]: info: Scanning into folder /volumio/app/plugins/ May 08 15:06:21 volumio volumio[16022]: info: Scanning category audio_interface May 08 15:06:21 volumio volumio[16022]: info: Scanning category miscellanea May 08 15:06:21 volumio volumio[16022]: info: Scanning category music_service May 08 15:06:21 volumio volumio[16022]: info: Scanning category plugins.json May 08 15:06:21 volumio volumio[16022]: info: Scanning category system_controller May 08 15:06:21 volumio volumio[16022]: info: Scanning category user_interface May 08 15:06:21 volumio volumio[16022]: info: Scanning into folder /data/plugins/ May 08 15:06:21 volumio volumio[16022]: info: Scanning category music_service May 08 15:06:21 volumio volumio[16022]: info: Plugin folders cleanup completed May 08 15:06:21 volumio volumio[16022]: info: ------------------------------------------- May 08 15:06:21 volumio volumio[16022]: info: ----- Core plugins startup ---- May 08 15:06:21 volumio volumio[16022]: info: ------------------------------------------- May 08 15:06:21 volumio volumio[16022]: info: Loading plugins from folder /volumio/app/plugins/ May 08 15:06:21 volumio volumio[16022]: info: Adding plugin upnp to MyMusic Plugins May 08 15:06:21 volumio volumio[16022]: info: Adding plugin airplay_emulation to MyMusic Plugins May 08 15:06:21 volumio volumio[16022]: info: Adding plugin upnp_browser to MyMusic Plugins May 08 15:06:21 volumio volumio[16022]: info: Loading plugins from folder /data/plugins/ May 08 15:06:21 volumio volumio[16022]: info: Loading plugin "system"... May 08 15:06:21 volumio volumio[16022]: info: Loading plugin "appearance"... May 08 15:06:22 volumio go-librespot[19072]: time="2024-05-08T15:06:22+08:00" level=warning msg="failed fetching new endpoint for dealer" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=dealer\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 08 15:06:22 volumio wpa_supplicant[670]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 May 08 15:06:23 volumio volumio[16022]: info: Loading plugin "network"... May 08 15:06:23 volumio volumio[16022]: info: Refreshing Cached IP Addresses May 08 15:06:23 volumio sudo[16047]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 08 15:06:23 volumio sudo[16047]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:23 volumio sudo[16049]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 08 15:06:23 volumio sudo[16049]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:23 volumio volumio[16022]: info: Loading plugin "services"... May 08 15:06:23 volumio sudo[16049]: pam_unix(sudo:session): session closed for user root May 08 15:06:23 volumio sudo[16047]: pam_unix(sudo:session): session closed for user root May 08 15:06:23 volumio volumio[16022]: info: Loading plugin "alsa_controller"... May 08 15:06:23 volumio sudo[16053]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 08 15:06:23 volumio sudo[16053]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:23 volumio sudo[16053]: pam_unix(sudo:session): session closed for user root May 08 15:06:23 volumio volumio[16022]: warn: Unable to locate the audio output device FiiO K5 Pro. Please configure a valid output device. May 08 15:06:23 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 08 15:06:23 volumio volumio[16022]: info: Loading plugin "wizard"... May 08 15:06:23 volumio volumio[16022]: info: Loading plugin "volumio_command_line_client"... May 08 15:06:23 volumio volumio[16022]: info: Loading plugin "upnp"... May 08 15:06:23 volumio volumio[16022]: info: [1715151983223] Starting Upmpd Daemon May 08 15:06:23 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 08 15:06:23 volumio volumio[16022]: info: Loading plugin "my_music"... May 08 15:06:23 volumio volumio[16022]: info: Loading plugin "mpd"... May 08 15:06:23 volumio volumio[16022]: info: Creating MPD Configuration file May 08 15:06:23 volumio volumio[16022]: info: Loading plugin "upnp_browser"... May 08 15:06:23 volumio sudo[16060]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 08 15:06:23 volumio sudo[16060]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:23 volumio sudo[16060]: pam_unix(sudo:session): session closed for user root May 08 15:06:23 volumio sudo[16062]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 08 15:06:23 volumio sudo[16062]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:23 volumio volumio-remote-updater[461]: [2024-05-08 15:06:23] [connect] Successful connection May 08 15:06:23 volumio systemd[1]: Stopping Music Player Daemon... May 08 15:06:23 volumio systemd[1]: mpd.service: Succeeded. May 08 15:06:23 volumio systemd[1]: Stopped Music Player Daemon. May 08 15:06:23 volumio go-librespot[19072]: time="2024-05-08T15:06:23+08:00" level=warning msg="failed fetching new endpoint for dealer" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=dealer\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 08 15:06:23 volumio systemd[1]: Starting Music Player Daemon... May 08 15:06:24 volumio volumio[16022]: info: Loading plugin "networkfs"... May 08 15:06:24 volumio volumio[16022]: info: Cannot mount NAS pishare at system boot, trial number 1 ,retrying in 5 seconds May 08 15:06:24 volumio volumio[16022]: info: Cannot mount NAS rpi at system boot, trial number 1 ,retrying in 5 seconds May 08 15:06:24 volumio volumio[16022]: info: Cannot mount NAS music at system boot, trial number 1 ,retrying in 5 seconds May 08 15:06:24 volumio volumio[16022]: info: Starting Udev Watcher for removable devices May 08 15:06:24 volumio volumio[16022]: info: Ignoring mount for partition: boot May 08 15:06:24 volumio volumio[16022]: info: Ignoring mount for partition: volumio May 08 15:06:24 volumio volumio[16022]: info: Ignoring mount for partition: volumio_data May 08 15:06:24 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 08 15:06:24 volumio volumio[16022]: info: Loading plugin "alarm-clock"... May 08 15:06:24 volumio volumio[16022]: info: Loading plugin "airplay_emulation"... May 08 15:06:24 volumio volumio[16022]: info: Starting Shairport Sync May 08 15:06:24 volumio volumio[16022]: info: Loading plugin "last_100"... May 08 15:06:24 volumio volumio[16022]: info: Loading plugin "webradio"... May 08 15:06:25 volumio volumio[16022]: info: Loading plugin "i2s_dacs"... May 08 15:06:25 volumio volumio[16022]: info: I2S DAC not set, start Auto-detection May 08 15:06:25 volumio volumio[16022]: info: Loading plugin "volumiodiscovery"... May 08 15:06:25 volumio volumio[16022]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 08 15:06:25 volumio volumio[16022]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 15:06:25 volumio volumio[16022]: *** WARNING *** For more information see May 08 15:06:25 volumio volumio[16022]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 08 15:06:25 volumio volumio[16022]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 15:06:25 volumio volumio[16022]: *** WARNING *** For more information see May 08 15:06:25 volumio node[16022]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 08 15:06:25 volumio node[16022]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 15:06:25 volumio node[16022]: *** WARNING *** For more information see May 08 15:06:25 volumio node[16022]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 08 15:06:25 volumio node[16022]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 15:06:25 volumio node[16022]: *** WARNING *** For more information see May 08 15:06:25 volumio volumio[16022]: info: Applying required configuration parameters for plugin volumiodiscovery May 08 15:06:25 volumio volumio[16022]: info: Discovery: Started advertising with name: Volumio May 08 15:06:25 volumio mpd[16068]: May 08 15:06 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 08 15:06:25 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 08 15:06:25 volumio volumio[16022]: info: Loading plugin "spop"... May 08 15:06:25 volumio mpd[16068]: May 08 15:06 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured May 08 15:06:25 volumio mpd[16068]: May 08 15:06 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured May 08 15:06:25 volumio systemd[1]: Started Music Player Daemon. May 08 15:06:25 volumio sudo[16062]: pam_unix(sudo:session): session closed for user root May 08 15:06:25 volumio go-librespot[19072]: time="2024-05-08T15:06:25+08:00" level=warning msg="failed fetching new endpoint for dealer" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=dealer\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 08 15:06:25 volumio wpa_supplicant[670]: wlan0: Trying to associate with SSID 'HomeNetwork' May 08 15:06:26 volumio volumio[16022]: info: Loading plugin "squeezelite_mc"... May 08 15:06:27 volumio volumio[16022]: info: Loading plugin "ytcr"... May 08 15:06:28 volumio go-librespot[19072]: time="2024-05-08T15:06:28+08:00" level=warning msg="failed fetching new endpoint for dealer" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=dealer\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 08 15:06:28 volumio wpa_supplicant[670]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16 May 08 15:06:29 volumio volumio[16022]: info: Loading plugin "outputs"... May 08 15:06:29 volumio volumio[16022]: info: Loading plugin "albumart"... May 08 15:06:29 volumio volumio[16022]: info: Plugin example_plugin is not enabled May 08 15:06:29 volumio volumio[16022]: info: Loading plugin "inputs"... May 08 15:06:29 volumio volumio[16022]: info: Loading plugin "updater_comm"... May 08 15:06:29 volumio volumio[16022]: info: Plugin mpdemulation is not enabled May 08 15:06:29 volumio volumio[16022]: info: Loading plugin "rest_api"... May 08 15:06:29 volumio volumio[16022]: info: Loading plugin "websocket"... May 08 15:06:29 volumio volumio[16022]: info: Loading i18n strings for locale zh_TW May 08 15:06:29 volumio volumio[16022]: Updating browse sources language May 08 15:06:29 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 15:06:29 volumio volumio[16022]: Forking 3 albumart workers May 08 15:06:29 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 15:06:29 volumio volumio[16022]: info: CoreCommandRouter::initPlayerControls May 08 15:06:29 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:29 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:29 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:29 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:29 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:29 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:29 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:29 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:29 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 15:06:29 volumio volumio[16022]: Express server listening on port 3000 May 08 15:06:29 volumio volumio[16022]: [Metrics] WebUI: 9s 596.52ms May 08 15:06:29 volumio volumio[16022]: info: CoreStateMachine::resetVolumioState May 08 15:06:29 volumio volumio[16022]: info: CoreStateMachine::getcurrentVolume May 08 15:06:29 volumio volumio[16022]: info: CoreCommandRouter::volumioRetrievevolume May 08 15:06:29 volumio volumio[16022]: info: CoreStateMachine::pushState May 08 15:06:29 volumio volumio[16022]: info: CorePlayQueue::getTrack 0 May 08 15:06:29 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 15:06:29 volumio volumio[16022]: info: CoreCommandRouter::volumioPushState May 08 15:06:29 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:29 volumio volumio[16022]: info: Cannot mount NAS pishare at system boot, trial number 2 ,retrying in 5 seconds May 08 15:06:29 volumio volumio[16022]: info: Cannot mount NAS rpi at system boot, trial number 2 ,retrying in 5 seconds May 08 15:06:29 volumio volumio[16022]: info: Cannot mount NAS music at system boot, trial number 2 ,retrying in 5 seconds May 08 15:06:29 volumio volumio[16022]: info: MPD Permissions set May 08 15:06:29 volumio volumio[16022]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan May 08 15:06:29 volumio volumio[16022]: wlan0 Interface doesn't support scanning : Device or resource busy May 08 15:06:29 volumio volumio[16022]: info: Cannot use regular scanning, forcing with ap-force May 08 15:06:30 volumio sudo[16109]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force May 08 15:06:30 volumio sudo[16109]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:30 volumio sudo[16109]: pam_unix(sudo:session): session closed for user root May 08 15:06:30 volumio volumio[16022]: command failed: Device or resource busy (-16) May 08 15:06:30 volumio volumio[16022]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force May 08 15:06:30 volumio volumio[16022]: command failed: Device or resource busy (-16) May 08 15:06:30 volumio volumio[16022]: info: MPD running with PID16068 May 08 15:06:30 volumio volumio[16022]: ,establishing connection May 08 15:06:30 volumio volumio[16022]: error: MPD error: The expression evaluated to a falsy value: May 08 15:06:30 volumio volumio[16022]: assert.ok(self.idling) May 08 15:06:30 volumio volumio[16022]: error: The expression evaluated to a falsy value: May 08 15:06:30 volumio volumio[16022]: assert.ok(self.idling) May 08 15:06:30 volumio volumio[16022]: info: Reloading queue from file May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:30 volumio volumio[16022]: info: Setting Device type: Raspberry PI May 08 15:06:30 volumio volumio[16022]: info: CoreStateMachine::setRepeat null single undefined May 08 15:06:30 volumio volumio[16022]: info: CoreStateMachine::pushState May 08 15:06:30 volumio volumio[16022]: info: CorePlayQueue::getTrack 0 May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::volumioPushState May 08 15:06:30 volumio volumio[16022]: info: CoreStateMachine::setRandom null May 08 15:06:30 volumio volumio[16022]: info: CoreStateMachine::pushState May 08 15:06:30 volumio volumio[16022]: info: CorePlayQueue::getTrack 0 May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::volumioPushState May 08 15:06:30 volumio volumio[16022]: error: updateQueue error: null May 08 15:06:30 volumio volumio[16022]: info: Completed loading Core Plugins May 08 15:06:30 volumio volumio[16022]: info: Preparing to generate the ALSA configuration file May 08 15:06:30 volumio volumio[16022]: info: Asound.conf file unchanged, so no further update is needed May 08 15:06:30 volumio volumio[16022]: info: Output device has changed, restarting MPD May 08 15:06:30 volumio volumio[16022]: info: Output device has changed, restarting Shairport Sync May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:30 volumio sudo[16121]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 08 15:06:30 volumio sudo[16121]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:30 volumio sudo[16121]: pam_unix(sudo:session): session closed for user root May 08 15:06:30 volumio sudo[16122]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 08 15:06:30 volumio sudo[16122]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:30 volumio systemd[1]: Stopping Music Player Daemon... May 08 15:06:30 volumio systemd[1]: mpd.service: Succeeded. May 08 15:06:30 volumio systemd[1]: Stopped Music Player Daemon. May 08 15:06:30 volumio volumio[16022]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 08 15:06:30 volumio volumio[16022]: info: ___________ START PLUGINS ___________ May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 08 15:06:30 volumio volumio[16022]: info: [1715151990677] CoreMusicLibrary::Adding element Media Servers May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:30 volumio systemd[1]: Starting Music Player Daemon... May 08 15:06:30 volumio volumio[16022]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:30 volumio volumio[16022]: Starting albumart workers May 08 15:06:30 volumio volumio[16022]: Starting albumart workers May 08 15:06:30 volumio volumio[16022]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 08 15:06:30 volumio volumio[16022]: info: [1715151990861] CoreMusicLibrary::Adding element Last_100 May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 08 15:06:30 volumio volumio[16022]: Starting albumart workers May 08 15:06:30 volumio volumio[16022]: info: [1715151990866] CoreMusicLibrary::Adding element Webradio May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 15:06:30 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 08 15:06:30 volumio volumio[16022]: info: Creating Spotify config file May 08 15:06:31 volumio volumio[16022]: info: Starting Volume Timer Limit Guard May 08 15:06:31 volumio volumio[16022]: info: Loading Spotify Daemon to Volumio volume map May 08 15:06:31 volumio volumio[16022]: info: [squeezelite_mc] Starting proxy server... May 08 15:06:31 volumio volumio[16022]: info: Volumio Calling Home May 08 15:06:31 volumio volumio[16022]: info: [squeezelite_mc] Proxy server started on port 42221 May 08 15:06:31 volumio volumio[16022]: info: CoreCommandRouter::volumioRetrievevolume May 08 15:06:31 volumio volumio[16022]: info: CoreStateMachine::pushState May 08 15:06:31 volumio volumio[16022]: info: CorePlayQueue::getTrack 0 May 08 15:06:31 volumio volumio[16022]: info: CoreCommandRouter::volumioPushState May 08 15:06:31 volumio volumio[16022]: info: [squeezelite_mc] Server discovery started May 08 15:06:31 volumio volumio[16022]: info: [squeezelite_mc] Player finder started May 08 15:06:31 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:31 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:31 volumio volumio[16022]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 15:06:31 volumio volumio[16022]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true May 08 15:06:31 volumio volumio[16022]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 08 15:06:31 volumio volumio[16022]: Error: send ENETUNREACH 255.255.255.255:3483 May 08 15:06:31 volumio volumio[16022]: at doSend (dgram.js:692:16) May 08 15:06:31 volumio volumio[16022]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) May 08 15:06:31 volumio volumio[16022]: at afterDns (dgram.js:638:5) May 08 15:06:31 volumio volumio[16022]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { May 08 15:06:31 volumio volumio[16022]: errno: -101, May 08 15:06:31 volumio volumio[16022]: code: 'ENETUNREACH', May 08 15:06:31 volumio volumio[16022]: syscall: 'send', May 08 15:06:31 volumio volumio[16022]: address: '255.255.255.255', May 08 15:06:31 volumio volumio[16022]: port: 3483 May 08 15:06:31 volumio volumio[16022]: } May 08 15:06:31 volumio volumio[16022]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 08 15:06:32 volumio sudo[16177]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-08 15:05 May 08 15:06:32 volumio sudo[16177]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:32 volumio wpa_supplicant[670]: wlan0: Trying to associate with SSID 'HomeNetwork' May 08 15:06:32 volumio sudo[16177]: pam_unix(sudo:session): session closed for user root May 08 15:06:32 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE May 08 15:06:32 volumio sudo[16122]: pam_unix(sudo:session): session closed for user root May 08 15:06:32 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. May 08 15:06:32 volumio mpd[16138]: May 08 15:06 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 08 15:06:32 volumio systemd[1]: Started dynamicswap service. May 08 15:06:32 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. May 08 15:06:32 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 32. May 08 15:06:32 volumio systemd[1]: dynamicswap.service: Succeeded. May 08 15:06:32 volumio systemd[1]: Stopped Volumio Backend Module. May 08 15:06:32 volumio systemd[1]: Started Volumio Backend Module. May 08 15:06:32 volumio mpd[16138]: May 08 15:06 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured May 08 15:06:32 volumio mpd[16138]: May 08 15:06 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured May 08 15:06:32 volumio systemd[1]: Started Music Player Daemon. May 08 15:06:33 volumio go-librespot[19072]: time="2024-05-08T15:06:33+08:00" level=warning msg="failed fetching new endpoint for dealer" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=dealer\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 08 15:06:34 volumio volumio[16192]: info: ------------------------------------------- May 08 15:06:34 volumio volumio[16192]: info: ----- Volumio3 ---- May 08 15:06:34 volumio volumio[16192]: info: ------------------------------------------- May 08 15:06:34 volumio volumio[16192]: info: ----- System startup ---- May 08 15:06:34 volumio volumio[16192]: info: ------------------------------------------- May 08 15:06:35 volumio wpa_supplicant[670]: wlan0: Associated with 58:11:22:59:89:14 May 08 15:06:35 volumio wpa_supplicant[670]: wlan0: CTRL-EVENT-CONNECTED - Connection to 58:11:22:59:89:14 completed [id=0 id_str=] May 08 15:06:35 volumio dhcpcd[684]: wlan0: carrier acquired May 08 15:06:35 volumio wpa_supplicant[670]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 May 08 15:06:35 volumio wpa_supplicant[670]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US May 08 15:06:35 volumio dhcpcd[684]: wlan0: IAID eb:5a:57:b5 May 08 15:06:35 volumio volumio[16192]: info: MYVOLUMIO Environment detected May 08 15:06:35 volumio volumio[16192]: info: Plugin folders cleanup May 08 15:06:35 volumio volumio[16192]: info: Scanning into folder /volumio/app/plugins/ May 08 15:06:35 volumio volumio[16192]: info: Scanning category audio_interface May 08 15:06:35 volumio volumio[16192]: info: Scanning category miscellanea May 08 15:06:35 volumio volumio[16192]: info: Scanning category music_service May 08 15:06:35 volumio volumio[16192]: info: Scanning category plugins.json May 08 15:06:35 volumio volumio[16192]: info: Scanning category system_controller May 08 15:06:35 volumio volumio[16192]: info: Scanning category user_interface May 08 15:06:35 volumio volumio[16192]: info: Scanning into folder /data/plugins/ May 08 15:06:35 volumio volumio[16192]: info: Scanning category music_service May 08 15:06:35 volumio volumio[16192]: info: Plugin folders cleanup completed May 08 15:06:35 volumio volumio[16192]: info: ------------------------------------------- May 08 15:06:35 volumio volumio[16192]: info: ----- Core plugins startup ---- May 08 15:06:35 volumio volumio[16192]: info: ------------------------------------------- May 08 15:06:35 volumio volumio[16192]: info: Loading plugins from folder /volumio/app/plugins/ May 08 15:06:35 volumio volumio[16192]: info: Adding plugin upnp to MyMusic Plugins May 08 15:06:35 volumio volumio[16192]: info: Adding plugin airplay_emulation to MyMusic Plugins May 08 15:06:35 volumio volumio[16192]: info: Adding plugin upnp_browser to MyMusic Plugins May 08 15:06:35 volumio volumio[16192]: info: Loading plugins from folder /data/plugins/ May 08 15:06:35 volumio volumio[16192]: info: Loading plugin "system"... May 08 15:06:35 volumio volumio[16192]: info: Loading plugin "appearance"... May 08 15:06:35 volumio dhcpcd[684]: wlan0: rebinding lease of 192.168.10.89 May 08 15:06:36 volumio volumio-remote-updater[461]: [2024-05-08 15:06:36] [connect] Successful connection May 08 15:06:36 volumio dhcpcd[684]: wlan0: soliciting an IPv6 router May 08 15:06:36 volumio volumio[16192]: info: Loading plugin "network"... May 08 15:06:36 volumio volumio[16192]: info: Refreshing Cached IP Addresses May 08 15:06:36 volumio sudo[16213]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 08 15:06:36 volumio sudo[16213]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:36 volumio sudo[16215]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 08 15:06:36 volumio sudo[16215]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:36 volumio volumio[16192]: info: Loading plugin "services"... May 08 15:06:36 volumio sudo[16215]: pam_unix(sudo:session): session closed for user root May 08 15:06:36 volumio volumio[16192]: info: Loading plugin "alsa_controller"... May 08 15:06:36 volumio sudo[16218]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 08 15:06:36 volumio sudo[16218]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:36 volumio sudo[16213]: pam_unix(sudo:session): session closed for user root May 08 15:06:36 volumio volumio[16192]: warn: Unable to locate the audio output device FiiO K5 Pro. Please configure a valid output device. May 08 15:06:36 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 08 15:06:36 volumio volumio[16192]: info: Loading plugin "wizard"... May 08 15:06:36 volumio volumio[16192]: info: Loading plugin "volumio_command_line_client"... May 08 15:06:36 volumio volumio[16192]: info: Loading plugin "upnp"... May 08 15:06:36 volumio volumio[16192]: info: [1715151996937] Starting Upmpd Daemon May 08 15:06:36 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 08 15:06:36 volumio volumio[16192]: info: Loading plugin "my_music"... May 08 15:06:36 volumio volumio[16192]: info: Loading plugin "mpd"... May 08 15:06:37 volumio volumio[16192]: info: Creating MPD Configuration file May 08 15:06:37 volumio volumio[16192]: info: Loading plugin "upnp_browser"... May 08 15:06:37 volumio sudo[16226]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 08 15:06:37 volumio sudo[16226]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:37 volumio sudo[16226]: pam_unix(sudo:session): session closed for user root May 08 15:06:37 volumio sudo[16228]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 08 15:06:37 volumio sudo[16228]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:37 volumio systemd[1]: Stopping Music Player Daemon... May 08 15:06:37 volumio systemd[1]: mpd.service: Succeeded. May 08 15:06:37 volumio systemd[1]: Stopped Music Player Daemon. May 08 15:06:37 volumio systemd[1]: Starting Music Player Daemon... May 08 15:06:37 volumio volumio[16192]: info: Loading plugin "networkfs"... May 08 15:06:38 volumio volumio[16192]: info: Cannot mount NAS pishare at system boot, trial number 1 ,retrying in 5 seconds May 08 15:06:38 volumio volumio[16192]: info: Cannot mount NAS rpi at system boot, trial number 1 ,retrying in 5 seconds May 08 15:06:38 volumio volumio[16192]: info: Cannot mount NAS music at system boot, trial number 1 ,retrying in 5 seconds May 08 15:06:38 volumio volumio[16192]: info: Starting Udev Watcher for removable devices May 08 15:06:38 volumio volumio[16192]: info: Ignoring mount for partition: boot May 08 15:06:38 volumio volumio[16192]: info: Ignoring mount for partition: volumio May 08 15:06:38 volumio volumio[16192]: info: Ignoring mount for partition: volumio_data May 08 15:06:38 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 08 15:06:38 volumio volumio[16192]: info: Loading plugin "alarm-clock"... May 08 15:06:38 volumio volumio[16192]: info: Loading plugin "airplay_emulation"... May 08 15:06:38 volumio volumio[16192]: info: Starting Shairport Sync May 08 15:06:38 volumio volumio[16192]: info: Loading plugin "last_100"... May 08 15:06:38 volumio volumio[16192]: info: Loading plugin "webradio"... May 08 15:06:38 volumio volumio[16192]: info: Loading plugin "i2s_dacs"... May 08 15:06:38 volumio volumio[16192]: info: I2S DAC not set, start Auto-detection May 08 15:06:38 volumio volumio[16192]: info: Loading plugin "volumiodiscovery"... May 08 15:06:38 volumio mpd[16233]: May 08 15:06 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 08 15:06:38 volumio volumio[16192]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 08 15:06:38 volumio volumio[16192]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 15:06:38 volumio volumio[16192]: *** WARNING *** For more information see May 08 15:06:38 volumio volumio[16192]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 08 15:06:38 volumio volumio[16192]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 15:06:38 volumio volumio[16192]: *** WARNING *** For more information see May 08 15:06:38 volumio node[16192]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 08 15:06:38 volumio node[16192]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 15:06:38 volumio node[16192]: *** WARNING *** For more information see May 08 15:06:38 volumio node[16192]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 08 15:06:38 volumio node[16192]: *** WARNING *** Please fix your application to use the native API of Avahi! May 08 15:06:38 volumio node[16192]: *** WARNING *** For more information see May 08 15:06:38 volumio volumio[16192]: info: Applying required configuration parameters for plugin volumiodiscovery May 08 15:06:38 volumio volumio[16192]: info: Discovery: Started advertising with name: Volumio May 08 15:06:38 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 08 15:06:38 volumio volumio[16192]: info: Loading plugin "spop"... May 08 15:06:39 volumio go-librespot[19072]: time="2024-05-08T15:06:39+08:00" level=warning msg="failed fetching new endpoint for dealer" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=dealer\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 08 15:06:39 volumio mpd[16233]: May 08 15:06 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured May 08 15:06:39 volumio mpd[16233]: May 08 15:06 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured May 08 15:06:39 volumio systemd[1]: Started Music Player Daemon. May 08 15:06:39 volumio sudo[16228]: pam_unix(sudo:session): session closed for user root May 08 15:06:40 volumio volumio[16192]: info: Loading plugin "squeezelite_mc"... May 08 15:06:40 volumio dhcpcd[684]: wlan0: probing address 192.168.10.89/24 May 08 15:06:40 volumio sudo[16218]: pam_unix(sudo:session): session closed for user root May 08 15:06:41 volumio volumio[16192]: info: Loading plugin "ytcr"... May 08 15:06:43 volumio volumio[16192]: info: Loading plugin "outputs"... May 08 15:06:43 volumio volumio[16192]: info: Loading plugin "albumart"... May 08 15:06:43 volumio volumio[16192]: info: Plugin example_plugin is not enabled May 08 15:06:43 volumio volumio[16192]: info: Loading plugin "inputs"... May 08 15:06:43 volumio volumio[16192]: info: Loading plugin "updater_comm"... May 08 15:06:43 volumio volumio[16192]: info: Plugin mpdemulation is not enabled May 08 15:06:43 volumio volumio[16192]: info: Loading plugin "rest_api"... May 08 15:06:43 volumio volumio[16192]: info: Loading plugin "websocket"... May 08 15:06:43 volumio volumio[16192]: info: Loading i18n strings for locale zh_TW May 08 15:06:43 volumio volumio[16192]: Updating browse sources language May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 15:06:43 volumio volumio[16192]: Forking 3 albumart workers May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::initPlayerControls May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 15:06:43 volumio volumio[16192]: Express server listening on port 3000 May 08 15:06:43 volumio volumio[16192]: [Metrics] WebUI: 9s 622.63ms May 08 15:06:43 volumio volumio[16192]: info: CoreStateMachine::resetVolumioState May 08 15:06:43 volumio volumio[16192]: info: CoreStateMachine::getcurrentVolume May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::volumioRetrievevolume May 08 15:06:43 volumio volumio[16192]: info: CoreStateMachine::pushState May 08 15:06:43 volumio volumio[16192]: info: CorePlayQueue::getTrack 0 May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::volumioPushState May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:43 volumio volumio[16192]: info: Cannot mount NAS pishare at system boot, trial number 2 ,retrying in 5 seconds May 08 15:06:43 volumio volumio[16192]: info: Cannot mount NAS rpi at system boot, trial number 2 ,retrying in 5 seconds May 08 15:06:43 volumio volumio[16192]: info: Cannot mount NAS music at system boot, trial number 2 ,retrying in 5 seconds May 08 15:06:43 volumio volumio[16192]: info: MPD Permissions set May 08 15:06:43 volumio volumio[16192]: info: MPD running with PID16233 May 08 15:06:43 volumio volumio[16192]: ,establishing connection May 08 15:06:43 volumio volumio[16192]: info: Reloading queue from file May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:43 volumio go-librespot[19072]: time="2024-05-08T15:06:43+08:00" level=warning msg="failed fetching new endpoint for dealer" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=dealer\": dial tcp: lookup apresolve.spotify.com: device or resource busy" May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:43 volumio volumio[16192]: error: updateQueue error: null May 08 15:06:43 volumio volumio[16192]: info: Setting Device type: Raspberry PI May 08 15:06:43 volumio volumio[16192]: info: CoreStateMachine::setRepeat null single undefined May 08 15:06:43 volumio volumio[16192]: info: CoreStateMachine::pushState May 08 15:06:43 volumio volumio[16192]: info: CorePlayQueue::getTrack 0 May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::volumioPushState May 08 15:06:43 volumio volumio[16192]: info: CoreStateMachine::setRandom null May 08 15:06:43 volumio volumio[16192]: info: CoreStateMachine::pushState May 08 15:06:43 volumio volumio[16192]: info: CorePlayQueue::getTrack 0 May 08 15:06:43 volumio volumio[16192]: info: CoreCommandRouter::volumioPushState May 08 15:06:43 volumio volumio[16192]: error: updateQueue error: null May 08 15:06:43 volumio volumio[16192]: info: Completed loading Core Plugins May 08 15:06:44 volumio volumio[16192]: info: Preparing to generate the ALSA configuration file May 08 15:06:44 volumio volumio[16192]: info: Asound.conf file unchanged, so no further update is needed May 08 15:06:44 volumio volumio[16192]: info: Output device has changed, restarting MPD May 08 15:06:44 volumio volumio[16192]: info: Output device has changed, restarting Shairport Sync May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:44 volumio sudo[16283]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 08 15:06:44 volumio sudo[16283]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:44 volumio sudo[16281]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 08 15:06:44 volumio sudo[16281]: pam_unix(sudo:session): session opened for user root by (uid=0) May 08 15:06:44 volumio sudo[16281]: pam_unix(sudo:session): session closed for user root May 08 15:06:44 volumio systemd[1]: Stopping Music Player Daemon... May 08 15:06:44 volumio volumio[16192]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 08 15:06:44 volumio volumio[16192]: info: ___________ START PLUGINS ___________ May 08 15:06:44 volumio systemd[1]: mpd.service: Succeeded. May 08 15:06:44 volumio systemd[1]: Stopped Music Player Daemon. May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 08 15:06:44 volumio volumio[16192]: info: [1715152004268] CoreMusicLibrary::Adding element Media Servers May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:44 volumio systemd[1]: Starting Music Player Daemon... May 08 15:06:44 volumio volumio[16192]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 08 15:06:44 volumio volumio[16192]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 08 15:06:44 volumio volumio[16192]: info: [1715152004428] CoreMusicLibrary::Adding element Last_100 May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 08 15:06:44 volumio volumio[16192]: info: [1715152004433] CoreMusicLibrary::Adding element Webradio May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 08 15:06:44 volumio volumio[16192]: info: Creating Spotify config file May 08 15:06:44 volumio volumio[16192]: info: Starting Volume Timer Limit Guard May 08 15:06:44 volumio volumio[16192]: info: Loading Spotify Daemon to Volumio volume map May 08 15:06:44 volumio volumio[16192]: info: [squeezelite_mc] Starting proxy server... May 08 15:06:44 volumio volumio[16192]: info: Volumio Calling Home May 08 15:06:44 volumio volumio[16192]: info: [squeezelite_mc] Proxy server started on port 41515 May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::volumioRetrievevolume May 08 15:06:44 volumio volumio[16192]: info: CoreStateMachine::pushState May 08 15:06:44 volumio volumio[16192]: info: CorePlayQueue::getTrack 0 May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::volumioPushState May 08 15:06:44 volumio volumio[16192]: Starting albumart workers May 08 15:06:44 volumio volumio[16192]: info: [squeezelite_mc] Server discovery started May 08 15:06:44 volumio volumio[16192]: info: [squeezelite_mc] Player finder started May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 08 15:06:44 volumio volumio[16192]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 08 15:06:44 volumio volumio[16192]: info: [squeezelite_mc] Executing aplay -D hw:5 --nonblock -f MPEG /dev/zero 2>&1 || true May 08 15:06:44 volumio volumio[16192]: Starting albumart workers May 08 15:06:44 volumio volumio[16192]: Starting albumart workers May 08 15:06:44 volumio volumio[16192]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 08 15:06:44 volumio volumio[16192]: Error: send ENETUNREACH 255.255.255.255:3483 May 08 15:06:44 volumio volumio[16192]: at doSend (dgram.js:692:16) May 08 15:06:44 volumio volumio[16192]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12) May 08 15:06:44 volumio volumio[16192]: at afterDns (dgram.js:638:5) May 08 15:06:44 volumio volumio[16192]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { May 08 15:06:44 volumio volumio[16192]: errno: -101, May 08 15:06:44 volumio volumio[16192]: code: 'ENETUNREACH', May 08 15:06:44 volumio volumio[16192]: syscall: 'send', May 08 15:06:44 volumio volumio[16192]: address: '255.255.255.255', May 08 15:06:44 volumio volumio[16192]: port: 3483 May 08 15:06:44 volumio volumio[16192]: } May 08 15:06:44 volumio volumio[16192]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 08 15:06:45 volumio nmbd[554]: [2024/05/08 15:06:45.028784, 0] ../source3/nmbd/nmbd.c:361(reload_interfaces) May 08 15:06:45 volumio nmbd[554]: reload_interfaces: No subnets to listen to. Waiting.. May 08 15:06:45 volumio dhcpcd[684]: wlan0: leased 192.168.10.89 for 86400 seconds May 08 15:06:45 volumio avahi-daemon[460]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.10.89. May 08 15:06:45 volumio dhcpcd[684]: wlan0: adding route to 192.168.10.0/24 May 08 15:06:45 volumio dhcpcd[684]: wlan0: adding default route via 192.168.10.1 May 08 15:06:45 volumio avahi-daemon[460]: New relevant interface wlan0.IPv4 for mDNS. May 08 15:06:45 volumio avahi-daemon[460]: Registering new address record for 192.168.10.89 on wlan0.IPv4. May 08 15:06:45 volumio go-librespot[19072]: time="2024-05-08T15:06:45+08:00" level=error msg="did not receive last pong from dealer, 90s passed" May 08 15:06:45 volumio go-librespot[19072]: panic: runtime error: invalid memory address or nil pointer dereference May 08 15:06:45 volumio go-librespot[19072]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x43a77c] May 08 15:06:45 volumio go-librespot[19072]: goroutine 12 [running]: May 08 15:06:45 volumio go-librespot[19072]: panic({0x59ce08, 0x9e1a20}) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/panic.go:987 +0x414 fp=0x25f5e50 sp=0x25f5df4 pc=0x4ee28 May 08 15:06:45 volumio go-librespot[19072]: runtime.panicmem() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/panic.go:260 +0x4c fp=0x25f5e5c sp=0x25f5e50 pc=0x4d5cc May 08 15:06:45 volumio go-librespot[19072]: runtime.sigpanic() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/signal_unix.go:841 +0x26c fp=0x25f5e78 sp=0x25f5e5c pc=0x68750 May 08 15:06:45 volumio go-librespot[19072]: nhooyr.io/websocket.(*Conn).writeClose(0x0, 0x3f4, {0x0, 0x0}) May 08 15:06:45 volumio go-librespot[19072]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/close_notjs.go:54 +0x14 fp=0x25f5ee4 sp=0x25f5e7c pc=0x43a77c May 08 15:06:45 volumio go-librespot[19072]: nhooyr.io/websocket.(*Conn).closeHandshake(0x0, 0x3f4, {0x0, 0x0}) May 08 15:06:45 volumio go-librespot[19072]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/close_notjs.go:37 +0x80 fp=0x25f5f24 sp=0x25f5ee4 pc=0x43a5a0 May 08 15:06:45 volumio go-librespot[19072]: nhooyr.io/websocket.(*Conn).Close(...) May 08 15:06:45 volumio go-librespot[19072]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/close_notjs.go:31 May 08 15:06:45 volumio go-librespot[19072]: go-librespot/dealer.(*Dealer).pingTicker(0x2518e10) May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:114 +0x26c fp=0x25f5fe4 sp=0x25f5f24 pc=0x51b994 May 08 15:06:45 volumio go-librespot[19072]: go-librespot/dealer.NewDealer.func1() May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:57 +0x28 fp=0x25f5fec sp=0x25f5fe4 pc=0x51b150 May 08 15:06:45 volumio go-librespot[19072]: runtime.goexit() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x25f5fec sp=0x25f5fec pc=0x84730 May 08 15:06:45 volumio go-librespot[19072]: created by go-librespot/dealer.NewDealer May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:57 +0x174 May 08 15:06:45 volumio go-librespot[19072]: goroutine 1 [select, 3 minutes]: May 08 15:06:45 volumio go-librespot[19072]: runtime.gopark(0x63b1d0, 0x0, 0x9, 0x18, 0x1) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x252f800 sp=0x252f7ec pc=0x527b0 May 08 15:06:45 volumio go-librespot[19072]: runtime.selectgo(0x252fa80, 0x252f9c8, 0x0, 0x0, 0x6, 0x1) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x252f8a8 sp=0x252f800 pc=0x64d80 May 08 15:06:45 volumio go-librespot[19072]: main.(*Session).Run(0x2522680, 0x26ea000) May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/session.go:449 +0x1d0 fp=0x252fec0 sp=0x252f8a8 pc=0x535098 May 08 15:06:45 volumio go-librespot[19072]: main.(*App).withReusableCredentials(0x2524390, {0x5a6b28, 0x252ffa0}) May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:217 +0x654 fp=0x252ff64 sp=0x252fec0 pc=0x530880 May 08 15:06:45 volumio go-librespot[19072]: main.(*App).SpotifyToken(...) May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:158 May 08 15:06:45 volumio go-librespot[19072]: main.main() May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:323 +0x460 fp=0x252ffc0 sp=0x252ff64 pc=0x5311a4 May 08 15:06:45 volumio go-librespot[19072]: runtime.main() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:250 +0x268 fp=0x252ffec sp=0x252ffc0 pc=0x52288 May 08 15:06:45 volumio go-librespot[19072]: runtime.goexit() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x252ffec sp=0x252ffec pc=0x84730 May 08 15:06:45 volumio go-librespot[19072]: goroutine 2 [force gc (idle), 3 minutes]: May 08 15:06:45 volumio go-librespot[19072]: runtime.gopark(0x63b1a0, 0xa280c8, 0x11, 0x14, 0x1) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x243cfd8 sp=0x243cfc4 pc=0x527b0 May 08 15:06:45 volumio go-librespot[19072]: runtime.goparkunlock(...) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:387 May 08 15:06:45 volumio go-librespot[19072]: runtime.forcegchelper() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:305 +0xd4 fp=0x243cfec sp=0x243cfd8 pc=0x525d0 May 08 15:06:45 volumio go-librespot[19072]: runtime.goexit() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x243cfec sp=0x243cfec pc=0x84730 May 08 15:06:45 volumio go-librespot[19072]: created by runtime.init.5 May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:293 +0x1c May 08 15:06:45 volumio go-librespot[19072]: goroutine 18 [GC sweep wait]: May 08 15:06:45 volumio go-librespot[19072]: runtime.gopark(0x63b1a0, 0xa286c8, 0xc, 0x14, 0x1) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x24387c8 sp=0x24387b4 pc=0x527b0 May 08 15:06:45 volumio go-librespot[19072]: runtime.goparkunlock(...) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:387 May 08 15:06:45 volumio go-librespot[19072]: runtime.bgsweep(0x2462000) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgcsweep.go:319 +0x104 fp=0x24387e4 sp=0x24387c8 pc=0x3c528 May 08 15:06:45 volumio go-librespot[19072]: runtime.gcenable.func1() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:178 +0x28 fp=0x24387ec sp=0x24387e4 pc=0x2cff4 May 08 15:06:45 volumio go-librespot[19072]: runtime.goexit() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x24387ec sp=0x24387ec pc=0x84730 May 08 15:06:45 volumio go-librespot[19072]: created by runtime.gcenable May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:178 +0x74 May 08 15:06:45 volumio go-librespot[19072]: goroutine 19 [GC scavenge wait]: May 08 15:06:45 volumio go-librespot[19072]: runtime.gopark(0x63b1a0, 0xa289a8, 0xd, 0x14, 0x2) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2438fb4 sp=0x2438fa0 pc=0x527b0 May 08 15:06:45 volumio go-librespot[19072]: runtime.goparkunlock(...) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:387 May 08 15:06:45 volumio go-librespot[19072]: runtime.(*scavengerState).park(0xa289a8) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgcscavenge.go:400 +0x64 fp=0x2438fc8 sp=0x2438fb4 pc=0x39e1c May 08 15:06:45 volumio go-librespot[19072]: runtime.bgscavenge(0x2462000) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgcscavenge.go:633 +0x64 fp=0x2438fe4 sp=0x2438fc8 pc=0x3a560 May 08 15:06:45 volumio go-librespot[19072]: runtime.gcenable.func2() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:179 +0x28 fp=0x2438fec sp=0x2438fe4 pc=0x2cfa0 May 08 15:06:45 volumio go-librespot[19072]: runtime.goexit() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2438fec sp=0x2438fec pc=0x84730 May 08 15:06:45 volumio go-librespot[19072]: created by runtime.gcenable May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:179 +0xbc May 08 15:06:45 volumio go-librespot[19072]: goroutine 34 [finalizer wait, 9 minutes]: May 08 15:06:45 volumio go-librespot[19072]: runtime.gopark(0x63b0e0, 0xa39a6c, 0x10, 0x14, 0x1) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x243c78c sp=0x243c778 pc=0x527b0 May 08 15:06:45 volumio go-librespot[19072]: runtime.runfinq() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mfinal.go:193 +0xfc fp=0x243c7ec sp=0x243c78c pc=0x2bed0 May 08 15:06:45 volumio go-librespot[19072]: runtime.goexit() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x243c7ec sp=0x243c7ec pc=0x84730 May 08 15:06:45 volumio go-librespot[19072]: created by runtime.createfing May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mfinal.go:163 +0x5c May 08 15:06:45 volumio go-librespot[19072]: goroutine 423 [select]: May 08 15:06:45 volumio go-librespot[19072]: runtime.gopark(0x63b1d0, 0x0, 0x9, 0x18, 0x1) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x260edd0 sp=0x260edbc pc=0x527b0 May 08 15:06:45 volumio go-librespot[19072]: runtime.selectgo(0x260eed0, 0x260eeb0, 0x0, 0x0, 0x2, 0x1) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x260ee78 sp=0x260edd0 pc=0x64d80 May 08 15:06:45 volumio go-librespot[19072]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0x260ef1c, {0x6c3838, 0x28ae060}, 0x0, {0x0, 0x0}) May 08 15:06:45 volumio go-librespot[19072]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:112 +0x268 fp=0x260eef4 sp=0x260ee78 pc=0x4553e0 May 08 15:06:45 volumio go-librespot[19072]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer(0x260ef78, {0x6c3838, 0x28ae060}, 0x0, {0x0, 0x0}) May 08 15:06:45 volumio go-librespot[19072]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:61 +0x6c fp=0x260ef24 sp=0x260eef4 pc=0x454e78 May 08 15:06:45 volumio go-librespot[19072]: github.com/cenkalti/backoff/v4.RetryNotify(...) May 08 15:06:45 volumio go-librespot[19072]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:49 May 08 15:06:45 volumio go-librespot[19072]: github.com/cenkalti/backoff/v4.Retry(...) May 08 15:06:45 volumio go-librespot[19072]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:38 May 08 15:06:45 volumio go-librespot[19072]: go-librespot/dealer.(*Dealer).recvLoop(0x2518e10) May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:191 +0x564 fp=0x260efe4 sp=0x260ef24 pc=0x51c118 May 08 15:06:45 volumio go-librespot[19072]: go-librespot/dealer.(*Dealer).reconnect.func1() May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:241 +0x28 fp=0x260efec sp=0x260efe4 pc=0x51c670 May 08 15:06:45 volumio go-librespot[19072]: runtime.goexit() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x260efec sp=0x260efec pc=0x84730 May 08 15:06:45 volumio go-librespot[19072]: created by go-librespot/dealer.(*Dealer).reconnect May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:241 +0x78 May 08 15:06:45 volumio go-librespot[19072]: goroutine 21 [GC worker (idle), 4039 minutes]: May 08 15:06:45 volumio go-librespot[19072]: runtime.gopark(0x63b0ec, 0x2719e78, 0x1a, 0x14, 0x0) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x25de790 sp=0x25de77c pc=0x527b0 May 08 15:06:45 volumio go-librespot[19072]: runtime.gcBgMarkWorker() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1275 +0x100 fp=0x25de7ec sp=0x25de790 pc=0x2fbb8 May 08 15:06:45 volumio go-librespot[19072]: runtime.goexit() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x25de7ec sp=0x25de7ec pc=0x84730 May 08 15:06:45 volumio go-librespot[19072]: created by runtime.gcBgMarkStartWorkers May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1199 +0x20 May 08 15:06:45 volumio go-librespot[19072]: goroutine 22 [GC worker (idle)]: May 08 15:06:45 volumio go-librespot[19072]: runtime.gopark(0x63b0ec, 0x2532690, 0x1a, 0x14, 0x0) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2439790 sp=0x243977c pc=0x527b0 May 08 15:06:45 volumio go-librespot[19072]: runtime.gcBgMarkWorker() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1275 +0x100 fp=0x24397ec sp=0x2439790 pc=0x2fbb8 May 08 15:06:45 volumio go-librespot[19072]: runtime.goexit() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x24397ec sp=0x24397ec pc=0x84730 May 08 15:06:45 volumio go-librespot[19072]: created by runtime.gcBgMarkStartWorkers May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1199 +0x20 May 08 15:06:45 volumio go-librespot[19072]: goroutine 40 [GC worker (idle), 130 minutes]: May 08 15:06:45 volumio go-librespot[19072]: runtime.gopark(0x63b0ec, 0x2880000, 0x1a, 0x14, 0x0) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x25def90 sp=0x25def7c pc=0x527b0 May 08 15:06:45 volumio go-librespot[19072]: runtime.gcBgMarkWorker() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1275 +0x100 fp=0x25defec sp=0x25def90 pc=0x2fbb8 May 08 15:06:45 volumio go-librespot[19072]: runtime.goexit() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x25defec sp=0x25defec pc=0x84730 May 08 15:06:45 volumio go-librespot[19072]: created by runtime.gcBgMarkStartWorkers May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1199 +0x20 May 08 15:06:45 volumio go-librespot[19072]: goroutine 23 [GC worker (idle), 61 minutes]: May 08 15:06:45 volumio go-librespot[19072]: runtime.gopark(0x63b0ec, 0x25326a8, 0x1a, 0x14, 0x0) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2439f90 sp=0x2439f7c pc=0x527b0 May 08 15:06:45 volumio go-librespot[19072]: runtime.gcBgMarkWorker() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1275 +0x100 fp=0x2439fec sp=0x2439f90 pc=0x2fbb8 May 08 15:06:45 volumio go-librespot[19072]: runtime.goexit() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2439fec sp=0x2439fec pc=0x84730 May 08 15:06:45 volumio go-librespot[19072]: created by runtime.gcBgMarkStartWorkers May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/mgc.go:1199 +0x20 May 08 15:06:45 volumio go-librespot[19072]: goroutine 41 [IO wait, 19174 minutes]: May 08 15:06:45 volumio go-librespot[19072]: runtime.gopark(0x63b188, 0x6dc42e9c, 0x2, 0x1b, 0x5) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x243e5dc sp=0x243e5c8 pc=0x527b0 May 08 15:06:45 volumio go-librespot[19072]: runtime.netpollblock(0x6dc42e90, 0x72, 0x0) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:527 +0x100 fp=0x243e5f4 sp=0x243e5dc pc=0x49f2c May 08 15:06:45 volumio go-librespot[19072]: internal/poll.runtime_pollWait(0x6dc42e90, 0x72) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:306 +0x54 fp=0x243e608 sp=0x243e5f4 pc=0x800b4 May 08 15:06:45 volumio go-librespot[19072]: internal/poll.(*pollDesc).wait(0x24ccb04, 0x72, 0x0) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x243e61c sp=0x243e608 pc=0xf7cd0 May 08 15:06:45 volumio go-librespot[19072]: internal/poll.(*pollDesc).waitRead(...) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:89 May 08 15:06:45 volumio go-librespot[19072]: internal/poll.(*FD).Accept(0x24ccaf0) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_unix.go:614 +0x2d0 fp=0x243e66c sp=0x243e61c pc=0xfc7f0 May 08 15:06:45 volumio go-librespot[19072]: net.(*netFD).accept(0x24ccaf0) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/fd_unix.go:172 +0x20 fp=0x243e6cc sp=0x243e66c pc=0x28147c May 08 15:06:45 volumio go-librespot[19072]: net.(*TCPListener).accept(0x288a200) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/tcpsock_posix.go:148 +0x20 fp=0x243e6e4 sp=0x243e6cc pc=0x299e14 May 08 15:06:45 volumio go-librespot[19072]: net.(*TCPListener).Accept(0x288a200) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/tcpsock.go:297 +0x30 fp=0x243e700 sp=0x243e6e4 pc=0x298dd8 May 08 15:06:45 volumio go-librespot[19072]: net/http.(*onceCloseListener).Accept(0x26e6020) May 08 15:06:45 volumio go-librespot[19072]: :1 +0x34 fp=0x243e718 sp=0x243e700 pc=0x426e2c May 08 15:06:45 volumio go-librespot[19072]: net/http.(*Server).Serve(0x2856000, {0x6c42f0, 0x288a200}) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:3059 +0x344 fp=0x243e7b4 sp=0x243e718 pc=0x402e24 May 08 15:06:45 volumio go-librespot[19072]: net/http.Serve(...) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/http/server.go:2581 May 08 15:06:45 volumio go-librespot[19072]: main.(*ApiServer).serve(0x2522580) May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:346 +0x4d0 fp=0x243e7e4 sp=0x243e7b4 pc=0x52a63c May 08 15:06:45 volumio go-librespot[19072]: main.NewApiServer.func1() May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:190 +0x28 fp=0x243e7ec sp=0x243e7e4 pc=0x529e50 May 08 15:06:45 volumio go-librespot[19072]: runtime.goexit() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x243e7ec sp=0x243e7ec pc=0x84730 May 08 15:06:45 volumio go-librespot[19072]: created by main.NewApiServer May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:190 +0x1dc May 08 15:06:45 volumio go-librespot[19072]: goroutine 48 [select]: May 08 15:06:45 volumio go-librespot[19072]: runtime.gopark(0x63b1d0, 0x0, 0x9, 0x18, 0x1) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x2450ea0 sp=0x2450e8c pc=0x527b0 May 08 15:06:45 volumio go-librespot[19072]: runtime.selectgo(0x2450fac, 0x2450f94, 0x0, 0x0, 0x2, 0x1) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x2450f48 sp=0x2450ea0 pc=0x64d80 May 08 15:06:45 volumio go-librespot[19072]: go-librespot/ap.(*Accesspoint).pongAckTicker(0x24c0240) May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:301 +0x8c fp=0x2450fe4 sp=0x2450f48 pc=0x4599fc May 08 15:06:45 volumio go-librespot[19072]: go-librespot/ap.NewAccesspoint.func1() May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:66 +0x28 fp=0x2450fec sp=0x2450fe4 pc=0x457de0 May 08 15:06:45 volumio go-librespot[19072]: runtime.goexit() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x2450fec sp=0x2450fec pc=0x84730 May 08 15:06:45 volumio go-librespot[19072]: created by go-librespot/ap.NewAccesspoint May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:66 +0x190 May 08 15:06:45 volumio go-librespot[19072]: goroutine 13 [select, 19174 minutes]: May 08 15:06:45 volumio go-librespot[19072]: runtime.gopark(0x63b1d0, 0x0, 0x9, 0x18, 0x1) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x243fe9c sp=0x243fe88 pc=0x527b0 May 08 15:06:45 volumio go-librespot[19072]: runtime.selectgo(0x243ffb0, 0x243ff84, 0x0, 0x0, 0x2, 0x1) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/select.go:327 +0xb70 fp=0x243ff44 sp=0x243fe9c pc=0x64d80 May 08 15:06:45 volumio go-librespot[19072]: go-librespot/player.(*Player).manageLoop(0x24a7b60) May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/player/player.go:92 +0xbc fp=0x243ffe4 sp=0x243ff44 pc=0x46cc68 May 08 15:06:45 volumio go-librespot[19072]: go-librespot/player.NewPlayer.func2() May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/player/player.go:80 +0x28 fp=0x243ffec sp=0x243ffe4 pc=0x46caf0 May 08 15:06:45 volumio go-librespot[19072]: runtime.goexit() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x243ffec sp=0x243ffec pc=0x84730 May 08 15:06:45 volumio go-librespot[19072]: created by go-librespot/player.NewPlayer May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/player/player.go:80 +0x198 May 08 15:06:45 volumio go-librespot[19072]: goroutine 404 [IO wait, 3 minutes]: May 08 15:06:45 volumio go-librespot[19072]: runtime.gopark(0x63b188, 0x6dc42d64, 0x2, 0x1b, 0x5) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/proc.go:381 +0x100 fp=0x244cd88 sp=0x244cd74 pc=0x527b0 May 08 15:06:45 volumio go-librespot[19072]: runtime.netpollblock(0x6dc42d58, 0x72, 0x0) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:527 +0x100 fp=0x244cda0 sp=0x244cd88 pc=0x49f2c May 08 15:06:45 volumio go-librespot[19072]: internal/poll.runtime_pollWait(0x6dc42d58, 0x72) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/netpoll.go:306 +0x54 fp=0x244cdb4 sp=0x244cda0 pc=0x800b4 May 08 15:06:45 volumio go-librespot[19072]: internal/poll.(*pollDesc).wait(0x27ff414, 0x72, 0x0) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x244cdc8 sp=0x244cdb4 pc=0xf7cd0 May 08 15:06:45 volumio go-librespot[19072]: internal/poll.(*pollDesc).waitRead(...) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_poll_runtime.go:89 May 08 15:06:45 volumio go-librespot[19072]: internal/poll.(*FD).Read(0x27ff400, {0x251689c, 0x3, 0x3}) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/internal/poll/fd_unix.go:167 +0x240 fp=0x244ce18 sp=0x244cdc8 pc=0xf8edc May 08 15:06:45 volumio go-librespot[19072]: net.(*netFD).Read(0x27ff400, {0x251689c, 0x3, 0x3}) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/fd_posix.go:55 +0x38 fp=0x244ce44 sp=0x244ce18 pc=0x27f3c0 May 08 15:06:45 volumio go-librespot[19072]: net.(*conn).Read(0x24102e8, {0x251689c, 0x3, 0x3}) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/net/net.go:183 +0x48 fp=0x244ce74 sp=0x244ce44 pc=0x290344 May 08 15:06:45 volumio go-librespot[19072]: net.(*TCPConn).Read(0x24102e8, {0x251689c, 0x3, 0x3}) May 08 15:06:45 volumio go-librespot[19072]: :1 +0x44 fp=0x244ce94 sp=0x244ce74 pc=0x2a4a20 May 08 15:06:45 volumio go-librespot[19072]: io.ReadAtLeast({0x6c2858, 0x24102e8}, {0x251689c, 0x3, 0x3}, 0x3) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/io/io.go:332 +0x90 fp=0x244cec0 sp=0x244ce94 pc=0xf1a38 May 08 15:06:45 volumio go-librespot[19072]: io.ReadFull(...) May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/io/io.go:351 May 08 15:06:45 volumio go-librespot[19072]: go-librespot/ap.(*shannonConn).receivePacket(0x25fe120) May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/ap/shannon.go:80 +0x124 fp=0x244cf20 sp=0x244cec0 pc=0x45c548 May 08 15:06:45 volumio go-librespot[19072]: go-librespot/ap.(*Accesspoint).recvLoop(0x24c0240) May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:239 +0x58 fp=0x244cfe4 sp=0x244cf20 pc=0x459388 May 08 15:06:45 volumio go-librespot[19072]: go-librespot/ap.(*Accesspoint).reconnect.func1() May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:335 +0x28 fp=0x244cfec sp=0x244cfe4 pc=0x459ee4 May 08 15:06:45 volumio go-librespot[19072]: runtime.goexit() May 08 15:06:45 volumio go-librespot[19072]: /opt/hostedtoolcache/go/1.20.8/x64/src/runtime/asm_arm.s:831 +0x4 fp=0x244cfec sp=0x244cfec pc=0x84730 May 08 15:06:45 volumio go-librespot[19072]: created by go-librespot/ap.(*Accesspoint).reconnect May 08 15:06:45 volumio go-librespot[19072]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:335 +0x168 May 08 15:06:45 volumio go-librespot[19072]: Aborted May 08 15:06:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a May 08 15:06:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. May 08 15:06:45 volumio sudo[16351]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-08 15:05 May 08 15:06:45 volumio sudo[16351]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="893d2e91c55a7857b58762e70c2f65b9d163562b" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="30b77d58bf3c2745acc494ddafed946392a79905" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 20 Oct 2023 03:38:28 PM CEST" VOLUMIO_VERSION="3.569" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4163d3756b55b3bf7c480d7285f68954"