-- 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"