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