-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Tue 2023-04-04 05:22:01 CEST. --
Apr 04 05:20:59 volumio systemd[1]: wireless.service: Control process exited, code=exited, status=237/KEYRING
Apr 04 05:20:59 volumio systemd[1]: wireless.service: Failed with result 'exit-code'.
Apr 04 05:21:00 volumio systemd[1]: Failed to start Wireless Services.
Apr 04 05:21:00 volumio systemd[1]: Started Volumio Backend Module.
Apr 04 05:21:01 volumio mpd[611]: Apr 04 05:21 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Apr 04 05:21:01 volumio mpd[611]: Apr 04 05:21 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured
Apr 04 05:21:01 volumio mpd[611]: Apr 04 05:21 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured
Apr 04 05:21:01 volumio systemd[1]: Started Music Player Daemon.
Apr 04 05:21:02 volumio sh[342]: eth0: leased 192.168.0.23 for 43200 seconds
Apr 04 05:21:02 volumio sh[342]: eth0: adding route to 192.168.0.0/24
Apr 04 05:21:02 volumio sh[342]: eth0: adding default route via 192.168.0.254
Apr 04 05:21:02 volumio dhcpcd[414]: eth0: leased 192.168.0.23 for 43200 seconds
Apr 04 05:21:02 volumio dhcpcd[414]: eth0: adding route to 192.168.0.0/24
Apr 04 05:21:02 volumio dhcpcd[414]: eth0: adding default route via 192.168.0.254
Apr 04 05:21:02 volumio avahi-daemon[393]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.0.23.
Apr 04 05:21:02 volumio avahi-daemon[393]: New relevant interface eth0.IPv4 for mDNS.
Apr 04 05:21:02 volumio avahi-daemon[393]: Registering new address record for 192.168.0.23 on eth0.IPv4.
Apr 04 05:21:02 volumio sh[342]: forked to background, child pid 664
Apr 04 05:21:02 volumio dhcpcd[414]: forked to background, child pid 664
Apr 04 05:21:02 volumio ifplugd(eth0)[609]: client: ifup: interface eth0 already configured
Apr 04 05:21:02 volumio sh[342]: eth0=eth0
Apr 04 05:21:02 volumio ifplugd(eth0)[609]: Program executed successfully.
Apr 04 05:21:02 volumio ifplugd[573]: Network Interface Plugging Daemon...start eth0...done.
Apr 04 05:21:02 volumio systemd[1]: Started LSB: Brings up/down network automatically.
Apr 04 05:21:03 volumio systemd[1]: Started Samba NMB Daemon.
Apr 04 05:21:03 volumio nmbd[579]: [2023/04/04 05:21:03.168923, 0] ../lib/util/become_daemon.c:138(daemon_ready)
Apr 04 05:21:03 volumio nmbd[579]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections
Apr 04 05:21:03 volumio systemd[1]: Starting Samba Winbind Daemon...
Apr 04 05:21:03 volumio ntpd[616]: Listen normally on 3 eth0 192.168.0.23:123
Apr 04 05:21:03 volumio ntpd[616]: new interface(s) found: waking up resolver
Apr 04 05:21:03 volumio kernel: cam1-reg: disabling
Apr 04 05:21:03 volumio kernel: cam-dummy-reg: disabling
Apr 04 05:21:03 volumio winbindd[690]: [2023/04/04 05:21:03.722542, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache)
Apr 04 05:21:03 volumio winbindd[690]: initialize_winbindd_cache: clearing cache and re-creating with version number 2
Apr 04 05:21:03 volumio winbindd[690]: [2023/04/04 05:21:03.768530, 0] ../lib/util/become_daemon.c:138(daemon_ready)
Apr 04 05:21:03 volumio winbindd[690]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections
Apr 04 05:21:03 volumio systemd[1]: Started Samba Winbind Daemon.
Apr 04 05:21:03 volumio systemd[1]: Starting Samba SMB Daemon...
Apr 04 05:21:04 volumio winbindd[690]: [2023/04/04 05:21:04.825671, 0] ../source3/winbindd/wb_lookupsids.c:659(wb_lookupsids_recv)
Apr 04 05:21:04 volumio winbindd[690]: res_names->count = 3, expected 4
Apr 04 05:21:04 volumio smbd[695]: [2023/04/04 05:21:04.890350, 0] ../lib/util/become_daemon.c:138(daemon_ready)
Apr 04 05:21:04 volumio smbd[695]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections
Apr 04 05:21:04 volumio systemd[1]: Started Samba SMB Daemon.
Apr 04 05:21:04 volumio systemd[1]: Reached target Multi-User System.
Apr 04 05:21:04 volumio systemd[1]: Reached target Graphical Interface.
Apr 04 05:21:04 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes...
Apr 04 05:21:05 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Apr 04 05:21:05 volumio systemd[1]: Started Update UTMP about System Runlevel Changes.
Apr 04 05:21:05 volumio systemd[1]: Startup finished in 11.982s (kernel) + 24.447s (userspace) = 36.430s.
Apr 04 05:21:05 volumio volumio[635]: info: -------------------------------------------
Apr 04 05:21:05 volumio volumio[635]: info: ----- Volumio3 ----
Apr 04 05:21:05 volumio volumio[635]: info: -------------------------------------------
Apr 04 05:21:05 volumio volumio[635]: info: ----- System startup ----
Apr 04 05:21:05 volumio volumio[635]: info: -------------------------------------------
Apr 04 05:21:07 volumio volumio-remote-updater[391]: [2023-04-04 05:21:07] [connect] Successful connection
Apr 04 05:21:07 volumio volumio[635]: info: MYVOLUMIO Environment detected
Apr 04 05:21:08 volumio volumio[635]: info: Plugin folders cleanup
Apr 04 05:21:08 volumio volumio[635]: info: Scanning into folder /volumio/app/plugins/
Apr 04 05:21:08 volumio volumio[635]: info: Scanning category audio_interface
Apr 04 05:21:08 volumio volumio[635]: info: Scanning category miscellanea
Apr 04 05:21:08 volumio volumio[635]: info: Scanning category music_service
Apr 04 05:21:08 volumio volumio[635]: info: Scanning category plugins.json
Apr 04 05:21:08 volumio volumio[635]: info: Scanning category system_controller
Apr 04 05:21:08 volumio volumio[635]: info: Scanning category user_interface
Apr 04 05:21:08 volumio volumio[635]: info: Scanning into folder /data/plugins/
Apr 04 05:21:08 volumio volumio[635]: info: Scanning category music_service
Apr 04 05:21:08 volumio volumio[635]: info: Plugin folders cleanup completed
Apr 04 05:21:08 volumio volumio[635]: info: -------------------------------------------
Apr 04 05:21:08 volumio volumio[635]: info: ----- Core plugins startup ----
Apr 04 05:21:08 volumio volumio[635]: info: -------------------------------------------
Apr 04 05:21:08 volumio volumio[635]: info: Loading plugins from folder /volumio/app/plugins/
Apr 04 05:21:08 volumio volumio[635]: info: Adding plugin upnp to MyMusic Plugins
Apr 04 05:21:08 volumio volumio[635]: info: Adding plugin airplay_emulation to MyMusic Plugins
Apr 04 05:21:08 volumio volumio[635]: info: Adding plugin upnp_browser to MyMusic Plugins
Apr 04 05:21:08 volumio volumio[635]: info: Loading plugins from folder /data/plugins/
Apr 04 05:21:08 volumio volumio[635]: info: Loading plugin "system"...
Apr 04 05:21:08 volumio volumio[635]: info: Loading plugin "appearance"...
Apr 04 05:21:10 volumio volumio[635]: info: Loading plugin "network"...
Apr 04 05:21:10 volumio volumio[635]: info: Refreshing Cached IP Addresses
Apr 04 05:21:11 volumio volumio[635]: info: Loading plugin "services"...
Apr 04 05:21:11 volumio volumio[635]: info: Loading plugin "alsa_controller"...
Apr 04 05:21:11 volumio sudo[715]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 04 05:21:11 volumio sudo[717]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 04 05:21:11 volumio sudo[719]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Apr 04 05:21:11 volumio sudo[715]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:11 volumio sudo[717]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:11 volumio sudo[719]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:11 volumio sudo[715]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:11 volumio sudo[717]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:11 volumio sudo[719]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:11 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 04 05:21:11 volumio volumio[635]: info: Loading plugin "wizard"...
Apr 04 05:21:11 volumio volumio[635]: info: Loading plugin "volumio_command_line_client"...
Apr 04 05:21:11 volumio volumio[635]: info: Loading plugin "upnp"...
Apr 04 05:21:11 volumio volumio[635]: info: [1680578471414] Starting Upmpd Daemon
Apr 04 05:21:11 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Apr 04 05:21:11 volumio volumio[635]: info: Loading plugin "my_music"...
Apr 04 05:21:11 volumio volumio[635]: info: Loading plugin "mpd"...
Apr 04 05:21:12 volumio volumio[635]: info: Creating MPD Configuration file
Apr 04 05:21:12 volumio volumio[635]: info: Loading plugin "upnp_browser"...
Apr 04 05:21:12 volumio sudo[732]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Apr 04 05:21:12 volumio sudo[732]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:12 volumio sudo[732]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:12 volumio sudo[734]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Apr 04 05:21:12 volumio sudo[734]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:12 volumio systemd[1]: Stopping Music Player Daemon...
Apr 04 05:21:12 volumio systemd[1]: mpd.service: Succeeded.
Apr 04 05:21:12 volumio systemd[1]: Stopped Music Player Daemon.
Apr 04 05:21:12 volumio systemd[1]: Starting Music Player Daemon...
Apr 04 05:21:13 volumio volumio[635]: info: Loading plugin "networkfs"...
Apr 04 05:21:14 volumio volumio[635]: info: Starting Udev Watcher for removable devices
Apr 04 05:21:14 volumio sudo[742]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.254/freebox /mnt/NAS/freebox
Apr 04 05:21:14 volumio sudo[742]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:14 volumio kernel: FS-Cache: Netfs 'cifs' registered for caching
Apr 04 05:21:14 volumio kernel: Key type cifs.spnego registered
Apr 04 05:21:14 volumio kernel: Key type cifs.idmap registered
Apr 04 05:21:14 volumio kernel: CIFS: Attempting to mount //192.168.0.254/freebox
Apr 04 05:21:14 volumio kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount.
Apr 04 05:21:14 volumio sudo[742]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:14 volumio volumio[635]: info: Ignoring mount for partition: boot
Apr 04 05:21:14 volumio volumio[635]: info: Ignoring mount for partition: volumio
Apr 04 05:21:14 volumio volumio[635]: info: Ignoring mount for partition: volumio_data
Apr 04 05:21:14 volumio volumio[635]: info: Mounting Device 88A8BB4FA8BB3B10
Apr 04 05:21:15 volumio sudo[778]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/88A8BB4FA8BB3B10 -o noatime,dmask=0000,fmask=0000,iocharset=utf8
Apr 04 05:21:15 volumio sudo[778]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:15 volumio kernel: fuse: init (API version 7.32)
Apr 04 05:21:15 volumio systemd[1]: Mounting FUSE Control File System...
Apr 04 05:21:15 volumio systemd[1]: Mounted FUSE Control File System.
Apr 04 05:21:15 volumio mpd[739]: Apr 04 05:21 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Apr 04 05:21:15 volumio ntfs-3g[783]: Version 2017.3.23AR.3 integrated FUSE 28
Apr 04 05:21:15 volumio ntfs-3g[783]: Mounted /dev/sda1 (Read-Write, label "", NTFS 3.1)
Apr 04 05:21:15 volumio ntfs-3g[783]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8
Apr 04 05:21:15 volumio ntfs-3g[783]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda1,blkdev,blksize=4096
Apr 04 05:21:15 volumio ntfs-3g[783]: Global ownership and permissions enforced, configuration type 7
Apr 04 05:21:15 volumio sudo[778]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:15 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Apr 04 05:21:15 volumio volumio[635]: info: Loading plugin "alarm-clock"...
Apr 04 05:21:15 volumio mpd[739]: Apr 04 05:21 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured
Apr 04 05:21:15 volumio mpd[739]: Apr 04 05:21 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured
Apr 04 05:21:15 volumio systemd[1]: Started Music Player Daemon.
Apr 04 05:21:15 volumio sudo[734]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:15 volumio volumio[635]: info: Loading plugin "airplay_emulation"...
Apr 04 05:21:16 volumio volumio[635]: info: Starting Shairport Sync
Apr 04 05:21:16 volumio volumio[635]: info: Loading plugin "last_100"...
Apr 04 05:21:16 volumio volumio[635]: info: Loading plugin "webradio"...
Apr 04 05:21:16 volumio volumio[635]: info: Loading plugin "i2s_dacs"...
Apr 04 05:21:16 volumio volumio[635]: info: Loading plugin "volumiodiscovery"...
Apr 04 05:21:16 volumio volumio[635]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Apr 04 05:21:16 volumio volumio[635]: *** WARNING *** Please fix your application to use the native API of Avahi!
Apr 04 05:21:16 volumio node[635]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Apr 04 05:21:16 volumio volumio[635]: *** WARNING *** For more information see
Apr 04 05:21:16 volumio volumio[635]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Apr 04 05:21:16 volumio volumio[635]: *** WARNING *** Please fix your application to use the native API of Avahi!
Apr 04 05:21:16 volumio volumio[635]: *** WARNING *** For more information see
Apr 04 05:21:16 volumio node[635]: *** WARNING *** Please fix your application to use the native API of Avahi!
Apr 04 05:21:16 volumio node[635]: *** WARNING *** For more information see
Apr 04 05:21:16 volumio node[635]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Apr 04 05:21:16 volumio node[635]: *** WARNING *** Please fix your application to use the native API of Avahi!
Apr 04 05:21:16 volumio node[635]: *** WARNING *** For more information see
Apr 04 05:21:16 volumio volumio[635]: info: Applying required configuration parameters for plugin volumiodiscovery
Apr 04 05:21:16 volumio volumio[635]: info: Discovery: Started advertising with name: Volumio
Apr 04 05:21:16 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Apr 04 05:21:16 volumio volumio[635]: info: Loading plugin "spop"...
Apr 04 05:21:18 volumio systemd[1]: systemd-fsckd.service: Succeeded.
Apr 04 05:21:19 volumio volumio[635]: info: Plugin youtube2 is not enabled
Apr 04 05:21:19 volumio volumio[635]: info: Loading plugin "ytmusic"...
Apr 04 05:21:22 volumio volumio-remote-updater[391]: [2023-04-04 05:21:22] [connect] Successful connection
Apr 04 05:21:23 volumio volumio[635]: info: Loading plugin "outputs"...
Apr 04 05:21:23 volumio volumio[635]: info: Loading plugin "albumart"...
Apr 04 05:21:23 volumio volumio[635]: info: Plugin example_plugin is not enabled
Apr 04 05:21:23 volumio volumio[635]: info: Loading plugin "inputs"...
Apr 04 05:21:23 volumio volumio[635]: info: Loading plugin "updater_comm"...
Apr 04 05:21:24 volumio volumio[635]: info: Plugin mpdemulation is not enabled
Apr 04 05:21:24 volumio volumio[635]: info: Loading plugin "rest_api"...
Apr 04 05:21:24 volumio volumio[635]: info: Loading plugin "websocket"...
Apr 04 05:21:24 volumio volumio[635]: info: Loading i18n strings for locale fr
Apr 04 05:21:24 volumio volumio[635]: Updating browse sources language
Apr 04 05:21:24 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 04 05:21:24 volumio volumio[635]: Forking 3 albumart workers
Apr 04 05:21:25 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 04 05:21:25 volumio volumio[635]: info: CoreCommandRouter::initPlayerControls
Apr 04 05:21:25 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:25 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:25 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:25 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:25 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:25 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:25 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:25 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:25 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 04 05:21:25 volumio volumio[635]: Express server listening on port 3000
Apr 04 05:21:25 volumio volumio[635]: [Metrics] WebUI: 21s 438.57ms
Apr 04 05:21:25 volumio volumio[635]: info: CoreStateMachine::resetVolumioState
Apr 04 05:21:25 volumio volumio[635]: info: CoreStateMachine::getcurrentVolume
Apr 04 05:21:25 volumio volumio[635]: info: CoreCommandRouter::volumioRetrievevolume
Apr 04 05:21:25 volumio sudo[821]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 04 05:21:25 volumio sudo[821]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:25 volumio sudo[821]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:25 volumio sudo[823]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 04 05:21:25 volumio sudo[823]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:25 volumio sudo[823]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:25 volumio volumio[635]: info: MPD Permissions set
Apr 04 05:21:25 volumio volumio[635]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan
Apr 04 05:21:25 volumio volumio[635]: wlan0 Interface doesn't support scanning.
Apr 04 05:21:25 volumio volumio[635]: info: Cannot use regular scanning, forcing with ap-force
Apr 04 05:21:25 volumio sudo[831]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force
Apr 04 05:21:25 volumio sudo[831]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:25 volumio sudo[831]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:25 volumio volumio[635]: command failed: No such device (-19)
Apr 04 05:21:25 volumio volumio[635]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force
Apr 04 05:21:25 volumio volumio[635]: command failed: No such device (-19)
Apr 04 05:21:26 volumio volumio-remote-updater[391]: [2023-04-04 05:21:26] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1680578482 101
Apr 04 05:21:26 volumio volumio[635]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 1
Apr 04 05:21:26 volumio volumio[635]: info: MPD running with PID739
Apr 04 05:21:26 volumio volumio[635]: ,establishing connection
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 04 05:21:26 volumio volumio[635]: info: Discovery: Getting this device information
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::volumioGetState
Apr 04 05:21:26 volumio volumio[635]: info: CorePlayQueue::getTrack 0
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 04 05:21:26 volumio volumio[635]: info: Discovery: Getting this device information
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::volumioGetState
Apr 04 05:21:26 volumio volumio[635]: info: CorePlayQueue::getTrack 0
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 04 05:21:26 volumio volumio[635]: info: Discovery: Getting this device information
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::volumioGetState
Apr 04 05:21:26 volumio volumio[635]: info: CorePlayQueue::getTrack 0
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 04 05:21:26 volumio volumio[635]: info: Discovery: Getting this device information
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::volumioGetState
Apr 04 05:21:26 volumio volumio[635]: info: CorePlayQueue::getTrack 0
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 04 05:21:26 volumio volumio[635]: error: MPD error: The expression evaluated to a falsy value:
Apr 04 05:21:26 volumio volumio[635]: assert.ok(self.idling)
Apr 04 05:21:26 volumio volumio[635]: error: The expression evaluated to a falsy value:
Apr 04 05:21:26 volumio volumio[635]: assert.ok(self.idling)
Apr 04 05:21:26 volumio volumio[635]: error: MPD error: The expression evaluated to a falsy value:
Apr 04 05:21:26 volumio volumio[635]: assert.ok(self.idling)
Apr 04 05:21:26 volumio volumio[635]: error: The expression evaluated to a falsy value:
Apr 04 05:21:26 volumio volumio[635]: assert.ok(self.idling)
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:26 volumio volumio[635]: Starting albumart workers
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:26 volumio volumio[635]: Starting albumart workers
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 04 05:21:26 volumio volumio[635]: Starting albumart workers
Apr 04 05:21:26 volumio volumio[635]: info: Reloading queue from file
Apr 04 05:21:26 volumio volumio[635]: info: VolumeController:: Volume=66 Mute =false
Apr 04 05:21:26 volumio volumio[635]: info: CoreStateMachine::pushState
Apr 04 05:21:26 volumio volumio[635]: info: CorePlayQueue::getTrack 0
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::volumioPushState
Apr 04 05:21:26 volumio volumio[635]: info: CoreStateMachine::updateTrackBlock
Apr 04 05:21:26 volumio volumio[635]: info: CorePlayQueue::getTrackBlock
Apr 04 05:21:26 volumio volumio[635]: info: CoreCommandRouter::volumioRetrievevolume
Apr 04 05:21:27 volumio volumio[635]: info: Setting Device type: Raspberry PI
Apr 04 05:21:27 volumio volumio[635]: info: CoreStateMachine::setRepeat true single undefined
Apr 04 05:21:27 volumio volumio[635]: info: CoreStateMachine::pushState
Apr 04 05:21:27 volumio volumio[635]: info: CorePlayQueue::getTrack 0
Apr 04 05:21:27 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 04 05:21:27 volumio volumio[635]: info: CoreCommandRouter::volumioPushState
Apr 04 05:21:27 volumio volumio[635]: info: CoreStateMachine::setRandom false
Apr 04 05:21:27 volumio volumio[635]: info: CoreStateMachine::pushState
Apr 04 05:21:27 volumio volumio[635]: info: CorePlayQueue::getTrack 0
Apr 04 05:21:27 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 04 05:21:27 volumio volumio[635]: info: CoreCommandRouter::volumioPushState
Apr 04 05:21:27 volumio volumio[635]: error: updateQueue error: null
Apr 04 05:21:27 volumio volumio[635]: verbose: New Socket.io Connection to 192.168.0.23 from 192.168.0.17 UA: unknown Total Clients: 2
Apr 04 05:21:27 volumio volumio[635]: info: Completed loading Core Plugins
Apr 04 05:21:27 volumio volumio[635]: info: Preparing to generate the ALSA configuration file
Apr 04 05:21:27 volumio volumio[635]: info: CoreCommandRouter::volumioGetState
Apr 04 05:21:27 volumio volumio[635]: info: CorePlayQueue::getTrack 0
Apr 04 05:21:27 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 04 05:21:27 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 04 05:21:27 volumio sudo[848]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Apr 04 05:21:27 volumio sudo[848]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:27 volumio volumio[635]: info: Discovery: adding cf3a4d4e-9b66-45f5-bacd-732bdd04c169
Apr 04 05:21:27 volumio volumio[635]: info: Discovery: Found device Volumio
Apr 04 05:21:27 volumio volumio[635]: info: CoreCommandRouter::volumioGetState
Apr 04 05:21:27 volumio volumio[635]: info: CorePlayQueue::getTrack 0
Apr 04 05:21:27 volumio volumio[635]: info: VolumeController:: Volume=66 Mute =false
Apr 04 05:21:27 volumio volumio[635]: info: CoreStateMachine::pushState
Apr 04 05:21:27 volumio volumio[635]: info: CorePlayQueue::getTrack 0
Apr 04 05:21:27 volumio volumio[635]: info: CoreCommandRouter::volumioPushState
Apr 04 05:21:27 volumio volumio[635]: info: Asound.conf file unchanged, so no further update is needed
Apr 04 05:21:27 volumio volumio[635]: info: Output device has changed, restarting MPD
Apr 04 05:21:27 volumio systemd[1]: Started UPnP Renderer front-end to MPD.
Apr 04 05:21:27 volumio sudo[848]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:27 volumio volumio[635]: info: Output device has changed, restarting Shairport Sync
Apr 04 05:21:27 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:27 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 04 05:21:27 volumio sudo[852]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Apr 04 05:21:27 volumio sudo[852]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:27 volumio sudo[854]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Apr 04 05:21:27 volumio sudo[854]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:27 volumio sudo[852]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:27 volumio systemd[1]: Stopping Music Player Daemon...
Apr 04 05:21:27 volumio systemd[1]: mpd.service: Succeeded.
Apr 04 05:21:27 volumio volumio[635]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 04 05:21:27 volumio volumio[635]: info: ___________ START PLUGINS ___________
Apr 04 05:21:27 volumio systemd[1]: Stopped Music Player Daemon.
Apr 04 05:21:27 volumio systemd[1]: Starting Music Player Daemon...
Apr 04 05:21:27 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 04 05:21:27 volumio volumio[635]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 04 05:21:27 volumio volumio[635]: info: [1680578487988] CoreMusicLibrary::Adding element Media Servers
Apr 04 05:21:27 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 04 05:21:28 volumio volumio[635]: Cannot find translation for sourceMedia Servers
Apr 04 05:21:28 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:28 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 04 05:21:28 volumio volumio[635]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 04 05:21:28 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:28 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 04 05:21:28 volumio volumio[635]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 04 05:21:28 volumio volumio[635]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 04 05:21:28 volumio volumio[635]: info: [1680578488496] CoreMusicLibrary::Adding element Last_100
Apr 04 05:21:28 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 04 05:21:28 volumio volumio[635]: Cannot find translation for sourceMedia Servers
Apr 04 05:21:28 volumio volumio[635]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 04 05:21:28 volumio volumio[635]: info: [1680578488545] CoreMusicLibrary::Adding element Webradio
Apr 04 05:21:28 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 04 05:21:28 volumio volumio[635]: Cannot find translation for sourceMedia Servers
Apr 04 05:21:28 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 04 05:21:28 volumio volumio[635]: info: Creating Spotify config file
Apr 04 05:21:28 volumio volumio[635]: info: Volumio Calling Home
Apr 04 05:21:29 volumio volumio[635]: info: MPD Permissions set
Apr 04 05:21:29 volumio volumio[635]: info: Upmpdcli Daemon Started
Apr 04 05:21:29 volumio volumio[635]: info: Spotify config file written
Apr 04 05:21:29 volumio sudo[897]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Apr 04 05:21:29 volumio sudo[897]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:29 volumio volumio[635]: info: An error occurred while refreshing Spotify Token Error: certificate is not yet valid
Apr 04 05:21:29 volumio systemd[1]: Started go-librespot Daemon.
Apr 04 05:21:29 volumio sudo[897]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:29 volumio go-librespot[899]: Librespot-go daemon starting...
Apr 04 05:21:29 volumio volumio[635]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3
Apr 04 05:21:29 volumio volumio[635]: info: Volumio called home
Apr 04 05:21:29 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:29 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:29 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:29 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:29 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:29 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:29 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:29 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:29 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 04 05:21:29 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 04 05:21:29 volumio volumio[635]: info: Starting Shairport Sync
Apr 04 05:21:29 volumio volumio[635]: info: Starting Shairport Sync
Apr 04 05:21:29 volumio sudo[911]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 04 05:21:29 volumio volumio[635]: info: Starting Shairport Sync
Apr 04 05:21:29 volumio sudo[911]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:29 volumio sudo[913]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 04 05:21:29 volumio sudo[913]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:29 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver...
Apr 04 05:21:29 volumio systemd[1]: shairport-sync.service: Succeeded.
Apr 04 05:21:29 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.
Apr 04 05:21:30 volumio sudo[916]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 04 05:21:30 volumio sudo[916]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:30 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
Apr 04 05:21:30 volumio sudo[911]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:30 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver...
Apr 04 05:21:30 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM
Apr 04 05:21:30 volumio systemd[1]: shairport-sync.service: Succeeded.
Apr 04 05:21:30 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.
Apr 04 05:21:30 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
Apr 04 05:21:30 volumio sudo[913]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:30 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver...
Apr 04 05:21:30 volumio volumio[635]: info: Shairport-Sync Started
Apr 04 05:21:30 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM
Apr 04 05:21:30 volumio systemd[1]: shairport-sync.service: Succeeded.
Apr 04 05:21:30 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.
Apr 04 05:21:30 volumio volumio[635]: Error adding Membership: Error: addMembership EINVAL
Apr 04 05:21:30 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
Apr 04 05:21:30 volumio sudo[916]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:30 volumio go-librespot[899]: time="2023-04-04T05:21:30+02:00" level=info msg="generated new device id: 9920de936e9c19dbe45992c42fa3eb7e3eaa761d"
Apr 04 05:21:30 volumio go-librespot[899]: time="2023-04-04T05:21:30+02:00" level=debug msg="stored credentials found for lucillouu"
Apr 04 05:21:30 volumio volumio[635]: info: Shairport-Sync Started
Apr 04 05:21:30 volumio volumio[635]: info: CoreCommandRouter::volumioGetState
Apr 04 05:21:30 volumio volumio[635]: info: CorePlayQueue::getTrack 0
Apr 04 05:21:30 volumio volumio[635]: info: Shairport-Sync Started
Apr 04 05:21:30 volumio sudo[928]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 04 05:21:30 volumio sudo[928]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:30 volumio sudo[927]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 04 05:21:30 volumio sudo[927]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 04 05:21:30 volumio sudo[927]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:30 volumio sudo[928]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:30 volumio volumio[635]: verbose: New Socket.io Connection to 192.168.0.23 from 192.168.0.17 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Total Clients: 4
Apr 04 05:21:30 volumio mpd[868]: Apr 04 05:21 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Apr 04 05:21:30 volumio go-librespot[899]: time="2023-04-04T05:21:30+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\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2023-04-04T05:21:30+02:00 is before 2024-02-05T00:00:00Z"
Apr 04 05:21:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 04 05:21:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 04 05:21:31 volumio mpd[868]: Apr 04 05:21 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured
Apr 04 05:21:31 volumio mpd[868]: Apr 04 05:21 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured
Apr 04 05:21:31 volumio systemd[1]: Started Music Player Daemon.
Apr 04 05:21:31 volumio volumio[635]: Upnp client error: Error: This socket has been ended by the other party
Apr 04 05:21:31 volumio sudo[854]: pam_unix(sudo:session): session closed for user root
Apr 04 05:21:31 volumio volumio[635]: error: updateQueue error: null
Apr 04 05:21:31 volumio volumio[635]: info: CoreCommandRouter::volumioGetState
Apr 04 05:21:31 volumio volumio[635]: info: CorePlayQueue::getTrack 0
Apr 04 05:21:31 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Apr 04 05:21:31 volumio volumio[635]: info: Listing playlists
Apr 04 05:21:31 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Apr 04 05:21:31 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Apr 04 05:21:31 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Apr 04 05:21:31 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Apr 04 05:21:31 volumio volumio[851]: Generating RSA private key, 4096 bit long modulus (2 primes)
Apr 04 05:21:32 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 04 05:21:32 volumio volumio[635]: info: go-librespot daemon successfully initialized
Apr 04 05:21:33 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken
Apr 04 05:21:34 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 04 05:21:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Apr 04 05:21:34 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 04 05:21:34 volumio systemd[1]: Started go-librespot Daemon.
Apr 04 05:21:34 volumio go-librespot[950]: Librespot-go daemon starting...
Apr 04 05:21:34 volumio go-librespot[950]: time="2023-04-04T05:21:34+02:00" level=info msg="generated new device id: 2047ac728aea43e2916b5e6ffbb1014acaccb6c7"
Apr 04 05:21:34 volumio go-librespot[950]: time="2023-04-04T05:21:34+02:00" level=debug msg="stored credentials found for lucillouu"
Apr 04 05:21:34 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 04 05:21:34 volumio go-librespot[950]: time="2023-04-04T05:21:34+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\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2023-04-04T05:21:34+02:00 is before 2024-02-05T00:00:00Z"
Apr 04 05:21:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 04 05:21:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 04 05:21:34 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken
Apr 04 05:21:35 volumio volumio[635]: info: CoreCommandRouter::volumioGetQueue
Apr 04 05:21:35 volumio volumio[635]: info: CoreStateMachine::getQueue
Apr 04 05:21:35 volumio volumio[635]: info: CorePlayQueue::getQueue
Apr 04 05:21:35 volumio volumio[635]: info: CoreCommandRouter::volumioGetVisibleSources
Apr 04 05:21:35 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 04 05:21:35 volumio volumio[635]: info: Initializing connection to go-librespot Websocket
Apr 04 05:21:35 volumio volumio[635]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 04 05:21:37 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 04 05:21:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Apr 04 05:21:37 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 04 05:21:37 volumio systemd[1]: Started go-librespot Daemon.
Apr 04 05:21:37 volumio go-librespot[958]: Librespot-go daemon starting...
Apr 04 05:21:37 volumio go-librespot[958]: time="2023-04-04T05:21:37+02:00" level=info msg="generated new device id: 0229bb2bd2d9822e65eef050daf3af324d6c6e36"
Apr 04 05:21:37 volumio go-librespot[958]: time="2023-04-04T05:21:37+02:00" level=debug msg="stored credentials found for lucillouu"
Apr 04 05:21:37 volumio go-librespot[958]: time="2023-04-04T05:21:37+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\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2023-04-04T05:21:37+02:00 is before 2024-02-05T00:00:00Z"
Apr 04 05:21:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 04 05:21:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 04 05:21:38 volumio volumio[635]: info: Initializing connection to go-librespot Websocket
Apr 04 05:21:38 volumio volumio[635]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 04 05:21:39 volumio volumio[851]: ...............................++++
Apr 04 05:21:41 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 04 05:21:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Apr 04 05:21:41 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 04 05:21:41 volumio systemd[1]: Started go-librespot Daemon.
Apr 04 05:21:41 volumio go-librespot[966]: Librespot-go daemon starting...
Apr 04 05:21:41 volumio go-librespot[966]: time="2023-04-04T05:21:41+02:00" level=info msg="generated new device id: bdbb1926d6e663b522181b673b5e49931f11016f"
Apr 04 05:21:41 volumio go-librespot[966]: time="2023-04-04T05:21:41+02:00" level=debug msg="stored credentials found for lucillouu"
Apr 04 05:21:41 volumio go-librespot[966]: time="2023-04-04T05:21:41+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\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2023-04-04T05:21:41+02:00 is before 2024-02-05T00:00:00Z"
Apr 04 05:21:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 04 05:21:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 04 05:21:41 volumio volumio[635]: info: Initializing connection to go-librespot Websocket
Apr 04 05:21:41 volumio volumio[635]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 04 05:21:44 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 04 05:21:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Apr 04 05:21:44 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 04 05:21:44 volumio systemd[1]: Started go-librespot Daemon.
Apr 04 05:21:44 volumio go-librespot[974]: Librespot-go daemon starting...
Apr 04 05:21:44 volumio go-librespot[974]: time="2023-04-04T05:21:44+02:00" level=info msg="generated new device id: b36712e1dbacb44d6d810c01cb0469755e14c7a4"
Apr 04 05:21:44 volumio go-librespot[974]: time="2023-04-04T05:21:44+02:00" level=debug msg="stored credentials found for lucillouu"
Apr 04 05:21:44 volumio volumio[635]: info: Initializing connection to go-librespot Websocket
Apr 04 05:21:44 volumio go-librespot[974]: time="2023-04-04T05:21:44+02:00" level=debug msg="new websocket client"
Apr 04 05:21:44 volumio volumio[635]: info: Connection to go-librespot Websocket established
Apr 04 05:21:45 volumio go-librespot[974]: time="2023-04-04T05:21: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\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2023-04-04T05:21:44+02:00 is before 2024-02-05T00:00:00Z"
Apr 04 05:21:45 volumio volumio[635]: info: Connection to go-librespot Websocket closed
Apr 04 05:21:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 04 05:21:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 04 05:21:47 volumio volumio[635]: info: Getting Spotify volume
Apr 04 05:21:47 volumio volumio[635]: (node:635) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 04 05:21:47 volumio volumio[635]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
Apr 04 05:21:47 volumio volumio[635]: (Use `node --trace-warnings ...` to show where the warning was created)
Apr 04 05:21:47 volumio volumio[635]: (node:635) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2)
Apr 04 05:21:47 volumio volumio[635]: (node:635) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
Apr 04 05:21:47 volumio volumio[635]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5
Apr 04 05:21:48 volumio volumio[635]: info: Initializing connection to go-librespot Websocket
Apr 04 05:21:48 volumio volumio[635]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 04 05:21:48 volumio volumio[635]: info: CoreCommandRouter::volumioGetState
Apr 04 05:21:48 volumio volumio[635]: info: CorePlayQueue::getTrack 0
Apr 04 05:21:48 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 04 05:21:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Apr 04 05:21:48 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 04 05:21:48 volumio systemd[1]: Started go-librespot Daemon.
Apr 04 05:21:48 volumio volumio[635]: SPOTIFY: RECEIVED VOLUMIO VOLUME 66
Apr 04 05:21:48 volumio volumio[635]: SPOTIFY: SPOTIFY VOLUME undefined
Apr 04 05:21:48 volumio volumio[635]: SPOTIFY: VOLUMIO VOLUME 66
Apr 04 05:21:48 volumio go-librespot[982]: Librespot-go daemon starting...
Apr 04 05:21:48 volumio volumio[635]: info: Aligning Spotify Volume to Volumio Volume
Apr 04 05:21:48 volumio volumio[635]: info: CoreCommandRouter::volumioGetState
Apr 04 05:21:48 volumio volumio[635]: info: CorePlayQueue::getTrack 0
Apr 04 05:21:48 volumio volumio[635]: info: Setting Spotify Volume from Volumio: 66
Apr 04 05:21:48 volumio go-librespot[982]: time="2023-04-04T05:21:48+02:00" level=info msg="generated new device id: 644cbc523ae2f2492e277a0a20772930aedfd3f9"
Apr 04 05:21:48 volumio go-librespot[982]: time="2023-04-04T05:21:48+02:00" level=debug msg="stored credentials found for lucillouu"
Apr 04 05:21:48 volumio go-librespot[982]: time="2023-04-04T05:21: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\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2023-04-04T05:21:48+02:00 is before 2024-02-05T00:00:00Z"
Apr 04 05:21:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 04 05:21:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 04 05:21:48 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Apr 04 05:21:48 volumio volumio[635]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Apr 04 05:21:48 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Apr 04 05:21:48 volumio volumio[635]: info: Received Get System Version
Apr 04 05:21:48 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 04 05:21:48 volumio volumio[635]: info: Received Get System Info
Apr 04 05:21:48 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 04 05:21:48 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 04 05:21:48 volumio volumio[635]: info: Discovery: Getting this device information
Apr 04 05:21:48 volumio volumio[635]: info: CoreCommandRouter::volumioGetState
Apr 04 05:21:48 volumio volumio[635]: info: CorePlayQueue::getTrack 0
Apr 04 05:21:48 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 04 05:21:49 volumio volumio[635]: SPOTIFY: SETTING SPOTIFY VOLUME 66
Apr 04 05:21:49 volumio volumio[635]: info: Sending Spotify command with payload to local API: /player/volume
Apr 04 05:21:49 volumio volumio[635]: error: Failed to send command to Spotify local API: /player/volume: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 04 05:21:51 volumio volumio[635]: info: Initializing connection to go-librespot Websocket
Apr 04 05:21:51 volumio volumio[635]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 04 05:21:51 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 04 05:21:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Apr 04 05:21:51 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 04 05:21:51 volumio systemd[1]: Started go-librespot Daemon.
Apr 04 05:21:51 volumio go-librespot[990]: Librespot-go daemon starting...
Apr 04 05:21:51 volumio go-librespot[990]: time="2023-04-04T05:21:51+02:00" level=info msg="generated new device id: 7178231a5eef4398c9e32292b82ecb8f7727b2f7"
Apr 04 05:21:51 volumio go-librespot[990]: time="2023-04-04T05:21:51+02:00" level=debug msg="stored credentials found for lucillouu"
Apr 04 05:21:51 volumio volumio[851]: .................................................++++
Apr 04 05:21:51 volumio volumio[851]: e is 65537 (0x010001)
Apr 04 05:21:51 volumio volumio[851]: writing RSA key
Apr 04 05:21:52 volumio go-librespot[990]: time="2023-04-04T05:21: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\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2023-04-04T05:21:51+02:00 is before 2024-02-05T00:00:00Z"
Apr 04 05:21:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 04 05:21:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 04 05:21:53 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Apr 04 05:21:53 volumio volumio[635]: info: CURURI: albums://
Apr 04 05:21:54 volumio volumio[635]: info: Initializing connection to go-librespot Websocket
Apr 04 05:21:54 volumio volumio[635]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 04 05:21:55 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 04 05:21:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Apr 04 05:21:55 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 04 05:21:55 volumio volumio[635]: info: Preload queue cleared
Apr 04 05:21:55 volumio systemd[1]: Started go-librespot Daemon.
Apr 04 05:21:55 volumio go-librespot[1026]: Librespot-go daemon starting...
Apr 04 05:21:55 volumio go-librespot[1026]: time="2023-04-04T05:21:55+02:00" level=info msg="generated new device id: ba11d26d1c467754d03d31315c1a8d5212a4561c"
Apr 04 05:21:55 volumio go-librespot[1026]: time="2023-04-04T05:21:55+02:00" level=debug msg="stored credentials found for lucillouu"
Apr 04 05:21:55 volumio go-librespot[1026]: time="2023-04-04T05:21:55+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\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2023-04-04T05:21:55+02:00 is before 2024-02-05T00:00:00Z"
Apr 04 05:21:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 04 05:21:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 04 05:21:57 volumio volumio[635]: info: Initializing connection to go-librespot Websocket
Apr 04 05:21:57 volumio volumio[635]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Apr 04 05:21:58 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Apr 04 05:21:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Apr 04 05:21:58 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 04 05:21:58 volumio systemd[1]: Started go-librespot Daemon.
Apr 04 05:21:58 volumio go-librespot[1034]: Librespot-go daemon starting...
Apr 04 05:21:58 volumio go-librespot[1034]: time="2023-04-04T05:21:58+02:00" level=info msg="generated new device id: 3abec738a5af499cf689c87c707768b56adb4135"
Apr 04 05:21:58 volumio go-librespot[1034]: time="2023-04-04T05:21:58+02:00" level=debug msg="stored credentials found for lucillouu"
Apr 04 05:21:59 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 04 05:21:59 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 04 05:21:59 volumio volumio[635]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Apr 04 05:21:59 volumio volumio[635]: error: Plugin music_service ytmusic failed to complete 'onStart' in a timely fashion
Apr 04 05:21:59 volumio volumio[635]: info: -------------------------------------------
Apr 04 05:21:59 volumio volumio[635]: info: ----- MyVolumio plugins startup ----
Apr 04 05:21:59 volumio volumio[635]: info: -------------------------------------------
Apr 04 05:21:59 volumio volumio[635]: info: [MyVolumio PluginManager] Fetching plans data....
Apr 04 05:21:59 volumio go-librespot[1034]: time="2023-04-04T05:21: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\": tls: failed to verify certificate: x509: certificate has expired or is not yet valid: current time 2023-04-04T05:21:58+02:00 is before 2024-02-05T00:00:00Z"
Apr 04 05:21:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Apr 04 05:21:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Apr 04 05:22:00 volumio volumio[635]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 04 05:22:00 volumio volumio[635]: Error: certificate is not yet valid
Apr 04 05:22:00 volumio volumio[635]: at TLSSocket.onConnectSecure (_tls_wrap.js:1497:34)
Apr 04 05:22:00 volumio volumio[635]: at TLSSocket.emit (events.js:315:20)
Apr 04 05:22:00 volumio volumio[635]: at TLSSocket._finishInit (_tls_wrap.js:932:8)
Apr 04 05:22:00 volumio volumio[635]: at TLSWrap.ssl.onhandshakedone (_tls_wrap.js:706:12) {
Apr 04 05:22:00 volumio volumio[635]: code: 'CERT_NOT_YET_VALID'
Apr 04 05:22:00 volumio volumio[635]: }
Apr 04 05:22:00 volumio volumio[635]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 04 05:22:01 volumio sudo[1053]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2023-04-04 05:21
Apr 04 05:22:01 volumio sudo[1053]: 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="c87c6e2b1ae33dc5801986cbcbe970898b92e7b4"
VOLUMIO_FE_VERSION="c433755e569617abac52264d17ad61be303ef463"
VOLUMIO_FE3_VERSION="2419ddd8e895c5bdc456962163c9dc7c0f187aa7"
VOLUMIO_BE_VERSION="b949d6001d7e656b4668f31c119d2247cdf45158"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu 30 Mar 2023 05:45:03 PM CEST"
VOLUMIO_VERSION="3.449"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="6428d8e2c06e98483f5c5d77e8f01989"