-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Tue 2024-07-23 10:43:04 CEST. --
Jul 23 10:42:08 volumio-principal ntpd[653]: Soliciting pool server 2606:4700:f1::1
Jul 23 10:42:11 volumio-principal wpa_supplicant[758]: wlan0: Associated with b8:be:f4:bc:78:d5
Jul 23 10:42:11 volumio-principal dhcpcd[770]: wlan0: carrier lost
Jul 23 10:42:11 volumio-principal wpa_supplicant[758]: wlan0: CTRL-EVENT-CONNECTED - Connection to b8:be:f4:bc:78:d5 completed [id=0 id_str=]
Jul 23 10:42:11 volumio-principal wpa_supplicant[758]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Jul 23 10:42:11 volumio-principal avahi-daemon[516]: Withdrawing address record for 169.254.176.174 on wlan0.
Jul 23 10:42:11 volumio-principal avahi-daemon[516]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 169.254.176.174.
Jul 23 10:42:11 volumio-principal avahi-daemon[516]: Interface wlan0.IPv4 no longer relevant for mDNS.
Jul 23 10:42:11 volumio-principal dhcpcd[770]: wlan0: deleting route to 169.254.0.0/16
Jul 23 10:42:11 volumio-principal dhcpcd[770]: wlan0: deleting default route
Jul 23 10:42:11 volumio-principal volumio[2302]: info: Discovery: A device disappeared from network
Jul 23 10:42:11 volumio-principal volumio[2302]: info: Discovery: A device disappeared from network
Jul 23 10:42:11 volumio-principal dhcpcd[770]: wlan0: carrier acquired
Jul 23 10:42:11 volumio-principal dhcpcd[770]: wlan0: IAID dd:80:f5:90
Jul 23 10:42:11 volumio-principal dhcpcd[770]: wlan0: soliciting a DHCP lease
Jul 23 10:42:12 volumio-principal dhcpcd[770]: wlan0: soliciting an IPv6 router
Jul 23 10:42:12 volumio-principal dhcpcd[770]: wlan0: offered 192.168.100.125 from 192.168.100.1
Jul 23 10:42:13 volumio-principal dhcpcd[770]: wlan0: probing address 192.168.100.125/24
Jul 23 10:42:13 volumio-principal ntpd[653]: Soliciting pool server 82.223.203.159
Jul 23 10:42:13 volumio-principal ntpd[653]: Deleting interface #6 wlan0, 169.254.176.174#123, interface stats: received=0, sent=6, dropped=0, active_time=18 secs
Jul 23 10:42:13 volumio-principal ntpd[653]: 194.0.5.123 local addr 169.254.176.174 ->
Jul 23 10:42:13 volumio-principal ntpd[653]: 217.71.200.210 local addr 169.254.176.174 ->
Jul 23 10:42:13 volumio-principal ntpd[653]: 193.149.0.217 local addr 169.254.176.174 ->
Jul 23 10:42:13 volumio-principal ntpd[653]: 162.159.200.1 local addr 169.254.176.174 ->
Jul 23 10:42:13 volumio-principal ntpd[653]: 193.149.0.221 local addr 169.254.176.174 ->
Jul 23 10:42:13 volumio-principal ntpd[653]: 162.159.200.123 local addr 169.254.176.174 ->
Jul 23 10:42:15 volumio-principal ntpd[653]: error resolving pool 1.debian.pool.ntp.org: System error (-11)
Jul 23 10:42:16 volumio-principal volumio[2302]: info: Discovery: Browse raised the following error Error: getaddrinfo -3008
Jul 23 10:42:18 volumio-principal dhcpcd[770]: wlan0: leased 192.168.100.125 for 86400 seconds
Jul 23 10:42:18 volumio-principal avahi-daemon[516]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.100.125.
Jul 23 10:42:18 volumio-principal avahi-daemon[516]: New relevant interface wlan0.IPv4 for mDNS.
Jul 23 10:42:18 volumio-principal dhcpcd[770]: wlan0: adding route to 192.168.100.0/24
Jul 23 10:42:18 volumio-principal avahi-daemon[516]: Registering new address record for 192.168.100.125 on wlan0.IPv4.
Jul 23 10:42:18 volumio-principal dhcpcd[770]: wlan0: adding default route via 192.168.100.1
Jul 23 10:42:19 volumio-principal volumio[2302]: info: Discovery: Browse raised the following error Error: getaddrinfo -3008
Jul 23 10:42:19 volumio-principal volumio[2302]: info: Discovery: adding ac411f73-a670-4edb-803a-53cc23512fdf
Jul 23 10:42:19 volumio-principal volumio[2302]: info: Discovery: Found device Volumio-Principal
Jul 23 10:42:19 volumio-principal volumio[2302]: info: CoreCommandRouter::volumioGetState
Jul 23 10:42:20 volumio-principal ntpd[653]: Listen normally on 7 wlan0 192.168.100.125:123
Jul 23 10:42:20 volumio-principal ntpd[653]: new interface(s) found: waking up resolver
Jul 23 10:42:21 volumio-principal ntpd[653]: Soliciting pool server 208.85.20.220
Jul 23 10:42:22 volumio-principal ntpd[653]: Soliciting pool server 158.227.98.15
Jul 23 10:42:23 volumio-principal ntpd[653]: Soliciting pool server 5.250.191.170
Jul 23 10:42:24 volumio-principal ntpd[653]: Soliciting pool server 90.68.206.60
Jul 23 10:42:28 volumio-principal wpa_supplicant[758]: wlan0: CTRL-EVENT-DISCONNECTED bssid=b8:be:f4:bc:78:d5 reason=8
Jul 23 10:42:28 volumio-principal dhcpcd[770]: wlan0: carrier lost
Jul 23 10:42:28 volumio-principal wpa_supplicant[758]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
Jul 23 10:42:28 volumio-principal wpa_supplicant[758]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US
Jul 23 10:42:28 volumio-principal avahi-daemon[516]: Withdrawing address record for 192.168.100.125 on wlan0.
Jul 23 10:42:28 volumio-principal avahi-daemon[516]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.100.125.
Jul 23 10:42:28 volumio-principal avahi-daemon[516]: Interface wlan0.IPv4 no longer relevant for mDNS.
Jul 23 10:42:28 volumio-principal dhcpcd[770]: wlan0: deleting route to 192.168.100.0/24
Jul 23 10:42:28 volumio-principal dhcpcd[770]: wlan0: deleting default route via 192.168.100.1
Jul 23 10:42:28 volumio-principal volumio[2302]: info: Discovery: A device disappeared from network
Jul 23 10:42:28 volumio-principal volumio[2302]: info: Discovery: Device volumio-principal disappeared from network
Jul 23 10:42:28 volumio-principal wpa_supplicant[758]: wlan0: Trying to associate with SSID 'devolo-961'
Jul 23 10:42:28 volumio-principal volumio[2302]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 23 10:42:28 volumio-principal volumio[2302]: Error: send ENETUNREACH 255.255.255.255:3483
Jul 23 10:42:28 volumio-principal volumio[2302]: at doSend (dgram.js:692:16)
Jul 23 10:42:28 volumio-principal volumio[2302]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12)
Jul 23 10:42:28 volumio-principal volumio[2302]: at afterDns (dgram.js:638:5)
Jul 23 10:42:28 volumio-principal volumio[2302]: at processTicksAndRejections (internal/process/task_queues.js:81:21) {
Jul 23 10:42:28 volumio-principal volumio[2302]: errno: -101,
Jul 23 10:42:28 volumio-principal volumio[2302]: code: 'ENETUNREACH',
Jul 23 10:42:28 volumio-principal volumio[2302]: syscall: 'send',
Jul 23 10:42:28 volumio-principal volumio[2302]: address: '255.255.255.255',
Jul 23 10:42:28 volumio-principal volumio[2302]: port: 3483
Jul 23 10:42:28 volumio-principal volumio[2302]: }
Jul 23 10:42:28 volumio-principal volumio[2302]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 23 10:42:29 volumio-principal sudo[3020]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-23 10:41
Jul 23 10:42:29 volumio-principal sudo[3020]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:29 volumio-principal sudo[3020]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:29 volumio-principal volumio-remote-updater[490]: [2024-07-23 10:42:29] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Jul 23 10:42:29 volumio-principal volumio-remote-updater[490]: [2024-07-23 10:42:29] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Jul 23 10:42:29 volumio-principal go-librespot[2709]: time="2024-07-23T10:42:29+02:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF"
Jul 23 10:42:29 volumio-principal systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Jul 23 10:42:29 volumio-principal systemd[1]: volumio.service: Failed with result 'exit-code'.
Jul 23 10:42:29 volumio-principal systemd[1]: Started dynamicswap service.
Jul 23 10:42:29 volumio-principal systemd[1]: dynamicswap.service: Succeeded.
Jul 23 10:42:29 volumio-principal systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart.
Jul 23 10:42:29 volumio-principal systemd[1]: volumio.service: Scheduled restart job, restart counter is at 7.
Jul 23 10:42:29 volumio-principal systemd[1]: Started dynamicswap service.
Jul 23 10:42:29 volumio-principal systemd[1]: Stopped Volumio Backend Module.
Jul 23 10:42:29 volumio-principal systemd[1]: Started Volumio Backend Module.
Jul 23 10:42:29 volumio-principal systemd[1]: dynamicswap.service: Succeeded.
Jul 23 10:42:30 volumio-principal ntpd[653]: Deleting interface #7 wlan0, 192.168.100.125#123, interface stats: received=16, sent=23, dropped=5, active_time=10 secs
Jul 23 10:42:30 volumio-principal ntpd[653]: 5.250.191.170 local addr 192.168.100.125 ->
Jul 23 10:42:30 volumio-principal ntpd[653]: 158.227.98.15 local addr 192.168.100.125 ->
Jul 23 10:42:30 volumio-principal ntpd[653]: 208.85.20.220 local addr 192.168.100.125 ->
Jul 23 10:42:30 volumio-principal ntpd[653]: 194.0.5.123 local addr 192.168.100.125 ->
Jul 23 10:42:30 volumio-principal ntpd[653]: 217.71.200.210 local addr 192.168.100.125 ->
Jul 23 10:42:30 volumio-principal ntpd[653]: 193.149.0.217 local addr 192.168.100.125 ->
Jul 23 10:42:30 volumio-principal ntpd[653]: 162.159.200.1 local addr 192.168.100.125 ->
Jul 23 10:42:30 volumio-principal ntpd[653]: 193.149.0.221 local addr 192.168.100.125 ->
Jul 23 10:42:30 volumio-principal ntpd[653]: 162.159.200.123 local addr 192.168.100.125 ->
Jul 23 10:42:30 volumio-principal volumio[3034]: info: -------------------------------------------
Jul 23 10:42:30 volumio-principal volumio[3034]: info: ----- Volumio3 ----
Jul 23 10:42:30 volumio-principal volumio[3034]: info: -------------------------------------------
Jul 23 10:42:30 volumio-principal volumio[3034]: info: ----- System startup ----
Jul 23 10:42:30 volumio-principal volumio[3034]: info: -------------------------------------------
Jul 23 10:42:31 volumio-principal volumio[3034]: info: MYVOLUMIO Environment detected
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Plugin folders cleanup
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Scanning into folder /volumio/app/plugins/
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Scanning category audio_interface
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Scanning category miscellanea
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Scanning category music_service
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Scanning category plugins.json
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Scanning category system_controller
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Scanning category user_interface
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Scanning into folder /data/plugins/
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Scanning category music_service
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Plugin folders cleanup completed
Jul 23 10:42:31 volumio-principal volumio[3034]: info: -------------------------------------------
Jul 23 10:42:31 volumio-principal volumio[3034]: info: ----- Core plugins startup ----
Jul 23 10:42:31 volumio-principal volumio[3034]: info: -------------------------------------------
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Loading plugins from folder /volumio/app/plugins/
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Adding plugin upnp to MyMusic Plugins
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Adding plugin airplay_emulation to MyMusic Plugins
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Adding plugin upnp_browser to MyMusic Plugins
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Loading plugins from folder /data/plugins/
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Loading plugin "system"...
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Loading plugin "appearance"...
Jul 23 10:42:31 volumio-principal wpa_supplicant[758]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Loading plugin "network"...
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Refreshing Cached IP Addresses
Jul 23 10:42:31 volumio-principal sudo[3057]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Jul 23 10:42:31 volumio-principal sudo[3057]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:31 volumio-principal sudo[3057]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:31 volumio-principal sudo[3059]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jul 23 10:42:31 volumio-principal sudo[3059]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Loading plugin "services"...
Jul 23 10:42:31 volumio-principal sudo[3059]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Loading plugin "alsa_controller"...
Jul 23 10:42:31 volumio-principal sudo[3063]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Jul 23 10:42:31 volumio-principal sudo[3063]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:31 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Loading plugin "wizard"...
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Loading plugin "volumio_command_line_client"...
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Loading plugin "upnp"...
Jul 23 10:42:31 volumio-principal volumio[3034]: info: [1721724151825] Starting Upmpd Daemon
Jul 23 10:42:31 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Loading plugin "my_music"...
Jul 23 10:42:31 volumio-principal volumio[3034]: info: Loading plugin "mpd"...
Jul 23 10:42:32 volumio-principal volumio[3034]: info: Creating MPD Configuration file
Jul 23 10:42:32 volumio-principal sudo[3070]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Jul 23 10:42:32 volumio-principal volumio[3034]: info: Loading plugin "upnp_browser"...
Jul 23 10:42:32 volumio-principal sudo[3070]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:32 volumio-principal sudo[3070]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:32 volumio-principal sudo[3072]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Jul 23 10:42:32 volumio-principal sudo[3072]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:32 volumio-principal systemd[1]: Stopping Music Player Daemon...
Jul 23 10:42:32 volumio-principal systemd[1]: mpd.service: Succeeded.
Jul 23 10:42:32 volumio-principal systemd[1]: Stopped Music Player Daemon.
Jul 23 10:42:32 volumio-principal systemd[1]: Starting Music Player Daemon...
Jul 23 10:42:32 volumio-principal volumio[3034]: info: Loading plugin "networkfs"...
Jul 23 10:42:32 volumio-principal volumio[3034]: info: Starting Udev Watcher for removable devices
Jul 23 10:42:32 volumio-principal volumio[3034]: info: Ignoring mount for partition: boot
Jul 23 10:42:32 volumio-principal volumio[3034]: info: Ignoring mount for partition: volumio
Jul 23 10:42:32 volumio-principal volumio[3034]: info: Ignoring mount for partition: volumio_data
Jul 23 10:42:32 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jul 23 10:42:32 volumio-principal volumio[3034]: info: Loading plugin "alarm-clock"...
Jul 23 10:42:32 volumio-principal volumio[3034]: info: Loading plugin "airplay_emulation"...
Jul 23 10:42:32 volumio-principal volumio[3034]: info: Starting Shairport Sync
Jul 23 10:42:32 volumio-principal volumio[3034]: info: Loading plugin "last_100"...
Jul 23 10:42:32 volumio-principal volumio[3034]: info: Loading plugin "webradio"...
Jul 23 10:42:32 volumio-principal mpd[3077]: Jul 23 10:42 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Jul 23 10:42:32 volumio-principal mpd[3077]: Jul 23 10:42 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured
Jul 23 10:42:32 volumio-principal mpd[3077]: Jul 23 10:42 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured
Jul 23 10:42:32 volumio-principal volumio[3034]: info: Loading plugin "i2s_dacs"...
Jul 23 10:42:32 volumio-principal systemd[1]: Started Music Player Daemon.
Jul 23 10:42:32 volumio-principal sudo[3072]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:32 volumio-principal volumio[3034]: info: Loading plugin "volumiodiscovery"...
Jul 23 10:42:32 volumio-principal volumio[3034]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Jul 23 10:42:32 volumio-principal volumio[3034]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jul 23 10:42:32 volumio-principal volumio[3034]: *** WARNING *** For more information see
Jul 23 10:42:32 volumio-principal node[3034]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Jul 23 10:42:32 volumio-principal volumio[3034]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Jul 23 10:42:32 volumio-principal volumio[3034]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jul 23 10:42:32 volumio-principal volumio[3034]: *** WARNING *** For more information see
Jul 23 10:42:32 volumio-principal node[3034]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jul 23 10:42:32 volumio-principal node[3034]: *** WARNING *** For more information see
Jul 23 10:42:32 volumio-principal node[3034]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Jul 23 10:42:32 volumio-principal node[3034]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jul 23 10:42:32 volumio-principal node[3034]: *** WARNING *** For more information see
Jul 23 10:42:32 volumio-principal volumio[3034]: info: Applying required configuration parameters for plugin volumiodiscovery
Jul 23 10:42:32 volumio-principal volumio[3034]: info: Discovery: Started advertising with name: Volumio-Principal
Jul 23 10:42:32 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jul 23 10:42:32 volumio-principal volumio[3034]: info: Loading plugin "spop"...
Jul 23 10:42:33 volumio-principal volumio[3034]: info: Loading plugin "squeezelite_mc"...
Jul 23 10:42:33 volumio-principal volumio[3034]: info: Loading plugin "outputs"...
Jul 23 10:42:33 volumio-principal volumio[3034]: info: Loading plugin "albumart"...
Jul 23 10:42:33 volumio-principal volumio[3034]: info: Plugin example_plugin is not enabled
Jul 23 10:42:33 volumio-principal volumio[3034]: info: Loading plugin "inputs"...
Jul 23 10:42:33 volumio-principal volumio[3034]: info: Loading plugin "updater_comm"...
Jul 23 10:42:34 volumio-principal volumio[3034]: info: Plugin mpdemulation is not enabled
Jul 23 10:42:34 volumio-principal volumio[3034]: info: Loading plugin "rest_api"...
Jul 23 10:42:34 volumio-principal volumio[3034]: info: Loading plugin "websocket"...
Jul 23 10:42:34 volumio-principal volumio[3034]: info: Loading plugin "lms"...
Jul 23 10:42:34 volumio-principal volumio[3034]: info: Loading i18n strings for locale es
Jul 23 10:42:34 volumio-principal volumio[3034]: Updating browse sources language
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 23 10:42:34 volumio-principal volumio[3034]: Forking 3 albumart workers
Jul 23 10:42:34 volumio-principal volumio-remote-updater[490]: [2024-07-23 10:42:34] [connect] Successful connection
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::initPlayerControls
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: Express server listening on port 3000
Jul 23 10:42:34 volumio-principal volumio[3034]: [Metrics] WebUI: 4s 66.85ms
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreStateMachine::resetVolumioState
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreStateMachine::getcurrentVolume
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::volumioRetrievevolume
Jul 23 10:42:34 volumio-principal volumio[3034]: info: MPD Permissions set
Jul 23 10:42:34 volumio-principal volumio-remote-updater[490]: [2024-07-23 10:42:34] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1721724154 101
Jul 23 10:42:34 volumio-principal volumio[3034]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 1
Jul 23 10:42:34 volumio-principal volumio[3034]: info: MPD running with PID3077
Jul 23 10:42:34 volumio-principal volumio[3034]: ,establishing connection
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: Reloading queue from file
Jul 23 10:42:34 volumio-principal volumio[3034]: error: updateQueue error: null
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreStateMachine::setRepeat null single undefined
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreStateMachine::pushState
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CorePlayQueue::getTrack 0
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::volumioPushState
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreStateMachine::setRandom null
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreStateMachine::pushState
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CorePlayQueue::getTrack 0
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::volumioPushState
Jul 23 10:42:34 volumio-principal volumio[3034]: info: Setting Device type: Raspberry PI
Jul 23 10:42:34 volumio-principal volumio[3034]: info: Completed loading Core Plugins
Jul 23 10:42:34 volumio-principal volumio[3034]: info: Preparing to generate the ALSA configuration file
Jul 23 10:42:34 volumio-principal volumio[3034]: info: VolumeController:: Volume=43 Mute =false
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreStateMachine::pushState
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CorePlayQueue::getTrack 0
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::volumioPushState
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreStateMachine::updateTrackBlock
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CorePlayQueue::getTrackBlock
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::volumioRetrievevolume
Jul 23 10:42:34 volumio-principal volumio[3034]: error: updateQueue error: null
Jul 23 10:42:34 volumio-principal volumio[3034]: info: Asound.conf file unchanged, so no further update is needed
Jul 23 10:42:34 volumio-principal volumio[3034]: info: Output device has changed, restarting MPD
Jul 23 10:42:34 volumio-principal volumio[3034]: Starting albumart workers
Jul 23 10:42:34 volumio-principal volumio[3034]: Starting albumart workers
Jul 23 10:42:34 volumio-principal volumio[3034]: Starting albumart workers
Jul 23 10:42:34 volumio-principal volumio[3034]: info: Output device has changed, restarting Shairport Sync
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:34 volumio-principal sudo[3129]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Jul 23 10:42:34 volumio-principal sudo[3129]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:34 volumio-principal sudo[3129]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:34 volumio-principal sudo[3131]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Jul 23 10:42:34 volumio-principal sudo[3131]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:34 volumio-principal volumio[3034]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jul 23 10:42:34 volumio-principal volumio[3034]: info: ___________ START PLUGINS ___________
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jul 23 10:42:34 volumio-principal volumio[3034]: info: [1721724154965] CoreMusicLibrary::Adding element Media Servers
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:34 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:35 volumio-principal systemd[1]: Stopping Music Player Daemon...
Jul 23 10:42:35 volumio-principal systemd[1]: mpd.service: Succeeded.
Jul 23 10:42:35 volumio-principal systemd[1]: Stopped Music Player Daemon.
Jul 23 10:42:35 volumio-principal systemd[1]: Starting Music Player Daemon...
Jul 23 10:42:35 volumio-principal volumio[3034]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:35 volumio-principal volumio[3034]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jul 23 10:42:35 volumio-principal volumio[3034]: info: [1721724155161] CoreMusicLibrary::Adding element Last_100
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jul 23 10:42:35 volumio-principal volumio[3034]: info: [1721724155165] CoreMusicLibrary::Adding element Webradio
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jul 23 10:42:35 volumio-principal volumio[3034]: info: Creating Spotify config file
Jul 23 10:42:35 volumio-principal volumio[3034]: info: [squeezelite_mc] Starting proxy server...
Jul 23 10:42:35 volumio-principal volumio[3034]: info: Volumio Calling Home
Jul 23 10:42:35 volumio-principal sudo[3162]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver
Jul 23 10:42:35 volumio-principal sudo[3162]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:35 volumio-principal systemd[1]: Stopping Logitech Media Server Daemon...
Jul 23 10:42:35 volumio-principal volumio[3034]: info: [squeezelite_mc] Proxy server started on port 44383
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::volumioRetrievevolume
Jul 23 10:42:35 volumio-principal volumio[3034]: Unhandled rejection Error: No sockets available, cannot start.
Jul 23 10:42:35 volumio-principal volumio[3034]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11)
Jul 23 10:42:35 volumio-principal volumio[3034]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10)
Jul 23 10:42:35 volumio-principal volumio[3034]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10
Jul 23 10:42:35 volumio-principal volumio[3034]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9)
Jul 23 10:42:35 volumio-principal volumio[3034]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18)
Jul 23 10:42:35 volumio-principal volumio[3034]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10)
Jul 23 10:42:35 volumio-principal volumio[3034]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10)
Jul 23 10:42:35 volumio-principal volumio[3034]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17)
Jul 23 10:42:35 volumio-principal volumio[3034]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12)
Jul 23 10:42:35 volumio-principal volumio[3034]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24)
Jul 23 10:42:35 volumio-principal volumio[3034]: at HashMap. (/volumio/app/pluginmanager.js:496:31)
Jul 23 10:42:35 volumio-principal volumio[3034]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10)
Jul 23 10:42:35 volumio-principal volumio[3034]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7)
Jul 23 10:42:35 volumio-principal volumio[3034]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20)
Jul 23 10:42:35 volumio-principal volumio[3034]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29)
Jul 23 10:42:35 volumio-principal volumio[3034]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)
Jul 23 10:42:35 volumio-principal volumio[3034]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.dfs.volumio.org
Jul 23 10:42:35 volumio-principal systemd[1]: logitechmediaserver.service: Succeeded.
Jul 23 10:42:35 volumio-principal volumio[3034]: info: MPD Permissions set
Jul 23 10:42:35 volumio-principal systemd[1]: Stopped Logitech Media Server Daemon.
Jul 23 10:42:35 volumio-principal systemd[1]: Starting Logitech Media Server Daemon...
Jul 23 10:42:35 volumio-principal systemd[1]: Started Logitech Media Server Daemon.
Jul 23 10:42:35 volumio-principal sudo[3162]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:35 volumio-principal volumio[3034]: info: Spotify config file written
Jul 23 10:42:35 volumio-principal sudo[3182]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Jul 23 10:42:35 volumio-principal sudo[3182]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:35 volumio-principal volumio[3034]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2
Jul 23 10:42:35 volumio-principal volumio[3034]: info: VolumeController:: Volume=43 Mute =false
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreStateMachine::pushState
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CorePlayQueue::getTrack 0
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::volumioPushState
Jul 23 10:42:35 volumio-principal volumio[3034]: info: logitechmediaserver started
Jul 23 10:42:35 volumio-principal systemd[1]: Stopping go-librespot Daemon...
Jul 23 10:42:35 volumio-principal systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM
Jul 23 10:42:35 volumio-principal systemd[1]: go-librespot-daemon.service: Succeeded.
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:35 volumio-principal systemd[1]: Stopped go-librespot Daemon.
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:35 volumio-principal systemd[1]: Started go-librespot Daemon.
Jul 23 10:42:35 volumio-principal sudo[3182]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:35 volumio-principal go-librespot[3184]: Librespot-go daemon starting...
Jul 23 10:42:35 volumio-principal go-librespot[3184]: time="2024-07-23T10:42:35+02:00" level=info msg="generated new device id: 11c7ca94c952a6ed7858fa0794301210e7f5517d"
Jul 23 10:42:35 volumio-principal go-librespot[3184]: time="2024-07-23T10:42:35+02:00" level=debug msg="stored credentials found for gcerruela"
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:35 volumio-principal go-librespot[3184]: time="2024-07-23T10:42:35+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy"
Jul 23 10:42:35 volumio-principal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 23 10:42:35 volumio-principal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 23 10:42:35 volumio-principal volumio[3034]: info: VolumeController:: Volume=43 Mute =false
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreStateMachine::pushState
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CorePlayQueue::getTrack 0
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::volumioPushState
Jul 23 10:42:35 volumio-principal volumio[3034]: info: [squeezelite_mc] Server discovery started
Jul 23 10:42:35 volumio-principal volumio[3034]: info: [squeezelite_mc] Player finder started
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:35 volumio-principal volumio[3034]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 23 10:42:35 volumio-principal volumio[3034]: info: [squeezelite_mc] Executing aplay -D hw:2 --nonblock -f MPEG /dev/zero 2>&1 || true
Jul 23 10:42:35 volumio-principal volumio[3034]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 23 10:42:35 volumio-principal volumio[3034]: Error: send ENETUNREACH 255.255.255.255:3483
Jul 23 10:42:35 volumio-principal volumio[3034]: at doSend (dgram.js:692:16)
Jul 23 10:42:35 volumio-principal volumio[3034]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12)
Jul 23 10:42:35 volumio-principal volumio[3034]: at afterDns (dgram.js:638:5)
Jul 23 10:42:35 volumio-principal volumio[3034]: at processTicksAndRejections (internal/process/task_queues.js:81:21) {
Jul 23 10:42:35 volumio-principal volumio[3034]: errno: -101,
Jul 23 10:42:35 volumio-principal volumio[3034]: code: 'ENETUNREACH',
Jul 23 10:42:35 volumio-principal volumio[3034]: syscall: 'send',
Jul 23 10:42:35 volumio-principal volumio[3034]: address: '255.255.255.255',
Jul 23 10:42:35 volumio-principal volumio[3034]: port: 3483
Jul 23 10:42:35 volumio-principal volumio[3034]: }
Jul 23 10:42:35 volumio-principal volumio[3034]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 23 10:42:35 volumio-principal mpd[3144]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Jul 23 10:42:35 volumio-principal mpd[3144]: output: No 'audio_output' defined in config file
Jul 23 10:42:35 volumio-principal mpd[3144]: output: Attempt to detect audio output device
Jul 23 10:42:35 volumio-principal mpd[3144]: output: Attempting to detect a alsa audio device
Jul 23 10:42:35 volumio-principal mpd[3144]: output: Successfully detected a alsa audio device
Jul 23 10:42:35 volumio-principal mpd[3144]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured
Jul 23 10:42:35 volumio-principal mpd[3144]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured
Jul 23 10:42:35 volumio-principal mpd[3144]: zeroconf: No global port, disabling zeroconf
Jul 23 10:42:36 volumio-principal systemd[1]: Started Music Player Daemon.
Jul 23 10:42:36 volumio-principal sudo[3131]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:36 volumio-principal sudo[3208]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-23 10:41
Jul 23 10:42:36 volumio-principal sudo[3208]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:36 volumio-principal sudo[3208]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:36 volumio-principal volumio-remote-updater[490]: [2024-07-23 10:42:36] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Jul 23 10:42:36 volumio-principal volumio-remote-updater[490]: [2024-07-23 10:42:36] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Jul 23 10:42:36 volumio-principal systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Jul 23 10:42:36 volumio-principal sudo[3063]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:36 volumio-principal systemd[1]: volumio.service: Failed with result 'exit-code'.
Jul 23 10:42:36 volumio-principal systemd[1]: Started dynamicswap service.
Jul 23 10:42:36 volumio-principal systemd[1]: dynamicswap.service: Succeeded.
Jul 23 10:42:36 volumio-principal systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart.
Jul 23 10:42:36 volumio-principal systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8.
Jul 23 10:42:36 volumio-principal systemd[1]: Started dynamicswap service.
Jul 23 10:42:36 volumio-principal systemd[1]: Stopped Volumio Backend Module.
Jul 23 10:42:36 volumio-principal systemd[1]: Started Volumio Backend Module.
Jul 23 10:42:36 volumio-principal systemd[1]: dynamicswap.service: Succeeded.
Jul 23 10:42:37 volumio-principal wpa_supplicant[758]: wlan0: Trying to associate with SSID 'devolo-961'
Jul 23 10:42:37 volumio-principal volumio[3222]: info: -------------------------------------------
Jul 23 10:42:37 volumio-principal volumio[3222]: info: ----- Volumio3 ----
Jul 23 10:42:37 volumio-principal volumio[3222]: info: -------------------------------------------
Jul 23 10:42:37 volumio-principal volumio[3222]: info: ----- System startup ----
Jul 23 10:42:37 volumio-principal volumio[3222]: info: -------------------------------------------
Jul 23 10:42:38 volumio-principal volumio[3222]: info: MYVOLUMIO Environment detected
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Plugin folders cleanup
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Scanning into folder /volumio/app/plugins/
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Scanning category audio_interface
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Scanning category miscellanea
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Scanning category music_service
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Scanning category plugins.json
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Scanning category system_controller
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Scanning category user_interface
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Scanning into folder /data/plugins/
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Scanning category music_service
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Plugin folders cleanup completed
Jul 23 10:42:38 volumio-principal volumio[3222]: info: -------------------------------------------
Jul 23 10:42:38 volumio-principal volumio[3222]: info: ----- Core plugins startup ----
Jul 23 10:42:38 volumio-principal volumio[3222]: info: -------------------------------------------
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Loading plugins from folder /volumio/app/plugins/
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Adding plugin upnp to MyMusic Plugins
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Adding plugin airplay_emulation to MyMusic Plugins
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Adding plugin upnp_browser to MyMusic Plugins
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Loading plugins from folder /data/plugins/
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Loading plugin "system"...
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Loading plugin "appearance"...
Jul 23 10:42:38 volumio-principal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 23 10:42:38 volumio-principal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Jul 23 10:42:38 volumio-principal systemd[1]: Stopped go-librespot Daemon.
Jul 23 10:42:38 volumio-principal systemd[1]: Started go-librespot Daemon.
Jul 23 10:42:38 volumio-principal go-librespot[3244]: Librespot-go daemon starting...
Jul 23 10:42:38 volumio-principal go-librespot[3244]: time="2024-07-23T10:42:38+02:00" level=info msg="generated new device id: 92d4bec9e60fb274095113ee2ef315a084865e09"
Jul 23 10:42:38 volumio-principal go-librespot[3244]: time="2024-07-23T10:42:38+02:00" level=debug msg="stored credentials found for gcerruela"
Jul 23 10:42:38 volumio-principal go-librespot[3244]: time="2024-07-23T10:42:38+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy"
Jul 23 10:42:38 volumio-principal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 23 10:42:38 volumio-principal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Loading plugin "network"...
Jul 23 10:42:38 volumio-principal volumio[3222]: info: Refreshing Cached IP Addresses
Jul 23 10:42:39 volumio-principal sudo[3253]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Jul 23 10:42:39 volumio-principal sudo[3253]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:39 volumio-principal sudo[3253]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:39 volumio-principal sudo[3255]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jul 23 10:42:39 volumio-principal volumio[3222]: info: Loading plugin "services"...
Jul 23 10:42:39 volumio-principal sudo[3255]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:39 volumio-principal volumio[3222]: info: Loading plugin "alsa_controller"...
Jul 23 10:42:39 volumio-principal sudo[3255]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:39 volumio-principal sudo[3258]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Jul 23 10:42:39 volumio-principal sudo[3258]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:39 volumio-principal sudo[3258]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:39 volumio-principal kernel: ieee80211 phy0: brcmf_cfg80211_scan: Connecting: status (3)
Jul 23 10:42:39 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jul 23 10:42:39 volumio-principal volumio[3222]: info: Loading plugin "wizard"...
Jul 23 10:42:39 volumio-principal volumio[3222]: info: Loading plugin "volumio_command_line_client"...
Jul 23 10:42:39 volumio-principal volumio[3222]: info: Loading plugin "upnp"...
Jul 23 10:42:39 volumio-principal volumio[3222]: info: [1721724159146] Starting Upmpd Daemon
Jul 23 10:42:39 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jul 23 10:42:39 volumio-principal volumio[3222]: info: Loading plugin "my_music"...
Jul 23 10:42:39 volumio-principal volumio[3222]: info: Loading plugin "mpd"...
Jul 23 10:42:39 volumio-principal squeezeboxserver[3179]: [24-07-23 10:42:37.8843] main::init (377) Starting Logitech Media Server (v8.3.1, 1676361197, Fri 17 Feb 2023 06:39:27 AM CET) perl 5.028001 - arm-linux-gnueabihf-thread-multi-64int
Jul 23 10:42:39 volumio-principal squeezeboxserver[3179]: [24-07-23 10:42:38.2650] Slim::Utils::IPDetect::_init (138) Warning: Couldn't call connect() - falling back to 127.0.0.1
Jul 23 10:42:39 volumio-principal volumio[3222]: info: Creating MPD Configuration file
Jul 23 10:42:39 volumio-principal sudo[3268]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Jul 23 10:42:39 volumio-principal sudo[3268]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:39 volumio-principal volumio[3222]: info: Loading plugin "upnp_browser"...
Jul 23 10:42:39 volumio-principal sudo[3268]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:39 volumio-principal sudo[3270]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Jul 23 10:42:39 volumio-principal sudo[3270]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:39 volumio-principal systemd[1]: Stopping Music Player Daemon...
Jul 23 10:42:39 volumio-principal systemd[1]: mpd.service: Succeeded.
Jul 23 10:42:39 volumio-principal systemd[1]: Stopped Music Player Daemon.
Jul 23 10:42:39 volumio-principal systemd[1]: Starting Music Player Daemon...
Jul 23 10:42:39 volumio-principal volumio[3222]: info: Loading plugin "networkfs"...
Jul 23 10:42:39 volumio-principal volumio[3222]: info: Starting Udev Watcher for removable devices
Jul 23 10:42:40 volumio-principal volumio[3222]: info: Ignoring mount for partition: boot
Jul 23 10:42:40 volumio-principal volumio[3222]: info: Ignoring mount for partition: volumio
Jul 23 10:42:40 volumio-principal volumio[3222]: info: Ignoring mount for partition: volumio_data
Jul 23 10:42:40 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jul 23 10:42:40 volumio-principal volumio[3222]: info: Loading plugin "alarm-clock"...
Jul 23 10:42:40 volumio-principal volumio[3222]: info: Loading plugin "airplay_emulation"...
Jul 23 10:42:40 volumio-principal volumio[3222]: info: Starting Shairport Sync
Jul 23 10:42:40 volumio-principal volumio[3222]: info: Loading plugin "last_100"...
Jul 23 10:42:40 volumio-principal wpa_supplicant[758]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16
Jul 23 10:42:40 volumio-principal volumio[3222]: info: Loading plugin "webradio"...
Jul 23 10:42:40 volumio-principal wpa_supplicant[758]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="devolo-961" auth_failures=1 duration=10 reason=CONN_FAILED
Jul 23 10:42:40 volumio-principal mpd[3275]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Jul 23 10:42:40 volumio-principal mpd[3275]: output: No 'audio_output' defined in config file
Jul 23 10:42:40 volumio-principal mpd[3275]: output: Attempt to detect audio output device
Jul 23 10:42:40 volumio-principal mpd[3275]: output: Attempting to detect a alsa audio device
Jul 23 10:42:40 volumio-principal mpd[3275]: output: Successfully detected a alsa audio device
Jul 23 10:42:40 volumio-principal mpd[3275]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured
Jul 23 10:42:40 volumio-principal mpd[3275]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured
Jul 23 10:42:40 volumio-principal mpd[3275]: zeroconf: No global port, disabling zeroconf
Jul 23 10:42:40 volumio-principal systemd[1]: Started Music Player Daemon.
Jul 23 10:42:40 volumio-principal sudo[3270]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:40 volumio-principal volumio[3222]: info: Loading plugin "i2s_dacs"...
Jul 23 10:42:40 volumio-principal volumio[3222]: info: Loading plugin "volumiodiscovery"...
Jul 23 10:42:40 volumio-principal volumio[3222]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Jul 23 10:42:40 volumio-principal node[3222]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Jul 23 10:42:40 volumio-principal volumio[3222]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jul 23 10:42:40 volumio-principal node[3222]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jul 23 10:42:40 volumio-principal volumio[3222]: *** WARNING *** For more information see
Jul 23 10:42:40 volumio-principal node[3222]: *** WARNING *** For more information see
Jul 23 10:42:40 volumio-principal volumio[3222]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Jul 23 10:42:40 volumio-principal node[3222]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Jul 23 10:42:40 volumio-principal volumio[3222]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jul 23 10:42:40 volumio-principal node[3222]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jul 23 10:42:40 volumio-principal volumio[3222]: *** WARNING *** For more information see
Jul 23 10:42:40 volumio-principal node[3222]: *** WARNING *** For more information see
Jul 23 10:42:40 volumio-principal volumio[3222]: info: Applying required configuration parameters for plugin volumiodiscovery
Jul 23 10:42:40 volumio-principal volumio[3222]: info: Discovery: Started advertising with name: Volumio-Principal
Jul 23 10:42:40 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jul 23 10:42:40 volumio-principal volumio[3222]: info: Loading plugin "spop"...
Jul 23 10:42:40 volumio-principal volumio[3222]: info: Loading plugin "squeezelite_mc"...
Jul 23 10:42:41 volumio-principal volumio[3222]: info: Loading plugin "outputs"...
Jul 23 10:42:41 volumio-principal volumio[3222]: info: Loading plugin "albumart"...
Jul 23 10:42:41 volumio-principal volumio[3222]: info: Plugin example_plugin is not enabled
Jul 23 10:42:41 volumio-principal volumio[3222]: info: Loading plugin "inputs"...
Jul 23 10:42:41 volumio-principal volumio[3222]: info: Loading plugin "updater_comm"...
Jul 23 10:42:41 volumio-principal volumio-remote-updater[490]: [2024-07-23 10:42:41] [connect] Successful connection
Jul 23 10:42:41 volumio-principal volumio[3222]: info: Plugin mpdemulation is not enabled
Jul 23 10:42:41 volumio-principal volumio[3222]: info: Loading plugin "rest_api"...
Jul 23 10:42:41 volumio-principal volumio[3222]: info: Loading plugin "websocket"...
Jul 23 10:42:41 volumio-principal volumio[3222]: info: Loading plugin "lms"...
Jul 23 10:42:41 volumio-principal volumio[3222]: Forking 3 albumart workers
Jul 23 10:42:41 volumio-principal volumio[3222]: info: Loading i18n strings for locale es
Jul 23 10:42:41 volumio-principal volumio[3222]: Updating browse sources language
Jul 23 10:42:41 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 23 10:42:41 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 23 10:42:41 volumio-principal volumio[3222]: info: CoreCommandRouter::initPlayerControls
Jul 23 10:42:41 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:41 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:41 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:41 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:41 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:41 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:41 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:41 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:41 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 23 10:42:41 volumio-principal volumio[3222]: Express server listening on port 3000
Jul 23 10:42:41 volumio-principal volumio[3222]: [Metrics] WebUI: 4s 354.97ms
Jul 23 10:42:41 volumio-principal volumio[3222]: info: CoreStateMachine::resetVolumioState
Jul 23 10:42:41 volumio-principal volumio[3222]: info: CoreStateMachine::getcurrentVolume
Jul 23 10:42:41 volumio-principal volumio[3222]: info: CoreCommandRouter::volumioRetrievevolume
Jul 23 10:42:41 volumio-principal mpd[3275]: client: [0] opened from local
Jul 23 10:42:41 volumio-principal volumio[3222]: info: MPD Permissions set
Jul 23 10:42:41 volumio-principal volumio[3222]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan
Jul 23 10:42:41 volumio-principal volumio[3222]: wlan0 Interface doesn't support scanning : Resource temporarily unavailable
Jul 23 10:42:41 volumio-principal volumio[3222]: info: Cannot use regular scanning, forcing with ap-force
Jul 23 10:42:41 volumio-principal sudo[3316]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force
Jul 23 10:42:41 volumio-principal sudo[3316]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:42 volumio-principal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 23 10:42:42 volumio-principal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Jul 23 10:42:42 volumio-principal systemd[1]: Stopped go-librespot Daemon.
Jul 23 10:42:42 volumio-principal systemd[1]: Started go-librespot Daemon.
Jul 23 10:42:42 volumio-principal go-librespot[3318]: Librespot-go daemon starting...
Jul 23 10:42:42 volumio-principal go-librespot[3318]: time="2024-07-23T10:42:42+02:00" level=info msg="generated new device id: d0e0d4fe00c7ca985510076578046009bab94a4a"
Jul 23 10:42:42 volumio-principal go-librespot[3318]: time="2024-07-23T10:42:42+02:00" level=debug msg="stored credentials found for gcerruela"
Jul 23 10:42:42 volumio-principal go-librespot[3318]: time="2024-07-23T10:42:42+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy"
Jul 23 10:42:42 volumio-principal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 23 10:42:42 volumio-principal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 23 10:42:42 volumio-principal volumio[3222]: Starting albumart workers
Jul 23 10:42:42 volumio-principal volumio[3222]: Starting albumart workers
Jul 23 10:42:42 volumio-principal volumio[3222]: Starting albumart workers
Jul 23 10:42:44 volumio-principal sudo[3316]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:44 volumio-principal volumio-remote-updater[490]: [2024-07-23 10:42:44] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1721724161 101
Jul 23 10:42:44 volumio-principal volumio[3222]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 1
Jul 23 10:42:44 volumio-principal volumio[3222]: info: MPD running with PID3275
Jul 23 10:42:44 volumio-principal volumio[3222]: ,establishing connection
Jul 23 10:42:44 volumio-principal mpd[3275]: client: [1] opened from local
Jul 23 10:42:44 volumio-principal volumio[3222]: error: MPD error: The expression evaluated to a falsy value:
Jul 23 10:42:44 volumio-principal volumio[3222]: assert.ok(self.idling)
Jul 23 10:42:44 volumio-principal volumio[3222]: error: The expression evaluated to a falsy value:
Jul 23 10:42:44 volumio-principal volumio[3222]: assert.ok(self.idling)
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:44 volumio-principal volumio[3222]: info: Reloading queue from file
Jul 23 10:42:44 volumio-principal volumio[3222]: info: VolumeController:: Volume=43 Mute =false
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreStateMachine::pushState
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CorePlayQueue::getTrack 0
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreCommandRouter::volumioPushState
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreStateMachine::updateTrackBlock
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CorePlayQueue::getTrackBlock
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreCommandRouter::volumioRetrievevolume
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreStateMachine::setRepeat null single undefined
Jul 23 10:42:44 volumio-principal volumio[3222]: info: CoreStateMachine::pushState
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CorePlayQueue::getTrack 0
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::volumioPushState
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreStateMachine::setRandom null
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreStateMachine::pushState
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CorePlayQueue::getTrack 0
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::volumioPushState
Jul 23 10:42:45 volumio-principal volumio[3222]: error: updateQueue error: null
Jul 23 10:42:45 volumio-principal volumio[3222]: info: Setting Device type: Raspberry PI
Jul 23 10:42:45 volumio-principal volumio[3222]: info: Completed loading Core Plugins
Jul 23 10:42:45 volumio-principal volumio[3222]: info: Preparing to generate the ALSA configuration file
Jul 23 10:42:45 volumio-principal volumio[3222]: info: Asound.conf file unchanged, so no further update is needed
Jul 23 10:42:45 volumio-principal volumio[3222]: info: Output device has changed, restarting MPD
Jul 23 10:42:45 volumio-principal sudo[3361]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Jul 23 10:42:45 volumio-principal sudo[3361]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:45 volumio-principal volumio[3222]: info: Output device has changed, restarting Shairport Sync
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:45 volumio-principal sudo[3361]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:45 volumio-principal sudo[3364]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Jul 23 10:42:45 volumio-principal sudo[3364]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:45 volumio-principal systemd[1]: Stopping Music Player Daemon...
Jul 23 10:42:45 volumio-principal volumio[3222]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jul 23 10:42:45 volumio-principal systemd[1]: mpd.service: Succeeded.
Jul 23 10:42:45 volumio-principal volumio[3222]: info: ___________ START PLUGINS ___________
Jul 23 10:42:45 volumio-principal systemd[1]: Stopped Music Player Daemon.
Jul 23 10:42:45 volumio-principal systemd[1]: Starting Music Player Daemon...
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jul 23 10:42:45 volumio-principal volumio[3222]: info: [1721724165144] CoreMusicLibrary::Adding element Media Servers
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:45 volumio-principal volumio[3222]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:45 volumio-principal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 23 10:42:45 volumio-principal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Jul 23 10:42:45 volumio-principal systemd[1]: Stopped go-librespot Daemon.
Jul 23 10:42:45 volumio-principal systemd[1]: Started go-librespot Daemon.
Jul 23 10:42:45 volumio-principal go-librespot[3375]: Librespot-go daemon starting...
Jul 23 10:42:45 volumio-principal go-librespot[3375]: time="2024-07-23T10:42:45+02:00" level=info msg="generated new device id: ae89c83bdbd4d03879a12ec11f1e5ec1bf42c937"
Jul 23 10:42:45 volumio-principal go-librespot[3375]: time="2024-07-23T10:42:45+02:00" level=debug msg="stored credentials found for gcerruela"
Jul 23 10:42:45 volumio-principal volumio[3222]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jul 23 10:42:45 volumio-principal volumio[3222]: info: [1721724165245] CoreMusicLibrary::Adding element Last_100
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 23 10:42:45 volumio-principal go-librespot[3375]: time="2024-07-23T10:42:45+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy"
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jul 23 10:42:45 volumio-principal volumio[3222]: info: [1721724165248] CoreMusicLibrary::Adding element Webradio
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 23 10:42:45 volumio-principal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 23 10:42:45 volumio-principal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jul 23 10:42:45 volumio-principal volumio[3222]: info: Creating Spotify config file
Jul 23 10:42:45 volumio-principal volumio[3222]: info: [squeezelite_mc] Starting proxy server...
Jul 23 10:42:45 volumio-principal volumio[3222]: info: Volumio Calling Home
Jul 23 10:42:45 volumio-principal sudo[3386]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver
Jul 23 10:42:45 volumio-principal sudo[3386]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:45 volumio-principal systemd[1]: Stopping Logitech Media Server Daemon...
Jul 23 10:42:45 volumio-principal volumio[3222]: info: [squeezelite_mc] Proxy server started on port 46251
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::volumioRetrievevolume
Jul 23 10:42:45 volumio-principal volumio[3222]: Unhandled rejection Error: No sockets available, cannot start.
Jul 23 10:42:45 volumio-principal volumio[3222]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11)
Jul 23 10:42:45 volumio-principal volumio[3222]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10)
Jul 23 10:42:45 volumio-principal volumio[3222]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10
Jul 23 10:42:45 volumio-principal volumio[3222]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9)
Jul 23 10:42:45 volumio-principal volumio[3222]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18)
Jul 23 10:42:45 volumio-principal volumio[3222]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10)
Jul 23 10:42:45 volumio-principal volumio[3222]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10)
Jul 23 10:42:45 volumio-principal volumio[3222]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17)
Jul 23 10:42:45 volumio-principal volumio[3222]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12)
Jul 23 10:42:45 volumio-principal volumio[3222]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24)
Jul 23 10:42:45 volumio-principal volumio[3222]: at HashMap. (/volumio/app/pluginmanager.js:496:31)
Jul 23 10:42:45 volumio-principal volumio[3222]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10)
Jul 23 10:42:45 volumio-principal volumio[3222]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7)
Jul 23 10:42:45 volumio-principal volumio[3222]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20)
Jul 23 10:42:45 volumio-principal volumio[3222]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29)
Jul 23 10:42:45 volumio-principal volumio[3222]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)
Jul 23 10:42:45 volumio-principal volumio[3222]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.dfs.volumio.org
Jul 23 10:42:45 volumio-principal volumio[3222]: info: MPD Permissions set
Jul 23 10:42:45 volumio-principal volumio[3222]: info: VolumeController:: Volume=43 Mute =false
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreStateMachine::pushState
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CorePlayQueue::getTrack 0
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::volumioPushState
Jul 23 10:42:45 volumio-principal volumio[3222]: info: Spotify config file written
Jul 23 10:42:45 volumio-principal systemd[1]: logitechmediaserver.service: Succeeded.
Jul 23 10:42:45 volumio-principal systemd[1]: Stopped Logitech Media Server Daemon.
Jul 23 10:42:45 volumio-principal systemd[1]: Starting Logitech Media Server Daemon...
Jul 23 10:42:45 volumio-principal volumio[3222]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:45 volumio-principal sudo[3395]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:45 volumio-principal sudo[3395]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:45 volumio-principal systemd[1]: Started Logitech Media Server Daemon.
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:45 volumio-principal systemd[1]: Stopped go-librespot Daemon.
Jul 23 10:42:45 volumio-principal systemd[1]: Started go-librespot Daemon.
Jul 23 10:42:45 volumio-principal sudo[3386]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:45 volumio-principal go-librespot[3403]: Librespot-go daemon starting...
Jul 23 10:42:45 volumio-principal sudo[3395]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:45 volumio-principal volumio[3222]: info: VolumeController:: Volume=43 Mute =false
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreStateMachine::pushState
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CorePlayQueue::getTrack 0
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::volumioPushState
Jul 23 10:42:45 volumio-principal volumio[3222]: info: [squeezelite_mc] Server discovery started
Jul 23 10:42:45 volumio-principal volumio[3222]: info: [squeezelite_mc] Player finder started
Jul 23 10:42:45 volumio-principal go-librespot[3403]: time="2024-07-23T10:42:45+02:00" level=info msg="generated new device id: 57ed7c53f1d2744bc3f5afcbe48a62d4d48268b3"
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:45 volumio-principal volumio[3222]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 23 10:42:45 volumio-principal go-librespot[3403]: time="2024-07-23T10:42:45+02:00" level=debug msg="stored credentials found for gcerruela"
Jul 23 10:42:45 volumio-principal volumio[3222]: info: [squeezelite_mc] Executing aplay -D hw:2 --nonblock -f MPEG /dev/zero 2>&1 || true
Jul 23 10:42:45 volumio-principal go-librespot[3403]: time="2024-07-23T10:42:45+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy"
Jul 23 10:42:45 volumio-principal volumio[3222]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 23 10:42:45 volumio-principal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 23 10:42:45 volumio-principal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 23 10:42:45 volumio-principal volumio[3222]: Error: send ENETUNREACH 255.255.255.255:3483
Jul 23 10:42:45 volumio-principal volumio[3222]: at doSend (dgram.js:692:16)
Jul 23 10:42:45 volumio-principal volumio[3222]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12)
Jul 23 10:42:45 volumio-principal volumio[3222]: at afterDns (dgram.js:638:5)
Jul 23 10:42:45 volumio-principal volumio[3222]: at processTicksAndRejections (internal/process/task_queues.js:81:21) {
Jul 23 10:42:45 volumio-principal volumio[3222]: errno: -101,
Jul 23 10:42:45 volumio-principal volumio[3222]: code: 'ENETUNREACH',
Jul 23 10:42:45 volumio-principal volumio[3222]: syscall: 'send',
Jul 23 10:42:45 volumio-principal volumio[3222]: address: '255.255.255.255',
Jul 23 10:42:45 volumio-principal volumio[3222]: port: 3483
Jul 23 10:42:45 volumio-principal volumio[3222]: }
Jul 23 10:42:45 volumio-principal volumio[3222]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 23 10:42:45 volumio-principal mpd[3384]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Jul 23 10:42:45 volumio-principal mpd[3384]: output: No 'audio_output' defined in config file
Jul 23 10:42:45 volumio-principal mpd[3384]: output: Attempt to detect audio output device
Jul 23 10:42:45 volumio-principal mpd[3384]: output: Attempting to detect a alsa audio device
Jul 23 10:42:46 volumio-principal mpd[3384]: output: Successfully detected a alsa audio device
Jul 23 10:42:46 volumio-principal mpd[3384]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured
Jul 23 10:42:46 volumio-principal mpd[3384]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured
Jul 23 10:42:46 volumio-principal mpd[3384]: zeroconf: No global port, disabling zeroconf
Jul 23 10:42:46 volumio-principal systemd[1]: Started Music Player Daemon.
Jul 23 10:42:46 volumio-principal sudo[3364]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:46 volumio-principal sudo[3423]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-23 10:41
Jul 23 10:42:46 volumio-principal sudo[3423]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:46 volumio-principal sudo[3423]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:46 volumio-principal volumio-remote-updater[490]: [2024-07-23 10:42:46] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Jul 23 10:42:46 volumio-principal volumio-remote-updater[490]: [2024-07-23 10:42:46] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Jul 23 10:42:46 volumio-principal systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Jul 23 10:42:46 volumio-principal systemd[1]: volumio.service: Failed with result 'exit-code'.
Jul 23 10:42:46 volumio-principal systemd[1]: Started dynamicswap service.
Jul 23 10:42:46 volumio-principal systemd[1]: dynamicswap.service: Succeeded.
Jul 23 10:42:46 volumio-principal systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart.
Jul 23 10:42:46 volumio-principal systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9.
Jul 23 10:42:46 volumio-principal systemd[1]: Started dynamicswap service.
Jul 23 10:42:46 volumio-principal systemd[1]: Stopped Volumio Backend Module.
Jul 23 10:42:46 volumio-principal systemd[1]: Started Volumio Backend Module.
Jul 23 10:42:46 volumio-principal systemd[1]: dynamicswap.service: Succeeded.
Jul 23 10:42:47 volumio-principal volumio[3437]: info: -------------------------------------------
Jul 23 10:42:47 volumio-principal volumio[3437]: info: ----- Volumio3 ----
Jul 23 10:42:47 volumio-principal volumio[3437]: info: -------------------------------------------
Jul 23 10:42:47 volumio-principal volumio[3437]: info: ----- System startup ----
Jul 23 10:42:47 volumio-principal volumio[3437]: info: -------------------------------------------
Jul 23 10:42:48 volumio-principal volumio[3437]: info: MYVOLUMIO Environment detected
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Plugin folders cleanup
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Scanning into folder /volumio/app/plugins/
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Scanning category audio_interface
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Scanning category miscellanea
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Scanning category music_service
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Scanning category plugins.json
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Scanning category system_controller
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Scanning category user_interface
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Scanning into folder /data/plugins/
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Scanning category music_service
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Plugin folders cleanup completed
Jul 23 10:42:48 volumio-principal volumio[3437]: info: -------------------------------------------
Jul 23 10:42:48 volumio-principal volumio[3437]: info: ----- Core plugins startup ----
Jul 23 10:42:48 volumio-principal volumio[3437]: info: -------------------------------------------
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Loading plugins from folder /volumio/app/plugins/
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Adding plugin upnp to MyMusic Plugins
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Adding plugin airplay_emulation to MyMusic Plugins
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Adding plugin upnp_browser to MyMusic Plugins
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Loading plugins from folder /data/plugins/
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Loading plugin "system"...
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Loading plugin "appearance"...
Jul 23 10:42:48 volumio-principal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 23 10:42:48 volumio-principal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Jul 23 10:42:48 volumio-principal systemd[1]: Stopped go-librespot Daemon.
Jul 23 10:42:48 volumio-principal systemd[1]: Started go-librespot Daemon.
Jul 23 10:42:48 volumio-principal go-librespot[3459]: Librespot-go daemon starting...
Jul 23 10:42:48 volumio-principal go-librespot[3459]: time="2024-07-23T10:42:48+02:00" level=info msg="generated new device id: c1d6ba25b2bbf9fb5302c6d53d9ce3f5cd214284"
Jul 23 10:42:48 volumio-principal go-librespot[3459]: time="2024-07-23T10:42:48+02:00" level=debug msg="stored credentials found for gcerruela"
Jul 23 10:42:48 volumio-principal go-librespot[3459]: time="2024-07-23T10:42:48+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy"
Jul 23 10:42:48 volumio-principal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 23 10:42:48 volumio-principal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Loading plugin "network"...
Jul 23 10:42:48 volumio-principal volumio[3437]: info: Refreshing Cached IP Addresses
Jul 23 10:42:49 volumio-principal sudo[3467]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Jul 23 10:42:49 volumio-principal sudo[3467]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:49 volumio-principal sudo[3467]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:49 volumio-principal sudo[3469]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jul 23 10:42:49 volumio-principal volumio[3437]: info: Loading plugin "services"...
Jul 23 10:42:49 volumio-principal sudo[3469]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:49 volumio-principal volumio[3437]: info: Loading plugin "alsa_controller"...
Jul 23 10:42:49 volumio-principal sudo[3469]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:49 volumio-principal sudo[3473]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Jul 23 10:42:49 volumio-principal sudo[3473]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:49 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jul 23 10:42:49 volumio-principal volumio[3437]: info: Loading plugin "wizard"...
Jul 23 10:42:49 volumio-principal volumio[3437]: info: Loading plugin "volumio_command_line_client"...
Jul 23 10:42:49 volumio-principal volumio[3437]: info: Loading plugin "upnp"...
Jul 23 10:42:49 volumio-principal volumio[3437]: info: [1721724169142] Starting Upmpd Daemon
Jul 23 10:42:49 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jul 23 10:42:49 volumio-principal volumio[3437]: info: Loading plugin "my_music"...
Jul 23 10:42:49 volumio-principal volumio[3437]: info: Loading plugin "mpd"...
Jul 23 10:42:49 volumio-principal squeezeboxserver[3402]: [24-07-23 10:42:47.8346] main::init (377) Starting Logitech Media Server (v8.3.1, 1676361197, Fri 17 Feb 2023 06:39:27 AM CET) perl 5.028001 - arm-linux-gnueabihf-thread-multi-64int
Jul 23 10:42:49 volumio-principal squeezeboxserver[3402]: [24-07-23 10:42:48.2191] Slim::Utils::IPDetect::_init (138) Warning: Couldn't call connect() - falling back to 127.0.0.1
Jul 23 10:42:49 volumio-principal volumio[3437]: info: Creating MPD Configuration file
Jul 23 10:42:49 volumio-principal volumio[3437]: info: Loading plugin "upnp_browser"...
Jul 23 10:42:49 volumio-principal sudo[3482]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Jul 23 10:42:49 volumio-principal sudo[3482]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:49 volumio-principal sudo[3482]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:49 volumio-principal sudo[3484]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Jul 23 10:42:49 volumio-principal sudo[3484]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:49 volumio-principal systemd[1]: Stopping Music Player Daemon...
Jul 23 10:42:49 volumio-principal systemd[1]: mpd.service: Succeeded.
Jul 23 10:42:49 volumio-principal systemd[1]: Stopped Music Player Daemon.
Jul 23 10:42:49 volumio-principal systemd[1]: Starting Music Player Daemon...
Jul 23 10:42:49 volumio-principal volumio[3437]: info: Loading plugin "networkfs"...
Jul 23 10:42:49 volumio-principal volumio[3437]: info: Starting Udev Watcher for removable devices
Jul 23 10:42:49 volumio-principal wpa_supplicant[758]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="devolo-961"
Jul 23 10:42:49 volumio-principal wpa_supplicant[758]: wlan0: Failed to initiate sched scan
Jul 23 10:42:50 volumio-principal volumio[3437]: info: Ignoring mount for partition: boot
Jul 23 10:42:50 volumio-principal volumio[3437]: info: Ignoring mount for partition: volumio
Jul 23 10:42:50 volumio-principal volumio[3437]: info: Ignoring mount for partition: volumio_data
Jul 23 10:42:50 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jul 23 10:42:50 volumio-principal volumio[3437]: info: Loading plugin "alarm-clock"...
Jul 23 10:42:50 volumio-principal volumio[3437]: info: Loading plugin "airplay_emulation"...
Jul 23 10:42:50 volumio-principal volumio[3437]: info: Starting Shairport Sync
Jul 23 10:42:50 volumio-principal volumio[3437]: info: Loading plugin "last_100"...
Jul 23 10:42:50 volumio-principal volumio[3437]: info: Loading plugin "webradio"...
Jul 23 10:42:50 volumio-principal mpd[3489]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Jul 23 10:42:50 volumio-principal mpd[3489]: output: No 'audio_output' defined in config file
Jul 23 10:42:50 volumio-principal mpd[3489]: output: Attempt to detect audio output device
Jul 23 10:42:50 volumio-principal mpd[3489]: output: Attempting to detect a alsa audio device
Jul 23 10:42:50 volumio-principal mpd[3489]: output: Successfully detected a alsa audio device
Jul 23 10:42:50 volumio-principal mpd[3489]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured
Jul 23 10:42:50 volumio-principal mpd[3489]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured
Jul 23 10:42:50 volumio-principal mpd[3489]: zeroconf: No global port, disabling zeroconf
Jul 23 10:42:50 volumio-principal systemd[1]: Started Music Player Daemon.
Jul 23 10:42:50 volumio-principal sudo[3484]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:50 volumio-principal volumio[3437]: info: Loading plugin "i2s_dacs"...
Jul 23 10:42:50 volumio-principal volumio[3437]: info: Loading plugin "volumiodiscovery"...
Jul 23 10:42:50 volumio-principal volumio[3437]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Jul 23 10:42:50 volumio-principal volumio[3437]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jul 23 10:42:50 volumio-principal node[3437]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Jul 23 10:42:50 volumio-principal volumio[3437]: *** WARNING *** For more information see
Jul 23 10:42:50 volumio-principal volumio[3437]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Jul 23 10:42:50 volumio-principal volumio[3437]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jul 23 10:42:50 volumio-principal volumio[3437]: *** WARNING *** For more information see
Jul 23 10:42:50 volumio-principal node[3437]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jul 23 10:42:50 volumio-principal node[3437]: *** WARNING *** For more information see
Jul 23 10:42:50 volumio-principal node[3437]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Jul 23 10:42:50 volumio-principal node[3437]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jul 23 10:42:50 volumio-principal node[3437]: *** WARNING *** For more information see
Jul 23 10:42:50 volumio-principal volumio[3437]: info: Applying required configuration parameters for plugin volumiodiscovery
Jul 23 10:42:50 volumio-principal volumio[3437]: info: Discovery: Started advertising with name: Volumio-Principal
Jul 23 10:42:50 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jul 23 10:42:50 volumio-principal volumio[3437]: info: Loading plugin "spop"...
Jul 23 10:42:50 volumio-principal volumio[3437]: info: Loading plugin "squeezelite_mc"...
Jul 23 10:42:51 volumio-principal volumio-remote-updater[490]: [2024-07-23 10:42:51] [connect] Successful connection
Jul 23 10:42:51 volumio-principal volumio[3437]: info: Loading plugin "outputs"...
Jul 23 10:42:51 volumio-principal volumio[3437]: info: Loading plugin "albumart"...
Jul 23 10:42:51 volumio-principal volumio[3437]: info: Plugin example_plugin is not enabled
Jul 23 10:42:51 volumio-principal volumio[3437]: info: Loading plugin "inputs"...
Jul 23 10:42:51 volumio-principal volumio[3437]: info: Loading plugin "updater_comm"...
Jul 23 10:42:51 volumio-principal volumio[3437]: info: Plugin mpdemulation is not enabled
Jul 23 10:42:51 volumio-principal volumio[3437]: info: Loading plugin "rest_api"...
Jul 23 10:42:51 volumio-principal volumio[3437]: info: Loading plugin "websocket"...
Jul 23 10:42:51 volumio-principal volumio[3437]: info: Loading plugin "lms"...
Jul 23 10:42:51 volumio-principal volumio[3437]: Forking 3 albumart workers
Jul 23 10:42:51 volumio-principal volumio[3437]: info: Loading i18n strings for locale es
Jul 23 10:42:51 volumio-principal volumio[3437]: Updating browse sources language
Jul 23 10:42:51 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 23 10:42:51 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 23 10:42:51 volumio-principal volumio[3437]: info: CoreCommandRouter::initPlayerControls
Jul 23 10:42:51 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:51 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:51 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:51 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:51 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:51 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:51 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:51 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:51 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 23 10:42:51 volumio-principal volumio[3437]: Express server listening on port 3000
Jul 23 10:42:51 volumio-principal volumio[3437]: [Metrics] WebUI: 4s 376.92ms
Jul 23 10:42:51 volumio-principal volumio[3437]: info: CoreStateMachine::resetVolumioState
Jul 23 10:42:51 volumio-principal volumio[3437]: info: CoreStateMachine::getcurrentVolume
Jul 23 10:42:51 volumio-principal volumio[3437]: info: CoreCommandRouter::volumioRetrievevolume
Jul 23 10:42:51 volumio-principal mpd[3489]: client: [0] opened from local
Jul 23 10:42:51 volumio-principal volumio[3437]: info: MPD Permissions set
Jul 23 10:42:51 volumio-principal volumio-remote-updater[490]: [2024-07-23 10:42:51] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1721724171 101
Jul 23 10:42:51 volumio-principal volumio[3437]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 1
Jul 23 10:42:51 volumio-principal volumio[3437]: info: MPD running with PID3489
Jul 23 10:42:51 volumio-principal volumio[3437]: ,establishing connection
Jul 23 10:42:51 volumio-principal mpd[3489]: client: [1] opened from local
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:52 volumio-principal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 23 10:42:52 volumio-principal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Jul 23 10:42:52 volumio-principal systemd[1]: Stopped go-librespot Daemon.
Jul 23 10:42:52 volumio-principal systemd[1]: Started go-librespot Daemon.
Jul 23 10:42:52 volumio-principal go-librespot[3538]: Librespot-go daemon starting...
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:52 volumio-principal volumio[3437]: info: Reloading queue from file
Jul 23 10:42:52 volumio-principal volumio[3437]: error: updateQueue error: null
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreStateMachine::setRepeat null single undefined
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreStateMachine::pushState
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CorePlayQueue::getTrack 0
Jul 23 10:42:52 volumio-principal go-librespot[3538]: time="2024-07-23T10:42:52+02:00" level=info msg="generated new device id: a254bafd0bd89cf97f1f42e1206f9732830a526e"
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 23 10:42:52 volumio-principal go-librespot[3538]: time="2024-07-23T10:42:52+02:00" level=debug msg="stored credentials found for gcerruela"
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::volumioPushState
Jul 23 10:42:52 volumio-principal go-librespot[3538]: time="2024-07-23T10:42:52+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy"
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreStateMachine::setRandom null
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreStateMachine::pushState
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CorePlayQueue::getTrack 0
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::volumioPushState
Jul 23 10:42:52 volumio-principal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 23 10:42:52 volumio-principal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 23 10:42:52 volumio-principal volumio[3437]: info: Setting Device type: Raspberry PI
Jul 23 10:42:52 volumio-principal volumio[3437]: info: Completed loading Core Plugins
Jul 23 10:42:52 volumio-principal volumio[3437]: info: Preparing to generate the ALSA configuration file
Jul 23 10:42:52 volumio-principal volumio[3437]: info: VolumeController:: Volume=43 Mute =false
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreStateMachine::pushState
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CorePlayQueue::getTrack 0
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::volumioPushState
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreStateMachine::updateTrackBlock
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CorePlayQueue::getTrackBlock
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::volumioRetrievevolume
Jul 23 10:42:52 volumio-principal volumio[3437]: Starting albumart workers
Jul 23 10:42:52 volumio-principal volumio[3437]: Starting albumart workers
Jul 23 10:42:52 volumio-principal volumio[3437]: error: updateQueue error: null
Jul 23 10:42:52 volumio-principal volumio[3437]: info: Asound.conf file unchanged, so no further update is needed
Jul 23 10:42:52 volumio-principal volumio[3437]: info: Output device has changed, restarting MPD
Jul 23 10:42:52 volumio-principal volumio[3437]: Starting albumart workers
Jul 23 10:42:52 volumio-principal volumio[3437]: info: Output device has changed, restarting Shairport Sync
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:52 volumio-principal sudo[3546]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Jul 23 10:42:52 volumio-principal sudo[3546]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:52 volumio-principal sudo[3546]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:52 volumio-principal sudo[3549]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Jul 23 10:42:52 volumio-principal sudo[3549]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:52 volumio-principal volumio[3437]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jul 23 10:42:52 volumio-principal volumio[3437]: info: ___________ START PLUGINS ___________
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jul 23 10:42:52 volumio-principal volumio[3437]: info: [1721724172331] CoreMusicLibrary::Adding element Media Servers
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 23 10:42:52 volumio-principal systemd[1]: Stopping Music Player Daemon...
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:52 volumio-principal systemd[1]: mpd.service: Succeeded.
Jul 23 10:42:52 volumio-principal systemd[1]: Stopped Music Player Daemon.
Jul 23 10:42:52 volumio-principal systemd[1]: Starting Music Player Daemon...
Jul 23 10:42:52 volumio-principal volumio[3437]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:52 volumio-principal volumio[3437]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jul 23 10:42:52 volumio-principal volumio[3437]: info: [1721724172490] CoreMusicLibrary::Adding element Last_100
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jul 23 10:42:52 volumio-principal volumio[3437]: info: [1721724172495] CoreMusicLibrary::Adding element Webradio
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jul 23 10:42:52 volumio-principal volumio[3437]: info: Creating Spotify config file
Jul 23 10:42:52 volumio-principal volumio[3437]: info: [squeezelite_mc] Starting proxy server...
Jul 23 10:42:52 volumio-principal volumio[3437]: info: Volumio Calling Home
Jul 23 10:42:52 volumio-principal sudo[3580]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver
Jul 23 10:42:52 volumio-principal sudo[3580]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:52 volumio-principal systemd[1]: Stopping Logitech Media Server Daemon...
Jul 23 10:42:52 volumio-principal volumio[3437]: info: [squeezelite_mc] Proxy server started on port 41687
Jul 23 10:42:52 volumio-principal volumio[3437]: info: CoreCommandRouter::volumioRetrievevolume
Jul 23 10:42:52 volumio-principal volumio[3437]: Unhandled rejection Error: No sockets available, cannot start.
Jul 23 10:42:52 volumio-principal volumio[3437]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11)
Jul 23 10:42:52 volumio-principal volumio[3437]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10)
Jul 23 10:42:52 volumio-principal volumio[3437]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10
Jul 23 10:42:52 volumio-principal volumio[3437]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9)
Jul 23 10:42:52 volumio-principal volumio[3437]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18)
Jul 23 10:42:52 volumio-principal volumio[3437]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10)
Jul 23 10:42:52 volumio-principal volumio[3437]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10)
Jul 23 10:42:52 volumio-principal volumio[3437]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17)
Jul 23 10:42:52 volumio-principal volumio[3437]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12)
Jul 23 10:42:52 volumio-principal volumio[3437]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24)
Jul 23 10:42:52 volumio-principal volumio[3437]: at HashMap. (/volumio/app/pluginmanager.js:496:31)
Jul 23 10:42:52 volumio-principal volumio[3437]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10)
Jul 23 10:42:52 volumio-principal volumio[3437]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7)
Jul 23 10:42:52 volumio-principal volumio[3437]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20)
Jul 23 10:42:52 volumio-principal volumio[3437]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29)
Jul 23 10:42:52 volumio-principal volumio[3437]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)
Jul 23 10:42:52 volumio-principal volumio[3437]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.dfs.volumio.org
Jul 23 10:42:52 volumio-principal systemd[1]: logitechmediaserver.service: Succeeded.
Jul 23 10:42:52 volumio-principal systemd[1]: Stopped Logitech Media Server Daemon.
Jul 23 10:42:52 volumio-principal volumio[3437]: info: MPD Permissions set
Jul 23 10:42:52 volumio-principal systemd[1]: Starting Logitech Media Server Daemon...
Jul 23 10:42:52 volumio-principal systemd[1]: Started Logitech Media Server Daemon.
Jul 23 10:42:52 volumio-principal sudo[3580]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:52 volumio-principal volumio[3437]: info: Spotify config file written
Jul 23 10:42:53 volumio-principal sudo[3600]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Jul 23 10:42:53 volumio-principal sudo[3600]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:53 volumio-principal volumio[3437]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2
Jul 23 10:42:53 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:53 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:53 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:53 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:53 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:53 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:53 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:53 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:53 volumio-principal systemd[1]: Stopped go-librespot Daemon.
Jul 23 10:42:53 volumio-principal systemd[1]: Started go-librespot Daemon.
Jul 23 10:42:53 volumio-principal go-librespot[3603]: Librespot-go daemon starting...
Jul 23 10:42:53 volumio-principal sudo[3600]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:53 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:42:53 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:53 volumio-principal go-librespot[3603]: time="2024-07-23T10:42:53+02:00" level=info msg="generated new device id: ad99edf848212593e554d89821adcbaca8206814"
Jul 23 10:42:53 volumio-principal go-librespot[3603]: time="2024-07-23T10:42:53+02:00" level=debug msg="stored credentials found for gcerruela"
Jul 23 10:42:53 volumio-principal go-librespot[3603]: time="2024-07-23T10:42:53+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy"
Jul 23 10:42:53 volumio-principal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 23 10:42:53 volumio-principal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 23 10:42:53 volumio-principal volumio[3437]: info: VolumeController:: Volume=43 Mute =false
Jul 23 10:42:53 volumio-principal volumio[3437]: info: CoreStateMachine::pushState
Jul 23 10:42:53 volumio-principal volumio[3437]: info: CorePlayQueue::getTrack 0
Jul 23 10:42:53 volumio-principal volumio[3437]: info: CoreCommandRouter::volumioPushState
Jul 23 10:42:53 volumio-principal volumio[3437]: info: [squeezelite_mc] Server discovery started
Jul 23 10:42:53 volumio-principal volumio[3437]: info: [squeezelite_mc] Player finder started
Jul 23 10:42:53 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:53 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:53 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:53 volumio-principal volumio[3437]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 23 10:42:53 volumio-principal volumio[3437]: info: [squeezelite_mc] Executing aplay -D hw:2 --nonblock -f MPEG /dev/zero 2>&1 || true
Jul 23 10:42:53 volumio-principal volumio[3437]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 23 10:42:53 volumio-principal volumio[3437]: Error: send ENETUNREACH 255.255.255.255:3483
Jul 23 10:42:53 volumio-principal volumio[3437]: at doSend (dgram.js:692:16)
Jul 23 10:42:53 volumio-principal volumio[3437]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12)
Jul 23 10:42:53 volumio-principal volumio[3437]: at afterDns (dgram.js:638:5)
Jul 23 10:42:53 volumio-principal volumio[3437]: at processTicksAndRejections (internal/process/task_queues.js:81:21) {
Jul 23 10:42:53 volumio-principal volumio[3437]: errno: -101,
Jul 23 10:42:53 volumio-principal volumio[3437]: code: 'ENETUNREACH',
Jul 23 10:42:53 volumio-principal volumio[3437]: syscall: 'send',
Jul 23 10:42:53 volumio-principal volumio[3437]: address: '255.255.255.255',
Jul 23 10:42:53 volumio-principal volumio[3437]: port: 3483
Jul 23 10:42:53 volumio-principal volumio[3437]: }
Jul 23 10:42:53 volumio-principal volumio[3437]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 23 10:42:53 volumio-principal mpd[3562]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Jul 23 10:42:53 volumio-principal mpd[3562]: output: No 'audio_output' defined in config file
Jul 23 10:42:53 volumio-principal mpd[3562]: output: Attempt to detect audio output device
Jul 23 10:42:53 volumio-principal mpd[3562]: output: Attempting to detect a alsa audio device
Jul 23 10:42:53 volumio-principal mpd[3562]: output: Successfully detected a alsa audio device
Jul 23 10:42:53 volumio-principal mpd[3562]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured
Jul 23 10:42:53 volumio-principal mpd[3562]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured
Jul 23 10:42:53 volumio-principal mpd[3562]: zeroconf: No global port, disabling zeroconf
Jul 23 10:42:53 volumio-principal systemd[1]: Started Music Player Daemon.
Jul 23 10:42:53 volumio-principal sudo[3549]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:53 volumio-principal sudo[3627]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-23 10:41
Jul 23 10:42:53 volumio-principal sudo[3627]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:53 volumio-principal sudo[3627]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:53 volumio-principal volumio-remote-updater[490]: [2024-07-23 10:42:53] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Jul 23 10:42:53 volumio-principal volumio-remote-updater[490]: [2024-07-23 10:42:53] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Jul 23 10:42:53 volumio-principal systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Jul 23 10:42:53 volumio-principal sudo[3473]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:53 volumio-principal systemd[1]: volumio.service: Failed with result 'exit-code'.
Jul 23 10:42:53 volumio-principal systemd[1]: Started dynamicswap service.
Jul 23 10:42:53 volumio-principal systemd[1]: dynamicswap.service: Succeeded.
Jul 23 10:42:54 volumio-principal systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart.
Jul 23 10:42:54 volumio-principal systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10.
Jul 23 10:42:54 volumio-principal systemd[1]: Stopped Volumio Backend Module.
Jul 23 10:42:54 volumio-principal systemd[1]: Started Volumio Backend Module.
Jul 23 10:42:54 volumio-principal systemd[1]: Started dynamicswap service.
Jul 23 10:42:54 volumio-principal systemd[1]: dynamicswap.service: Succeeded.
Jul 23 10:42:54 volumio-principal wpa_supplicant[758]: wlan0: Trying to associate with SSID 'devolo-961'
Jul 23 10:42:55 volumio-principal volumio[3640]: info: -------------------------------------------
Jul 23 10:42:55 volumio-principal volumio[3640]: info: ----- Volumio3 ----
Jul 23 10:42:55 volumio-principal volumio[3640]: info: -------------------------------------------
Jul 23 10:42:55 volumio-principal volumio[3640]: info: ----- System startup ----
Jul 23 10:42:55 volumio-principal volumio[3640]: info: -------------------------------------------
Jul 23 10:42:55 volumio-principal volumio[3640]: info: MYVOLUMIO Environment detected
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Plugin folders cleanup
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Scanning into folder /volumio/app/plugins/
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Scanning category audio_interface
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Scanning category miscellanea
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Scanning category music_service
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Scanning category plugins.json
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Scanning category system_controller
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Scanning category user_interface
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Scanning into folder /data/plugins/
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Scanning category music_service
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Plugin folders cleanup completed
Jul 23 10:42:55 volumio-principal volumio[3640]: info: -------------------------------------------
Jul 23 10:42:55 volumio-principal volumio[3640]: info: ----- Core plugins startup ----
Jul 23 10:42:55 volumio-principal volumio[3640]: info: -------------------------------------------
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Loading plugins from folder /volumio/app/plugins/
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Adding plugin upnp to MyMusic Plugins
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Adding plugin airplay_emulation to MyMusic Plugins
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Adding plugin upnp_browser to MyMusic Plugins
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Loading plugins from folder /data/plugins/
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Loading plugin "system"...
Jul 23 10:42:55 volumio-principal volumio[3640]: info: Loading plugin "appearance"...
Jul 23 10:42:56 volumio-principal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 23 10:42:56 volumio-principal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Jul 23 10:42:56 volumio-principal systemd[1]: Stopped go-librespot Daemon.
Jul 23 10:42:56 volumio-principal systemd[1]: Started go-librespot Daemon.
Jul 23 10:42:56 volumio-principal go-librespot[3663]: Librespot-go daemon starting...
Jul 23 10:42:56 volumio-principal go-librespot[3663]: time="2024-07-23T10:42:56+02:00" level=info msg="generated new device id: a7d80877499e5e0ecdabbb45e10d02242f23125e"
Jul 23 10:42:56 volumio-principal go-librespot[3663]: time="2024-07-23T10:42:56+02:00" level=debug msg="stored credentials found for gcerruela"
Jul 23 10:42:56 volumio-principal go-librespot[3663]: time="2024-07-23T10:42:56+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy"
Jul 23 10:42:56 volumio-principal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 23 10:42:56 volumio-principal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 23 10:42:56 volumio-principal volumio[3640]: info: Loading plugin "network"...
Jul 23 10:42:56 volumio-principal volumio[3640]: info: Refreshing Cached IP Addresses
Jul 23 10:42:56 volumio-principal sudo[3672]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Jul 23 10:42:56 volumio-principal sudo[3672]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:56 volumio-principal sudo[3672]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:56 volumio-principal sudo[3674]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Jul 23 10:42:56 volumio-principal volumio[3640]: info: Loading plugin "services"...
Jul 23 10:42:56 volumio-principal sudo[3674]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:56 volumio-principal volumio[3640]: info: Loading plugin "alsa_controller"...
Jul 23 10:42:56 volumio-principal sudo[3674]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:56 volumio-principal sudo[3678]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Jul 23 10:42:56 volumio-principal sudo[3678]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:56 volumio-principal sudo[3678]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:56 volumio-principal kernel: ieee80211 phy0: brcmf_cfg80211_scan: Connecting: status (3)
Jul 23 10:42:56 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jul 23 10:42:56 volumio-principal volumio[3640]: info: Loading plugin "wizard"...
Jul 23 10:42:56 volumio-principal volumio[3640]: info: Loading plugin "volumio_command_line_client"...
Jul 23 10:42:56 volumio-principal volumio[3640]: info: Loading plugin "upnp"...
Jul 23 10:42:56 volumio-principal volumio[3640]: info: [1721724176612] Starting Upmpd Daemon
Jul 23 10:42:56 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jul 23 10:42:56 volumio-principal volumio[3640]: info: Loading plugin "my_music"...
Jul 23 10:42:56 volumio-principal volumio[3640]: info: Loading plugin "mpd"...
Jul 23 10:42:56 volumio-principal squeezeboxserver[3597]: [24-07-23 10:42:55.1840] main::init (377) Starting Logitech Media Server (v8.3.1, 1676361197, Fri 17 Feb 2023 06:39:27 AM CET) perl 5.028001 - arm-linux-gnueabihf-thread-multi-64int
Jul 23 10:42:56 volumio-principal squeezeboxserver[3597]: [24-07-23 10:42:55.5659] Slim::Utils::IPDetect::_init (138) Warning: Couldn't call connect() - falling back to 127.0.0.1
Jul 23 10:42:56 volumio-principal volumio[3640]: info: Creating MPD Configuration file
Jul 23 10:42:56 volumio-principal volumio[3640]: info: Loading plugin "upnp_browser"...
Jul 23 10:42:56 volumio-principal sudo[3687]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Jul 23 10:42:56 volumio-principal sudo[3687]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:56 volumio-principal sudo[3687]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:56 volumio-principal sudo[3689]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Jul 23 10:42:56 volumio-principal sudo[3689]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:56 volumio-principal systemd[1]: Stopping Music Player Daemon...
Jul 23 10:42:56 volumio-principal systemd[1]: mpd.service: Succeeded.
Jul 23 10:42:56 volumio-principal systemd[1]: Stopped Music Player Daemon.
Jul 23 10:42:56 volumio-principal systemd[1]: Starting Music Player Daemon...
Jul 23 10:42:57 volumio-principal volumio[3640]: info: Loading plugin "networkfs"...
Jul 23 10:42:57 volumio-principal volumio[3640]: info: Starting Udev Watcher for removable devices
Jul 23 10:42:57 volumio-principal volumio[3640]: info: Ignoring mount for partition: boot
Jul 23 10:42:57 volumio-principal volumio[3640]: info: Ignoring mount for partition: volumio
Jul 23 10:42:57 volumio-principal volumio[3640]: info: Ignoring mount for partition: volumio_data
Jul 23 10:42:57 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jul 23 10:42:57 volumio-principal volumio[3640]: info: Loading plugin "alarm-clock"...
Jul 23 10:42:57 volumio-principal volumio[3640]: info: Loading plugin "airplay_emulation"...
Jul 23 10:42:57 volumio-principal volumio[3640]: info: Starting Shairport Sync
Jul 23 10:42:57 volumio-principal volumio[3640]: info: Loading plugin "last_100"...
Jul 23 10:42:57 volumio-principal volumio[3640]: info: Loading plugin "webradio"...
Jul 23 10:42:57 volumio-principal dhcpcd[770]: wlan0: carrier acquired
Jul 23 10:42:57 volumio-principal wpa_supplicant[758]: wlan0: Associated with b8:be:f4:bc:78:d5
Jul 23 10:42:57 volumio-principal wpa_supplicant[758]: wlan0: CTRL-EVENT-CONNECTED - Connection to b8:be:f4:bc:78:d5 completed [id=0 id_str=]
Jul 23 10:42:57 volumio-principal wpa_supplicant[758]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Jul 23 10:42:57 volumio-principal dhcpcd[770]: wlan0: IAID dd:80:f5:90
Jul 23 10:42:57 volumio-principal dhcpcd[770]: wlan0: carrier lost
Jul 23 10:42:57 volumio-principal mpd[3694]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Jul 23 10:42:57 volumio-principal mpd[3694]: output: No 'audio_output' defined in config file
Jul 23 10:42:57 volumio-principal mpd[3694]: output: Attempt to detect audio output device
Jul 23 10:42:57 volumio-principal mpd[3694]: output: Attempting to detect a alsa audio device
Jul 23 10:42:57 volumio-principal mpd[3694]: output: Successfully detected a alsa audio device
Jul 23 10:42:57 volumio-principal mpd[3694]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured
Jul 23 10:42:57 volumio-principal mpd[3694]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured
Jul 23 10:42:57 volumio-principal dhcpcd[770]: wlan0: carrier acquired
Jul 23 10:42:57 volumio-principal wpa_supplicant[758]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE
Jul 23 10:42:57 volumio-principal mpd[3694]: zeroconf: No global port, disabling zeroconf
Jul 23 10:42:57 volumio-principal systemd[1]: Started Music Player Daemon.
Jul 23 10:42:57 volumio-principal dhcpcd[770]: wlan0: IAID dd:80:f5:90
Jul 23 10:42:57 volumio-principal sudo[3689]: pam_unix(sudo:session): session closed for user root
Jul 23 10:42:57 volumio-principal volumio[3640]: info: Loading plugin "i2s_dacs"...
Jul 23 10:42:57 volumio-principal volumio[3640]: info: Loading plugin "volumiodiscovery"...
Jul 23 10:42:57 volumio-principal volumio[3640]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Jul 23 10:42:57 volumio-principal volumio[3640]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jul 23 10:42:57 volumio-principal volumio[3640]: *** WARNING *** For more information see
Jul 23 10:42:57 volumio-principal node[3640]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Jul 23 10:42:57 volumio-principal volumio[3640]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Jul 23 10:42:57 volumio-principal volumio[3640]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jul 23 10:42:57 volumio-principal volumio[3640]: *** WARNING *** For more information see
Jul 23 10:42:57 volumio-principal node[3640]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jul 23 10:42:57 volumio-principal node[3640]: *** WARNING *** For more information see
Jul 23 10:42:57 volumio-principal node[3640]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Jul 23 10:42:57 volumio-principal node[3640]: *** WARNING *** Please fix your application to use the native API of Avahi!
Jul 23 10:42:57 volumio-principal node[3640]: *** WARNING *** For more information see
Jul 23 10:42:57 volumio-principal volumio[3640]: info: Applying required configuration parameters for plugin volumiodiscovery
Jul 23 10:42:57 volumio-principal volumio[3640]: info: Discovery: Started advertising with name: Volumio-Principal
Jul 23 10:42:57 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jul 23 10:42:57 volumio-principal volumio[3640]: info: Loading plugin "spop"...
Jul 23 10:42:58 volumio-principal volumio[3640]: info: Loading plugin "squeezelite_mc"...
Jul 23 10:42:58 volumio-principal dhcpcd[770]: wlan0: rebinding lease of 192.168.100.125
Jul 23 10:42:58 volumio-principal dhcpcd[770]: wlan0: probing address 192.168.100.125/24
Jul 23 10:42:58 volumio-principal dhcpcd[770]: wlan0: soliciting an IPv6 router
Jul 23 10:42:58 volumio-principal volumio-remote-updater[490]: [2024-07-23 10:42:58] [connect] Successful connection
Jul 23 10:42:58 volumio-principal volumio[3640]: info: Loading plugin "outputs"...
Jul 23 10:42:58 volumio-principal volumio[3640]: info: Loading plugin "albumart"...
Jul 23 10:42:58 volumio-principal volumio[3640]: info: Plugin example_plugin is not enabled
Jul 23 10:42:58 volumio-principal volumio[3640]: info: Loading plugin "inputs"...
Jul 23 10:42:58 volumio-principal volumio[3640]: info: Loading plugin "updater_comm"...
Jul 23 10:42:58 volumio-principal volumio[3640]: info: Plugin mpdemulation is not enabled
Jul 23 10:42:58 volumio-principal volumio[3640]: info: Loading plugin "rest_api"...
Jul 23 10:42:58 volumio-principal volumio[3640]: info: Loading plugin "websocket"...
Jul 23 10:42:58 volumio-principal volumio[3640]: info: Loading plugin "lms"...
Jul 23 10:42:59 volumio-principal volumio[3640]: info: Loading i18n strings for locale es
Jul 23 10:42:59 volumio-principal volumio[3640]: Forking 3 albumart workers
Jul 23 10:42:59 volumio-principal volumio[3640]: Updating browse sources language
Jul 23 10:42:59 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 23 10:42:59 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 23 10:42:59 volumio-principal volumio[3640]: info: CoreCommandRouter::initPlayerControls
Jul 23 10:42:59 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:59 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:59 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:59 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:59 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:59 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:59 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:59 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:42:59 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 23 10:42:59 volumio-principal volumio[3640]: Express server listening on port 3000
Jul 23 10:42:59 volumio-principal volumio[3640]: [Metrics] WebUI: 4s 338.74ms
Jul 23 10:42:59 volumio-principal volumio[3640]: info: CoreStateMachine::resetVolumioState
Jul 23 10:42:59 volumio-principal volumio[3640]: info: CoreStateMachine::getcurrentVolume
Jul 23 10:42:59 volumio-principal volumio[3640]: info: CoreCommandRouter::volumioRetrievevolume
Jul 23 10:42:59 volumio-principal mpd[3694]: client: [0] opened from local
Jul 23 10:42:59 volumio-principal volumio[3640]: info: MPD Permissions set
Jul 23 10:42:59 volumio-principal volumio[3640]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan
Jul 23 10:42:59 volumio-principal volumio[3640]: wlan0 Interface doesn't support scanning : Resource temporarily unavailable
Jul 23 10:42:59 volumio-principal volumio[3640]: info: Cannot use regular scanning, forcing with ap-force
Jul 23 10:42:59 volumio-principal sudo[3750]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force
Jul 23 10:42:59 volumio-principal sudo[3750]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:42:59 volumio-principal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 23 10:42:59 volumio-principal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Jul 23 10:42:59 volumio-principal systemd[1]: Stopped go-librespot Daemon.
Jul 23 10:42:59 volumio-principal systemd[1]: Started go-librespot Daemon.
Jul 23 10:42:59 volumio-principal go-librespot[3752]: Librespot-go daemon starting...
Jul 23 10:42:59 volumio-principal volumio[3640]: Starting albumart workers
Jul 23 10:42:59 volumio-principal go-librespot[3752]: time="2024-07-23T10:42:59+02:00" level=info msg="generated new device id: 3065669589d7cef230ec1cc036370ad70e71623f"
Jul 23 10:42:59 volumio-principal go-librespot[3752]: time="2024-07-23T10:42:59+02:00" level=debug msg="stored credentials found for gcerruela"
Jul 23 10:42:59 volumio-principal volumio[3640]: Starting albumart workers
Jul 23 10:42:59 volumio-principal volumio[3640]: Starting albumart workers
Jul 23 10:42:59 volumio-principal go-librespot[3752]: time="2024-07-23T10:42:59+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy"
Jul 23 10:42:59 volumio-principal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 23 10:42:59 volumio-principal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 23 10:43:02 volumio-principal systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Jul 23 10:43:02 volumio-principal systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Jul 23 10:43:02 volumio-principal systemd[1]: Stopped go-librespot Daemon.
Jul 23 10:43:02 volumio-principal systemd[1]: Started go-librespot Daemon.
Jul 23 10:43:02 volumio-principal go-librespot[3784]: Librespot-go daemon starting...
Jul 23 10:43:02 volumio-principal go-librespot[3784]: time="2024-07-23T10:43:02+02:00" level=info msg="generated new device id: 099357fd5095ead7a92fff5be6ac7173a47fb46a"
Jul 23 10:43:02 volumio-principal go-librespot[3784]: time="2024-07-23T10:43:02+02:00" level=debug msg="stored credentials found for gcerruela"
Jul 23 10:43:02 volumio-principal go-librespot[3784]: time="2024-07-23T10:43:02+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy"
Jul 23 10:43:02 volumio-principal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 23 10:43:02 volumio-principal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 23 10:43:03 volumio-principal sudo[3750]: pam_unix(sudo:session): session closed for user root
Jul 23 10:43:03 volumio-principal volumio-remote-updater[490]: [2024-07-23 10:43:03] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1721724178 101
Jul 23 10:43:03 volumio-principal volumio[3640]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 1
Jul 23 10:43:03 volumio-principal volumio[3640]: info: MPD running with PID3694
Jul 23 10:43:03 volumio-principal volumio[3640]: ,establishing connection
Jul 23 10:43:03 volumio-principal mpd[3694]: client: [1] opened from local
Jul 23 10:43:03 volumio-principal volumio[3640]: error: MPD error: The expression evaluated to a falsy value:
Jul 23 10:43:03 volumio-principal volumio[3640]: assert.ok(self.idling)
Jul 23 10:43:03 volumio-principal volumio[3640]: error: The expression evaluated to a falsy value:
Jul 23 10:43:03 volumio-principal volumio[3640]: assert.ok(self.idling)
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: Reloading queue from file
Jul 23 10:43:03 volumio-principal volumio[3640]: info: VolumeController:: Volume=43 Mute =false
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreStateMachine::pushState
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CorePlayQueue::getTrack 0
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::volumioPushState
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreStateMachine::updateTrackBlock
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CorePlayQueue::getTrackBlock
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::volumioRetrievevolume
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreStateMachine::setRepeat null single undefined
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreStateMachine::pushState
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CorePlayQueue::getTrack 0
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::volumioPushState
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreStateMachine::setRandom null
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreStateMachine::pushState
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CorePlayQueue::getTrack 0
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::volumioPushState
Jul 23 10:43:03 volumio-principal volumio[3640]: info: Setting Device type: Raspberry PI
Jul 23 10:43:03 volumio-principal volumio[3640]: error: updateQueue error: null
Jul 23 10:43:03 volumio-principal volumio[3640]: info: Completed loading Core Plugins
Jul 23 10:43:03 volumio-principal volumio[3640]: info: Preparing to generate the ALSA configuration file
Jul 23 10:43:03 volumio-principal volumio[3640]: info: Asound.conf file unchanged, so no further update is needed
Jul 23 10:43:03 volumio-principal volumio[3640]: info: Output device has changed, restarting MPD
Jul 23 10:43:03 volumio-principal sudo[3803]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Jul 23 10:43:03 volumio-principal sudo[3803]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:43:03 volumio-principal volumio[3640]: info: Output device has changed, restarting Shairport Sync
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:43:03 volumio-principal sudo[3803]: pam_unix(sudo:session): session closed for user root
Jul 23 10:43:03 volumio-principal sudo[3805]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Jul 23 10:43:03 volumio-principal sudo[3805]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:43:03 volumio-principal systemd[1]: Stopping Music Player Daemon...
Jul 23 10:43:03 volumio-principal volumio[3640]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jul 23 10:43:03 volumio-principal volumio[3640]: info: ___________ START PLUGINS ___________
Jul 23 10:43:03 volumio-principal systemd[1]: mpd.service: Succeeded.
Jul 23 10:43:03 volumio-principal systemd[1]: Stopped Music Player Daemon.
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jul 23 10:43:03 volumio-principal volumio[3640]: info: [1721724183395] CoreMusicLibrary::Adding element Media Servers
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 23 10:43:03 volumio-principal systemd[1]: Starting Music Player Daemon...
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jul 23 10:43:03 volumio-principal volumio[3640]: info: [1721724183492] CoreMusicLibrary::Adding element Last_100
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Jul 23 10:43:03 volumio-principal volumio[3640]: info: [1721724183495] CoreMusicLibrary::Adding element Webradio
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Jul 23 10:43:03 volumio-principal volumio[3640]: info: Creating Spotify config file
Jul 23 10:43:03 volumio-principal volumio[3640]: info: [squeezelite_mc] Starting proxy server...
Jul 23 10:43:03 volumio-principal volumio[3640]: info: Volumio Calling Home
Jul 23 10:43:03 volumio-principal sudo[3821]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver
Jul 23 10:43:03 volumio-principal sudo[3821]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:43:03 volumio-principal systemd[1]: Stopping Logitech Media Server Daemon...
Jul 23 10:43:03 volumio-principal volumio[3640]: info: [squeezelite_mc] Proxy server started on port 39781
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::volumioRetrievevolume
Jul 23 10:43:03 volumio-principal volumio[3640]: Unhandled rejection Error: No sockets available, cannot start.
Jul 23 10:43:03 volumio-principal volumio[3640]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11)
Jul 23 10:43:03 volumio-principal volumio[3640]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10)
Jul 23 10:43:03 volumio-principal volumio[3640]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10
Jul 23 10:43:03 volumio-principal volumio[3640]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9)
Jul 23 10:43:03 volumio-principal volumio[3640]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18)
Jul 23 10:43:03 volumio-principal volumio[3640]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10)
Jul 23 10:43:03 volumio-principal volumio[3640]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10)
Jul 23 10:43:03 volumio-principal volumio[3640]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17)
Jul 23 10:43:03 volumio-principal volumio[3640]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12)
Jul 23 10:43:03 volumio-principal volumio[3640]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24)
Jul 23 10:43:03 volumio-principal volumio[3640]: at HashMap. (/volumio/app/pluginmanager.js:496:31)
Jul 23 10:43:03 volumio-principal volumio[3640]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10)
Jul 23 10:43:03 volumio-principal volumio[3640]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7)
Jul 23 10:43:03 volumio-principal volumio[3640]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20)
Jul 23 10:43:03 volumio-principal volumio[3640]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29)
Jul 23 10:43:03 volumio-principal volumio[3640]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)
Jul 23 10:43:03 volumio-principal systemd[1]: logitechmediaserver.service: Succeeded.
Jul 23 10:43:03 volumio-principal systemd[1]: Stopped Logitech Media Server Daemon.
Jul 23 10:43:03 volumio-principal volumio[3640]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.dfs.volumio.org
Jul 23 10:43:03 volumio-principal systemd[1]: Starting Logitech Media Server Daemon...
Jul 23 10:43:03 volumio-principal volumio[3640]: info: MPD Permissions set
Jul 23 10:43:03 volumio-principal volumio[3640]: info: VolumeController:: Volume=43 Mute =false
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreStateMachine::pushState
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CorePlayQueue::getTrack 0
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::volumioPushState
Jul 23 10:43:03 volumio-principal systemd[1]: Started Logitech Media Server Daemon.
Jul 23 10:43:03 volumio-principal sudo[3821]: pam_unix(sudo:session): session closed for user root
Jul 23 10:43:03 volumio-principal volumio[3640]: info: Spotify config file written
Jul 23 10:43:03 volumio-principal volumio[3640]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2
Jul 23 10:43:03 volumio-principal volumio[3640]: info: logitechmediaserver started
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal sudo[3832]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Jul 23 10:43:03 volumio-principal sudo[3832]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal systemd[1]: Stopped go-librespot Daemon.
Jul 23 10:43:03 volumio-principal systemd[1]: Started go-librespot Daemon.
Jul 23 10:43:03 volumio-principal go-librespot[3838]: Librespot-go daemon starting...
Jul 23 10:43:03 volumio-principal sudo[3832]: pam_unix(sudo:session): session closed for user root
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal go-librespot[3838]: time="2024-07-23T10:43:03+02:00" level=info msg="generated new device id: fb49c245c55a82961c6f9e0b9a9296cf38073cfb"
Jul 23 10:43:03 volumio-principal go-librespot[3838]: time="2024-07-23T10:43:03+02:00" level=debug msg="stored credentials found for gcerruela"
Jul 23 10:43:03 volumio-principal go-librespot[3838]: time="2024-07-23T10:43:03+02:00" level=fatal msg="failed running with username and spotify token" error="failed obtaining client token: failed requesting clienttoken: Post \"https://clienttoken.spotify.com/v1/clienttoken\": dial tcp: lookup clienttoken.spotify.com: device or resource busy"
Jul 23 10:43:03 volumio-principal systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Jul 23 10:43:03 volumio-principal systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Jul 23 10:43:03 volumio-principal volumio[3640]: info: VolumeController:: Volume=43 Mute =false
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreStateMachine::pushState
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CorePlayQueue::getTrack 0
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::volumioPushState
Jul 23 10:43:03 volumio-principal volumio[3640]: info: [squeezelite_mc] Server discovery started
Jul 23 10:43:03 volumio-principal volumio[3640]: info: [squeezelite_mc] Player finder started
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 23 10:43:03 volumio-principal volumio[3640]: info: [squeezelite_mc] Executing aplay -D hw:2 --nonblock -f MPEG /dev/zero 2>&1 || true
Jul 23 10:43:04 volumio-principal volumio[3640]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 23 10:43:04 volumio-principal volumio[3640]: Error: send ENETUNREACH 255.255.255.255:3483
Jul 23 10:43:04 volumio-principal volumio[3640]: at doSend (dgram.js:692:16)
Jul 23 10:43:04 volumio-principal volumio[3640]: at defaultTriggerAsyncIdScope (internal/async_hooks.js:430:12)
Jul 23 10:43:04 volumio-principal volumio[3640]: at afterDns (dgram.js:638:5)
Jul 23 10:43:04 volumio-principal volumio[3640]: at processTicksAndRejections (internal/process/task_queues.js:81:21) {
Jul 23 10:43:04 volumio-principal volumio[3640]: errno: -101,
Jul 23 10:43:04 volumio-principal volumio[3640]: code: 'ENETUNREACH',
Jul 23 10:43:04 volumio-principal volumio[3640]: syscall: 'send',
Jul 23 10:43:04 volumio-principal volumio[3640]: address: '255.255.255.255',
Jul 23 10:43:04 volumio-principal volumio[3640]: port: 3483
Jul 23 10:43:04 volumio-principal volumio[3640]: }
Jul 23 10:43:04 volumio-principal volumio[3640]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 23 10:43:04 volumio-principal mpd[3819]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Jul 23 10:43:04 volumio-principal mpd[3819]: output: No 'audio_output' defined in config file
Jul 23 10:43:04 volumio-principal mpd[3819]: output: Attempt to detect audio output device
Jul 23 10:43:04 volumio-principal mpd[3819]: output: Attempting to detect a alsa audio device
Jul 23 10:43:04 volumio-principal mpd[3819]: output: Successfully detected a alsa audio device
Jul 23 10:43:04 volumio-principal mpd[3819]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured
Jul 23 10:43:04 volumio-principal mpd[3819]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured
Jul 23 10:43:04 volumio-principal mpd[3819]: zeroconf: No global port, disabling zeroconf
Jul 23 10:43:04 volumio-principal systemd[1]: Started Music Player Daemon.
Jul 23 10:43:04 volumio-principal sudo[3805]: pam_unix(sudo:session): session closed for user root
Jul 23 10:43:04 volumio-principal dhcpcd[770]: wlan0: leased 192.168.100.125 for 86400 seconds
Jul 23 10:43:04 volumio-principal avahi-daemon[516]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.100.125.
Jul 23 10:43:04 volumio-principal avahi-daemon[516]: New relevant interface wlan0.IPv4 for mDNS.
Jul 23 10:43:04 volumio-principal dhcpcd[770]: wlan0: adding route to 192.168.100.0/24
Jul 23 10:43:04 volumio-principal avahi-daemon[516]: Registering new address record for 192.168.100.125 on wlan0.IPv4.
Jul 23 10:43:04 volumio-principal dhcpcd[770]: wlan0: adding default route via 192.168.100.1
Jul 23 10:43:04 volumio-principal sudo[3880]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-23 10:42
Jul 23 10:43:04 volumio-principal sudo[3880]: 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="cd8cf34b47ce852e70b71e6f7b6e0265f7fdb695"
VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71"
VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1"
VOLUMIO_BE_VERSION="8f88153f9a18f312d56050e6613b45a852ac819a"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Wed 27 Sep 2023 11:35:49 AM CEST"
VOLUMIO_VERSION="3.546"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="6823c0d83061ff736b7e0dd4481bc496"