-- Logs begin at Thu 2019-02-14 05:11:58 EST, end at Fri 2025-03-14 12:41:58 EDT. -- Mar 14 12:41:15 volumio systemd-timedated[1029]: Changed local time to Fri Mar 14 12:41:15 2025 Mar 14 12:41:15 volumio sudo[1024]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:15 volumio volumio-time-update[573]: volumio-time-update-util: System time updated successfully. Mar 14 12:41:15 volumio systemd[1]: Starting Daily apt download activities... Mar 14 12:41:15 volumio systemd[1]: Started Volumio Time Update Utility. Mar 14 12:41:15 volumio wpa_supplicant[862]: RRM: Ignoring radio measurement request: Not RRM network Mar 14 12:41:15 volumio wireless.js[569]: trying... Mar 14 12:41:15 volumio sudo[1052]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Mar 14 12:41:15 volumio sudo[1052]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:15 volumio sudo[1052]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:16 volumio wireless.js[569]: trying... Mar 14 12:41:16 volumio sudo[1074]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Mar 14 12:41:16 volumio sudo[1074]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:16 volumio sudo[1074]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:16 volumio systemd[1]: apt-daily.service: Succeeded. Mar 14 12:41:16 volumio systemd[1]: Started Daily apt download activities. Mar 14 12:41:16 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Mar 14 12:41:17 volumio wireless.js[569]: trying... Mar 14 12:41:17 volumio sudo[1118]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Mar 14 12:41:17 volumio sudo[1118]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:17 volumio sudo[1118]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:18 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Mar 14 12:41:18 volumio systemd[1]: Started Daily apt upgrade and clean activities. Mar 14 12:41:18 volumio wireless.js[569]: trying... Mar 14 12:41:18 volumio sudo[1139]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Mar 14 12:41:18 volumio sudo[1139]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:18 volumio sudo[1139]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:19 volumio dhcpcd[960]: wlan0: leased 192.168.1.25 for 86400 seconds Mar 14 12:41:19 volumio avahi-daemon[595]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.25. Mar 14 12:41:19 volumio dhcpcd[960]: wlan0: adding route to 192.168.1.0/24 Mar 14 12:41:19 volumio dhcpcd[960]: wlan0: adding default route via 192.168.1.1 Mar 14 12:41:19 volumio avahi-daemon[595]: New relevant interface wlan0.IPv4 for mDNS. Mar 14 12:41:19 volumio avahi-daemon[595]: Registering new address record for 192.168.1.25 on wlan0.IPv4. Mar 14 12:41:19 volumio wireless.js[569]: trying... Mar 14 12:41:19 volumio sudo[1163]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Mar 14 12:41:19 volumio sudo[1163]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:19 volumio sudo[1163]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:19 volumio wireless.js[569]: Connected to: ----M&G_ORBI60 Mar 14 12:41:19 volumio wireless.js[569]: ---- Mar 14 12:41:19 volumio sudo[1166]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 14 12:41:19 volumio sudo[1166]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:19 volumio sudo[1166]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:19 volumio wireless.js[569]: ... joined AP, wlan0 IPv4 is 192.168.1.25, ipV6 is undefined Mar 14 12:41:19 volumio wireless.js[569]: It's done! AP Mar 14 12:41:19 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Mar 14 12:41:19 volumio systemd[1]: Started Wireless Services. Mar 14 12:41:19 volumio systemd[1]: Started Volumio Backend Module. Mar 14 12:41:19 volumio systemd[1]: Started Volumio Cpu Tweaker. Mar 14 12:41:19 volumio systemd[1]: Reached target Multi-User System. Mar 14 12:41:19 volumio systemd[1]: Reached target Graphical Interface. Mar 14 12:41:19 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Mar 14 12:41:20 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Mar 14 12:41:20 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Mar 14 12:41:20 volumio systemd[1]: Startup finished in 12.003s (kernel) + 24.274s (userspace) = 36.277s. Mar 14 12:41:20 volumio volumio-cpu-tweak[1172]: Setting RT Priority for mpd Mar 14 12:41:20 volumio volumio-cpu-tweak[1172]: Setting MPD Affinity Mar 14 12:41:20 volumio volumio-cpu-tweak[1172]: pid 777's current affinity mask: f Mar 14 12:41:20 volumio volumio-cpu-tweak[1172]: pid 777's new affinity mask: 3 Mar 14 12:41:20 volumio volumio-cpu-tweak[1172]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Mar 14 12:41:20 volumio volumio-cpu-tweak[1172]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Mar 14 12:41:20 volumio systemd[1]: volumio_cpu_tweak.service: Succeeded. Mar 14 12:41:21 volumio ntpd[755]: Listen normally on 4 wlan0 192.168.1.25:123 Mar 14 12:41:21 volumio ntpd[755]: new interface(s) found: waking up resolver Mar 14 12:41:21 volumio volumio[1171]: info: ------------------------------------------- Mar 14 12:41:21 volumio volumio[1171]: info: ----- Volumio3 ---- Mar 14 12:41:21 volumio volumio[1171]: info: ------------------------------------------- Mar 14 12:41:21 volumio volumio[1171]: info: ----- System startup ---- Mar 14 12:41:21 volumio volumio[1171]: info: ------------------------------------------- Mar 14 12:41:21 volumio volumio-remote-updater[592]: [2025-03-14 12:41:21] [connect] Successful connection Mar 14 12:41:22 volumio volumio[1171]: info: MYVOLUMIO Environment detected Mar 14 12:41:22 volumio volumio[1171]: info: Plugin folders cleanup Mar 14 12:41:22 volumio volumio[1171]: info: Scanning into folder /volumio/app/plugins/ Mar 14 12:41:22 volumio volumio[1171]: info: Scanning category audio_interface Mar 14 12:41:22 volumio volumio[1171]: info: Scanning category miscellanea Mar 14 12:41:22 volumio volumio[1171]: info: Scanning category music_service Mar 14 12:41:22 volumio volumio[1171]: info: Scanning category plugins.json Mar 14 12:41:22 volumio volumio[1171]: info: Scanning category system_controller Mar 14 12:41:22 volumio volumio[1171]: info: Scanning category user_interface Mar 14 12:41:22 volumio volumio[1171]: info: Scanning into folder /data/plugins/ Mar 14 12:41:22 volumio volumio[1171]: info: Scanning category music_service Mar 14 12:41:22 volumio volumio[1171]: info: Plugin folders cleanup completed Mar 14 12:41:22 volumio volumio[1171]: info: ------------------------------------------- Mar 14 12:41:22 volumio volumio[1171]: info: ----- Core plugins startup ---- Mar 14 12:41:22 volumio volumio[1171]: info: ------------------------------------------- Mar 14 12:41:22 volumio volumio[1171]: info: Loading plugins from folder /volumio/app/plugins/ Mar 14 12:41:22 volumio volumio[1171]: info: Adding plugin upnp to MyMusic Plugins Mar 14 12:41:22 volumio volumio[1171]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 14 12:41:22 volumio volumio[1171]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 14 12:41:22 volumio volumio[1171]: info: Loading plugins from folder /data/plugins/ Mar 14 12:41:22 volumio volumio[1171]: info: Loading plugin "system"... Mar 14 12:41:22 volumio volumio[1171]: info: Loading plugin "appearance"... Mar 14 12:41:23 volumio volumio[1171]: info: Loading plugin "network"... Mar 14 12:41:23 volumio volumio[1171]: info: Refreshing Cached IP Addresses Mar 14 12:41:23 volumio sudo[1206]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 14 12:41:23 volumio sudo[1206]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:23 volumio sudo[1206]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:23 volumio sudo[1208]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 14 12:41:23 volumio sudo[1208]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:23 volumio sudo[1208]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:23 volumio volumio[1171]: info: Loading plugin "services"... Mar 14 12:41:23 volumio volumio[1171]: info: Loading plugin "alsa_controller"... Mar 14 12:41:23 volumio sudo[1218]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 14 12:41:23 volumio sudo[1218]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:23 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 14 12:41:23 volumio volumio[1171]: info: Loading plugin "wizard"... Mar 14 12:41:23 volumio volumio[1171]: info: Loading plugin "networkfs"... Mar 14 12:41:23 volumio volumio[1171]: info: Starting Udev Watcher for removable devices Mar 14 12:41:23 volumio sudo[1234]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Gary Cattabriga,password=oglala.666,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.254/RAID_5\\Music /mnt/NAS/raid_5 Mar 14 12:41:23 volumio sudo[1234]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:23 volumio volumio[1171]: info: Ignoring mount for partition: boot Mar 14 12:41:23 volumio volumio[1171]: info: Ignoring mount for partition: volumio Mar 14 12:41:23 volumio volumio[1171]: info: Ignoring mount for partition: volumio_data Mar 14 12:41:23 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 14 12:41:23 volumio volumio[1171]: info: Loading plugin "volumio_command_line_client"... Mar 14 12:41:23 volumio volumio[1171]: info: Loading plugin "upnp"... Mar 14 12:41:23 volumio volumio[1171]: info: [1741970483745] Starting Upmpd Daemon Mar 14 12:41:23 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 14 12:41:23 volumio volumio[1171]: info: Loading plugin "my_music"... Mar 14 12:41:23 volumio volumio[1171]: info: Loading plugin "mpd"... Mar 14 12:41:23 volumio kernel: Key type cifs.spnego registered Mar 14 12:41:23 volumio kernel: Key type cifs.idmap registered Mar 14 12:41:23 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. Mar 14 12:41:23 volumio kernel: CIFS: Attempting to mount //192.168.1.254/RAID_5/Music Mar 14 12:41:24 volumio volumio[1171]: info: Loading plugin "upnp_browser"... Mar 14 12:41:24 volumio volumio[1171]: info: Loading plugin "alarm-clock"... Mar 14 12:41:24 volumio volumio[1171]: info: Loading plugin "airplay_emulation"... Mar 14 12:41:24 volumio volumio[1171]: info: Starting Shairport Sync Mar 14 12:41:24 volumio volumio[1171]: info: Loading plugin "last_100"... Mar 14 12:41:24 volumio volumio[1171]: info: Loading plugin "webradio"... Mar 14 12:41:24 volumio volumio[1171]: info: Loading plugin "i2s_dacs"... Mar 14 12:41:24 volumio volumio[1171]: info: Loading plugin "volumiodiscovery"... Mar 14 12:41:24 volumio volumio[1171]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 14 12:41:24 volumio volumio[1171]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 14 12:41:24 volumio node[1171]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 14 12:41:24 volumio volumio[1171]: *** WARNING *** For more information see Mar 14 12:41:24 volumio volumio[1171]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 14 12:41:24 volumio volumio[1171]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 14 12:41:24 volumio volumio[1171]: *** WARNING *** For more information see Mar 14 12:41:24 volumio node[1171]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 14 12:41:24 volumio node[1171]: *** WARNING *** For more information see Mar 14 12:41:24 volumio node[1171]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 14 12:41:24 volumio node[1171]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 14 12:41:24 volumio node[1171]: *** WARNING *** For more information see Mar 14 12:41:24 volumio volumio[1171]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 14 12:41:24 volumio volumio[1171]: info: Discovery: Started advertising with name: Volumio Mar 14 12:41:24 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 14 12:41:24 volumio volumio[1171]: info: Loading plugin "mixcloud"... Mar 14 12:41:25 volumio volumio[1171]: info: Loading plugin "spop"... Mar 14 12:41:26 volumio volumio[1171]: info: Loading plugin "ytmusic"... Mar 14 12:41:27 volumio sudo[1218]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:28 volumio systemd[1]: systemd-fsckd.service: Succeeded. Mar 14 12:41:28 volumio volumio[1171]: info: Loading plugin "outputs"... Mar 14 12:41:28 volumio volumio[1171]: info: Loading plugin "albumart"... Mar 14 12:41:28 volumio volumio[1171]: info: Plugin example_plugin is not enabled Mar 14 12:41:28 volumio volumio[1171]: info: Loading plugin "inputs"... Mar 14 12:41:28 volumio volumio[1171]: info: Loading plugin "updater_comm"... Mar 14 12:41:28 volumio volumio[1171]: info: Plugin mpdemulation is not enabled Mar 14 12:41:28 volumio volumio[1171]: info: Loading plugin "rest_api"... Mar 14 12:41:28 volumio volumio[1171]: info: Loading plugin "websocket"... Mar 14 12:41:28 volumio volumio[1171]: info: Starting Socket.io Server version 2.3.0 Mar 14 12:41:28 volumio volumio[1171]: info: Loading plugin "80s80s"... Mar 14 12:41:28 volumio volumio[1171]: Forking 3 albumart workers Mar 14 12:41:29 volumio volumio[1171]: info: Applying required configuration parameters for plugin 80s80s Mar 14 12:41:29 volumio volumio[1171]: info: [1741970489179] [80s80s] API delay: 30 Mar 14 12:41:29 volumio volumio[1171]: info: Loading plugin "motherearthradio"... Mar 14 12:41:29 volumio volumio[1171]: Starting albumart workers Mar 14 12:41:29 volumio volumio[1171]: Starting albumart workers Mar 14 12:41:29 volumio volumio[1171]: Starting albumart workers Mar 14 12:41:29 volumio volumio[1171]: info: Applying required configuration parameters for plugin motherearthradio Mar 14 12:41:29 volumio volumio[1171]: info: [1741970489478] [MotherEarth] API delay: 5 Mar 14 12:41:29 volumio volumio[1171]: info: Loading plugin "radio_paradise"... Mar 14 12:41:29 volumio volumio[1171]: info: Applying required configuration parameters for plugin radio_paradise Mar 14 12:41:29 volumio volumio[1171]: info: [1741970489840] [RadioParadise] API delay: 5 Mar 14 12:41:29 volumio volumio[1171]: info: Loading i18n strings for locale en Mar 14 12:41:29 volumio volumio[1171]: Updating browse sources language Mar 14 12:41:29 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::initPlayerControls Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 14 12:41:30 volumio volumio[1171]: Express server listening on port 3000 Mar 14 12:41:30 volumio volumio[1171]: [Metrics] WebUI: 9s 22.23ms Mar 14 12:41:30 volumio volumio[1171]: info: CoreStateMachine::resetVolumioState Mar 14 12:41:30 volumio volumio[1171]: info: CoreStateMachine::getcurrentVolume Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::volumioRetrievevolume Mar 14 12:41:30 volumio volumio[1171]: info: Volumio Network Manager: Network status updated: 3 Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 14 12:41:30 volumio volumio[1171]: info: Reloading queue from file Mar 14 12:41:30 volumio volumio[1171]: info: Setting Device type: Raspberry PI Mar 14 12:41:30 volumio volumio[1171]: info: VolumeController:: Volume=100 Mute =true Mar 14 12:41:30 volumio volumio[1171]: info: CoreStateMachine::pushState Mar 14 12:41:30 volumio volumio[1171]: info: CorePlayQueue::getTrack 0 Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::volumioPushState Mar 14 12:41:30 volumio volumio[1171]: info: CoreStateMachine::updateTrackBlock Mar 14 12:41:30 volumio volumio[1171]: info: CorePlayQueue::getTrackBlock Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::volumioRetrievevolume Mar 14 12:41:30 volumio volumio[1171]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Mar 14 12:41:30 volumio volumio[1171]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03115 Mar 14 12:41:30 volumio volumio[1171]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Mar 14 12:41:30 volumio volumio[1171]: info: CoreStateMachine::setRepeat null single undefined Mar 14 12:41:30 volumio volumio[1171]: info: CoreStateMachine::pushState Mar 14 12:41:30 volumio volumio[1171]: info: CorePlayQueue::getTrack 0 Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::volumioPushState Mar 14 12:41:30 volumio volumio[1171]: info: CoreStateMachine::setRandom null Mar 14 12:41:30 volumio volumio[1171]: info: CoreStateMachine::pushState Mar 14 12:41:30 volumio volumio[1171]: info: CorePlayQueue::getTrack 0 Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::volumioPushState Mar 14 12:41:30 volumio volumio[1171]: info: Discovery: adding db675ebc-0b50-4458-9cc5-1e19959a367c Mar 14 12:41:30 volumio volumio[1171]: info: Discovery: Found device Volumio Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::volumioGetState Mar 14 12:41:30 volumio volumio[1171]: info: CorePlayQueue::getTrack 0 Mar 14 12:41:30 volumio volumio[1171]: info: Discovery: this is already registered, db675ebc-0b50-4458-9cc5-1e19959a367c Mar 14 12:41:30 volumio volumio[1171]: info: Discovery: Found device Volumio Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::volumioGetState Mar 14 12:41:30 volumio volumio[1171]: info: CorePlayQueue::getTrack 0 Mar 14 12:41:30 volumio volumio[1171]: info: VolumeController:: Volume=100 Mute =true Mar 14 12:41:30 volumio volumio[1171]: info: CoreStateMachine::pushState Mar 14 12:41:30 volumio volumio[1171]: info: CorePlayQueue::getTrack 0 Mar 14 12:41:30 volumio volumio[1171]: info: CoreCommandRouter::volumioPushState Mar 14 12:41:30 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Mar 14 12:41:33 volumio sudo[1345]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 14 12:41:33 volumio sudo[1345]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:33 volumio sudo[1345]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:33 volumio sudo[1347]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 14 12:41:33 volumio sudo[1347]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:33 volumio sudo[1347]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:33 volumio sudo[1351]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 14 12:41:33 volumio sudo[1351]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:33 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Mar 14 12:41:33 volumio sudo[1351]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:33 volumio volumio[1171]: info: Upmpdcli Daemon Started Mar 14 12:41:33 volumio volumio[1353]: Generating RSA private key, 4096 bit long modulus (2 primes) Mar 14 12:41:36 volumio volumio-remote-updater[592]: [2025-03-14 12:41:36] [connect] Successful connection Mar 14 12:41:36 volumio volumio-remote-updater[592]: [2025-03-14 12:41:36] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1741970496 101 Mar 14 12:41:36 volumio volumio[1171]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Mar 14 12:41:39 volumio volumio[1353]: .................................................................++++ Mar 14 12:41:42 volumio volumio[1353]: ......................++++ Mar 14 12:41:42 volumio volumio[1353]: e is 65537 (0x010001) Mar 14 12:41:42 volumio volumio[1353]: writing RSA key Mar 14 12:41:45 volumio systemd[1]: systemd-timedated.service: Succeeded. Mar 14 12:41:46 volumio sudo[1234]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:46 volumio volumio[1171]: info: Completed loading Core Plugins Mar 14 12:41:46 volumio volumio[1171]: info: Preparing to generate the ALSA configuration file Mar 14 12:41:46 volumio volumio[1171]: info: Asound.conf file written Mar 14 12:41:46 volumio sudo[1415]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Mar 14 12:41:46 volumio sudo[1415]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:46 volumio sudo[1415]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:46 volumio volumio[1171]: info: Output device has changed, restarting MPD Mar 14 12:41:46 volumio sudo[1420]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 14 12:41:46 volumio sudo[1420]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:46 volumio volumio[1171]: info: Output device has changed, restarting Shairport Sync Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 14 12:41:46 volumio sudo[1420]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:46 volumio sudo[1422]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 14 12:41:46 volumio sudo[1422]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:46 volumio systemd[1]: Stopping Music Player Daemon... Mar 14 12:41:46 volumio volumio[1171]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 14 12:41:46 volumio volumio[1171]: info: ___________ START PLUGINS ___________ Mar 14 12:41:46 volumio volumio[1171]: info: ControllerMpd::onStart: Initializing MPD Mar 14 12:41:46 volumio volumio[1171]: info: Creating MPD Configuration file Mar 14 12:41:46 volumio sudo[1429]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 14 12:41:46 volumio volumio[1171]: info: [1741970506579] CoreMusicLibrary::Adding element Media Servers Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 14 12:41:46 volumio sudo[1429]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:46 volumio sudo[1431]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 14 12:41:46 volumio sudo[1431]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:46 volumio sudo[1429]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 14 12:41:46 volumio systemd[1]: mpd.service: Succeeded. Mar 14 12:41:46 volumio systemd[1]: Stopped Music Player Daemon. Mar 14 12:41:46 volumio volumio[1171]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 14 12:41:46 volumio volumio[1171]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 14 12:41:46 volumio volumio[1171]: info: [1741970506677] CoreMusicLibrary::Adding element Last_100 Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 14 12:41:46 volumio volumio[1171]: info: [1741970506679] CoreMusicLibrary::Adding element Webradio Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 14 12:41:46 volumio volumio[1171]: info: Initializing BBC Radios Mar 14 12:41:46 volumio systemd[1]: Starting Music Player Daemon... Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 14 12:41:46 volumio sudo[1437]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 14 12:41:46 volumio sudo[1437]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 14 12:41:46 volumio volumio[1171]: info: [1741970506770] CoreMusicLibrary::Adding element Mixcloud Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 14 12:41:46 volumio volumio[1171]: Cannot find translation for source Mixcloud Mar 14 12:41:46 volumio sudo[1437]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:46 volumio volumio[1171]: info: Creating Spotify config file Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 14 12:41:46 volumio volumio[1171]: info: [1741970506854] CoreMusicLibrary::Adding element YouTube Music Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 14 12:41:46 volumio volumio[1171]: Cannot find translation for source Mixcloud Mar 14 12:41:46 volumio volumio[1171]: Cannot find translation for source YouTube Music Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 14 12:41:46 volumio volumio[1171]: info: [1741970506865] CoreMusicLibrary::Adding element 80s80s Radio Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 14 12:41:46 volumio volumio[1171]: Cannot find translation for source Mixcloud Mar 14 12:41:46 volumio volumio[1171]: Cannot find translation for source YouTube Music Mar 14 12:41:46 volumio volumio[1171]: Cannot find translation for source 80s80s Radio Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 14 12:41:46 volumio volumio[1171]: info: [1741970506872] CoreMusicLibrary::Adding element Mother Earth Radio Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 14 12:41:46 volumio volumio[1171]: Cannot find translation for source Mixcloud Mar 14 12:41:46 volumio volumio[1171]: Cannot find translation for source YouTube Music Mar 14 12:41:46 volumio volumio[1171]: Cannot find translation for source 80s80s Radio Mar 14 12:41:46 volumio volumio[1171]: Cannot find translation for source Mother Earth Radio Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 14 12:41:46 volumio volumio[1171]: info: [1741970506878] CoreMusicLibrary::Adding element Radio Paradise Mar 14 12:41:46 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 14 12:41:46 volumio volumio[1171]: Cannot find translation for source Mixcloud Mar 14 12:41:46 volumio volumio[1171]: Cannot find translation for source YouTube Music Mar 14 12:41:46 volumio volumio[1171]: Cannot find translation for source 80s80s Radio Mar 14 12:41:46 volumio volumio[1171]: Cannot find translation for source Mother Earth Radio Mar 14 12:41:46 volumio volumio[1171]: Cannot find translation for source Radio Paradise Mar 14 12:41:46 volumio volumio[1171]: info: Volumio Calling Home Mar 14 12:41:46 volumio volumio[1171]: info: MPD Permissions set Mar 14 12:41:46 volumio volumio[1171]: info: MPD Permissions set Mar 14 12:41:47 volumio volumio[1171]: info: Spotify config file written Mar 14 12:41:47 volumio sudo[1457]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 14 12:41:47 volumio sudo[1457]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:47 volumio volumio[1171]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 14 12:41:47 volumio volumio[1171]: info: No need to fix Spotify hosts Mar 14 12:41:47 volumio systemd[1]: Started go-librespot Daemon. Mar 14 12:41:47 volumio go-librespot[1463]: Librespot-go daemon starting... Mar 14 12:41:47 volumio sudo[1457]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:47 volumio volumio[1171]: info: Volumio called home Mar 14 12:41:47 volumio volumio[1171]: info: Starting Shairport Sync Mar 14 12:41:47 volumio volumio[1171]: info: Starting Shairport Sync Mar 14 12:41:47 volumio sudo[1474]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 14 12:41:47 volumio volumio[1171]: info: Starting Shairport Sync Mar 14 12:41:47 volumio sudo[1474]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:47 volumio sudo[1477]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 14 12:41:47 volumio sudo[1477]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:47 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 14 12:41:47 volumio systemd[1]: shairport-sync.service: Succeeded. Mar 14 12:41:47 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 14 12:41:47 volumio sudo[1480]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 14 12:41:47 volumio sudo[1480]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::volumioGetState Mar 14 12:41:47 volumio volumio[1171]: info: CorePlayQueue::getTrack 0 Mar 14 12:41:47 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 14 12:41:47 volumio sudo[1474]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:47 volumio sudo[1480]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:47 volumio sudo[1477]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:47 volumio volumio[1171]: info: Shairport-Sync Started Mar 14 12:41:47 volumio volumio[1171]: Error adding Membership: Error: addMembership EINVAL Mar 14 12:41:47 volumio volumio[1171]: info: Shairport-Sync Started Mar 14 12:41:47 volumio volumio[1171]: info: Shairport-Sync Started Mar 14 12:41:47 volumio volumio[1171]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 14 12:41:47 volumio volumio[1171]: SPOTIFY: BQAHaj4ZJmvrWGmutAzBC0YC8dBTYwph6qNQCrvapOgRio76ky59HQ-7i9Px8IHDvuIXu3R6WJd0KMPkBW9jYdPGuq7EQG3wlXQrbvdQbBEKDzhM8u5Epnw80UxhZjK44IQB5U8_ezH-BMTRCgtryCSAfZodvUHKYyGRNdQhTU0311aUNSyc9GD6vnGNAdWqB-4OI-z-MSQIa8K62OMW9V5ZklwBnBK9doM5X5ORpUIBmT2KT79RC-NUxAnoXH1rrVijK0y2MIZwWmNnSEw Mar 14 12:41:47 volumio volumio[1171]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 14 12:41:47 volumio volumio[1171]: info: New Spotify access token = BQAHaj4ZJmvrWGmutAzBC0YC8dBTYwph6qNQCrvapOgRio76ky59HQ-7i9Px8IHDvuIXu3R6WJd0KMPkBW9jYdPGuq7EQG3wlXQrbvdQbBEKDzhM8u5Epnw80UxhZjK44IQB5U8_ezH-BMTRCgtryCSAfZodvUHKYyGRNdQhTU0311aUNSyc9GD6vnGNAdWqB-4OI-z-MSQIa8K62OMW9V5ZklwBnBK9doM5X5ORpUIBmT2KT79RC-NUxAnoXH1rrVijK0y2MIZwWmNnSEw Mar 14 12:41:47 volumio volumio[1171]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 14 12:41:47 volumio go-librespot[1463]: time="2025-03-14T12:41:47-04:00" level=info msg="generated new device id: 64ccc10d4c2875e02fed52ba859a8e9857918f0e" Mar 14 12:41:47 volumio go-librespot[1463]: time="2025-03-14T12:41:47-04:00" level=debug msg="stored credentials found for 1213455816" Mar 14 12:41:47 volumio mpd[1452]: Mar 14 12:41 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 14 12:41:47 volumio volumio[1171]: SPOTIFY: User informations: {"country":"US","display_name":"Gary C","email":"gcatabr1@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/1213455816"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/1213455816","id":"1213455816","images":[],"product":"premium","type":"user","uri":"spotify:user:1213455816"} Mar 14 12:41:47 volumio volumio[1171]: info: Spotify Successfully logged in Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 14 12:41:47 volumio volumio[1171]: info: [1741970507644] CoreMusicLibrary::Adding element Spotify Mar 14 12:41:47 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 14 12:41:47 volumio volumio[1171]: Cannot find translation for source Mixcloud Mar 14 12:41:47 volumio volumio[1171]: Cannot find translation for source YouTube Music Mar 14 12:41:47 volumio volumio[1171]: Cannot find translation for source 80s80s Radio Mar 14 12:41:47 volumio volumio[1171]: Cannot find translation for source Mother Earth Radio Mar 14 12:41:47 volumio volumio[1171]: Cannot find translation for source Radio Paradise Mar 14 12:41:47 volumio volumio[1171]: Cannot find translation for source Spotify Mar 14 12:41:47 volumio systemd[1]: Started Music Player Daemon. Mar 14 12:41:47 volumio sudo[1431]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:47 volumio sudo[1422]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:47 volumio volumio[1171]: info: Completed starting Core Plugins Mar 14 12:41:47 volumio volumio[1171]: info: ------------------------------------------- Mar 14 12:41:47 volumio volumio[1171]: info: ----- MyVolumio plugins startup ---- Mar 14 12:41:47 volumio volumio[1171]: info: ------------------------------------------- Mar 14 12:41:47 volumio volumio[1171]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 14 12:41:47 volumio volumio[1171]: info: MPD running with PID1452 Mar 14 12:41:47 volumio volumio[1171]: ,establishing connection Mar 14 12:41:47 volumio go-librespot[1463]: time="2025-03-14T12:41:47-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Mar 14 12:41:47 volumio go-librespot[1463]: time="2025-03-14T12:41:47-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Mar 14 12:41:47 volumio go-librespot[1463]: time="2025-03-14T12:41:47-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Mar 14 12:41:47 volumio go-librespot[1463]: time="2025-03-14T12:41:47-04:00" level=debug msg="zeroconf server listening on port 35373" Mar 14 12:41:47 volumio volumio[1171]: error: MPD error: The expression evaluated to a falsy value: Mar 14 12:41:47 volumio volumio[1171]: assert.ok(self.idling) Mar 14 12:41:47 volumio volumio[1171]: error: The expression evaluated to a falsy value: Mar 14 12:41:47 volumio volumio[1171]: assert.ok(self.idling) Mar 14 12:41:47 volumio volumio[1171]: error: MPD error: The expression evaluated to a falsy value: Mar 14 12:41:47 volumio volumio[1171]: assert.ok(self.idling) Mar 14 12:41:47 volumio volumio[1171]: error: The expression evaluated to a falsy value: Mar 14 12:41:47 volumio volumio[1171]: assert.ok(self.idling) Mar 14 12:41:47 volumio volumio[1171]: error: updateQueue error: null Mar 14 12:41:47 volumio go-librespot[1463]: time="2025-03-14T12:41:47-04:00" level=debug msg="obtained new client token: AACaZs3g7iHgqUr+xEqT2BUZJ6lzURrJS3OqJZEb3VvGntrqwFh32S/kzbDNDJC19Xc1RoJgMZ1VtZ8k7sFgUC9jgBC1G/1ME2ZxJo+GcT6oJngDSq1BpNidsktvt4WffsfsbpkL6iiCN3UuLdmb/0z5gv22hYkqPhPSsqL8uNP2P8fZ1dnVvPUUY8eRTtBT1kO982oYvPj6wSbyp4htkUjUZQPA6NTkQcC560TLjEn++gbMdXdeQGyfbXhiZQ==" Mar 14 12:41:47 volumio go-librespot[1463]: time="2025-03-14T12:41:47-04:00" level=info msg="connected to ap-gue1.spotify.com:4070" Mar 14 12:41:47 volumio go-librespot[1463]: time="2025-03-14T12:41:47-04:00" level=debug msg="completed keyexchange" Mar 14 12:41:48 volumio go-librespot[1463]: time="2025-03-14T12:41:48-04:00" level=debug msg="completed challenge" Mar 14 12:41:48 volumio go-librespot[1463]: time="2025-03-14T12:41:48-04:00" level=debug msg="authenticated as 1213455816" Mar 14 12:41:48 volumio go-librespot[1463]: time="2025-03-14T12:41:48-04:00" level=debug msg="authenticated as 1213455816" Mar 14 12:41:48 volumio go-librespot[1463]: time="2025-03-14T12:41:48-04:00" level=debug msg="dealer connection opened" Mar 14 12:41:48 volumio go-librespot[1463]: time="2025-03-14T12:41:48-04:00" level=debug msg="initializing zeroconf session, username: 1213455816" Mar 14 12:41:48 volumio go-librespot[1463]: time="2025-03-14T12:41:48-04:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 14 12:41:48 volumio go-librespot[1463]: time="2025-03-14T12:41:48-04:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 14 12:41:48 volumio go-librespot[1463]: time="2025-03-14T12:41:48-04:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 14 12:41:48 volumio go-librespot[1463]: time="2025-03-14T12:41:48-04:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 14 12:41:48 volumio go-librespot[1463]: time="2025-03-14T12:41:48-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 14 12:41:48 volumio go-librespot[1463]: time="2025-03-14T12:41:48-04:00" level=debug msg="autoplay enabled: false" Mar 14 12:41:48 volumio go-librespot[1463]: time="2025-03-14T12:41:48-04:00" level=debug msg="received connection id: NmMyYzBkZGQtM2NhMy00N2FlLWJlN2EtZWE5ZDMzMjU5NWM5K2RlYWxlcit0Y3A6Ly8wYWNiZmE3Yy5pcC5ndWUxLnNwb3RpZnkubmV0OjU3MDArMUVDN0Y1Nzc4NDkyRkQxNzU0RUM2QTdERTQxNzRFMDgzMDBEMTRBOUMyMDkxMDdFMUIxMjlGMkJBNkIzNzExRQ==" Mar 14 12:41:48 volumio go-librespot[1463]: time="2025-03-14T12:41:48-04:00" level=debug msg="put connect state because NEW_DEVICE" Mar 14 12:41:50 volumio volumio[1171]: info: go-librespot daemon successfully initialized Mar 14 12:41:52 volumio volumio[1171]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 14 12:41:53 volumio volumio[1171]: info: Initializing connection to go-librespot Websocket Mar 14 12:41:53 volumio go-librespot[1463]: time="2025-03-14T12:41:53-04:00" level=debug msg="new websocket client" Mar 14 12:41:53 volumio volumio[1171]: info: Connection to go-librespot Websocket established Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 14 12:41:56 volumio volumio[1171]: info: Adding plugin bluetooth to MyMusic Plugins Mar 14 12:41:56 volumio volumio[1171]: info: Adding plugin multiroom to MyMusic Plugins Mar 14 12:41:56 volumio volumio[1171]: info: Adding plugin metavolumio to MyMusic Plugins Mar 14 12:41:56 volumio volumio[1171]: info: Adding plugin cd_controller to MyMusic Plugins Mar 14 12:41:56 volumio volumio[1171]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 14 12:41:56 volumio volumio[1171]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 14 12:41:56 volumio go-librespot[1463]: time="2025-03-14T12:41:56-04:00" level=debug msg="handling transfer player command from 3c9ed9dd8757ab4bb918bcd3f41392dbc51ca3ca" Mar 14 12:41:56 volumio go-librespot[1463]: time="2025-03-14T12:41:56-04:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZF1DWZtZ8vUCzche" Mar 14 12:41:56 volumio go-librespot[1463]: time="2025-03-14T12:41:56-04:00" level=trace msg="fetched new page 0 with 200 items (list: 200)" uri="spotify:playlist:37i9dQZF1DWZtZ8vUCzche" Mar 14 12:41:56 volumio go-librespot[1463]: time="2025-03-14T12:41:56-04:00" level=debug msg="loading track (paused: false, position: 243456ms)" uri="spotify:track:6bzwsAtj4TqaBysLDrGiO3" Mar 14 12:41:56 volumio go-librespot[1463]: time="2025-03-14T12:41:56-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 14 12:41:56 volumio go-librespot[1463]: time="2025-03-14T12:41:56-04:00" level=trace msg="emitting websocket event: will_play" Mar 14 12:41:56 volumio go-librespot[1463]: time="2025-03-14T12:41:56-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Mar 14 12:41:56 volumio go-librespot[1463]: time="2025-03-14T12:41:56-04:00" level=debug msg="selected format OGG_VORBIS_320 (6343bca74923a6683cb2b25877dafcc6f4c3182b)" uri="spotify:track:6bzwsAtj4TqaBysLDrGiO3" Mar 14 12:41:56 volumio go-librespot[1463]: time="2025-03-14T12:41:56-04:00" level=debug msg="requested aes key for file 6343bca74923a6683cb2b25877dafcc6f4c3182b, gid: 6bzwsAtj4TqaBysLDrGiO3" Mar 14 12:41:56 volumio go-librespot[1463]: time="2025-03-14T12:41:56-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1332" Mar 14 12:41:56 volumio go-librespot[1463]: time="2025-03-14T12:41:56-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1110" Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 14 12:41:56 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 14 12:41:56 volumio volumio[1171]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 14 12:41:56 volumio volumio[1171]: info: Starting MyVolumio Remote Streaming Endpoints Mar 14 12:41:56 volumio volumio[1171]: info: MyVolumio login type: Token Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 14 12:41:56 volumio volumio[1171]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=debug msg="fetched first chunk of 29, total size is 14737100 bytes" uri="spotify:track:6bzwsAtj4TqaBysLDrGiO3" Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=debug msg="fetched chunk 1/28, size: 524288" uri="spotify:track:6bzwsAtj4TqaBysLDrGiO3" Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=debug msg="fetched chunk 3/28, size: 524288" uri="spotify:track:6bzwsAtj4TqaBysLDrGiO3" Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=debug msg="fetched chunk 18/28, size: 524288" uri="spotify:track:6bzwsAtj4TqaBysLDrGiO3" Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=trace msg="seek to 243456ms (diff: 191ms, samples: 10736409, bytes: 9858751)" uri="spotify:track:6bzwsAtj4TqaBysLDrGiO3" Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=debug msg="fetched chunk 19/28, size: 524288" uri="spotify:track:6bzwsAtj4TqaBysLDrGiO3" Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=debug msg="fetched chunk 20/28, size: 524288" uri="spotify:track:6bzwsAtj4TqaBysLDrGiO3" Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=debug msg="fetched chunk 21/28, size: 524288" uri="spotify:track:6bzwsAtj4TqaBysLDrGiO3" Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=debug msg="created new output device" Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=info msg="loaded track \"I.G.Y.\" (paused: false, position: 243456ms, duration: 363413ms, prefetched: false)" uri="spotify:track:6bzwsAtj4TqaBysLDrGiO3" Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=debug msg="fetched chunk 2/28, size: 524288" uri="spotify:track:6bzwsAtj4TqaBysLDrGiO3" Mar 14 12:41:57 volumio volumio[1171]: info: Starting Streaming Service Transparent Proxy Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=trace msg="scheduling prefetch in 90s" Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=trace msg="emitting websocket event: metadata" Mar 14 12:41:57 volumio volumio[1171]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=trace msg="emitting websocket event: active" Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=debug msg="sending successful reply for dealer request" Mar 14 12:41:57 volumio volumio[1171]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 14 12:41:57 volumio volumio[1171]: info: Streaming services startup Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Mar 14 12:41:57 volumio volumio[1171]: info: Starting Streaming Daemon Mar 14 12:41:57 volumio sudo[1515]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 14 12:41:57 volumio sudo[1515]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 14 12:41:57 volumio sudo[1515]: pam_unix(sudo:session): session closed for user root Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 14 12:41:57 volumio go-librespot[1463]: time="2025-03-14T12:41:57-04:00" level=trace msg="emitting websocket event: playing" Mar 14 12:41:57 volumio volumio[1171]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 14 12:41:58 volumio volumio[1171]: info: Getting Spotify volume Mar 14 12:41:58 volumio volumio[1171]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6bzwsAtj4TqaBysLDrGiO3","play_origin":"playlist/ondemand"}} Mar 14 12:41:58 volumio volumio[1171]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6bzwsAtj4TqaBysLDrGiO3","name":"I.G.Y.","artist_names":["Donald Fagen"],"album_name":"The Nightfly","album_cover_url":"https://i.scdn.co/image/ab67616d00001e029c3be4e1c786475f9489529f","position":243456,"duration":363413,"release_date":"year:1982 month:10 day:29","track_number":1,"disc_number":1}} Mar 14 12:41:58 volumio volumio[1171]: SPOTIFY: received: {"type":"active","data":null} Mar 14 12:41:58 volumio volumio[1171]: info: Aligning Spotify Volume to Volumio Volume Mar 14 12:41:58 volumio volumio[1171]: info: CoreCommandRouter::volumioGetState Mar 14 12:41:58 volumio volumio[1171]: info: CorePlayQueue::getTrack 0 Mar 14 12:41:58 volumio volumio[1171]: info: Setting Spotify Volume from Volumio: 0 Mar 14 12:41:58 volumio volumio[1171]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6bzwsAtj4TqaBysLDrGiO3","play_origin":"playlist/ondemand"}} Mar 14 12:41:58 volumio volumio[1171]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 14 12:41:58 volumio volumio[1171]: TypeError: Cannot read property 'service' of undefined Mar 14 12:41:58 volumio volumio[1171]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) Mar 14 12:41:58 volumio volumio[1171]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:263:18) Mar 14 12:41:58 volumio volumio[1171]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Mar 14 12:41:58 volumio volumio[1171]: at WebSocket.emit (events.js:315:20) Mar 14 12:41:58 volumio volumio[1171]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Mar 14 12:41:58 volumio volumio[1171]: at Receiver.emit (events.js:315:20) Mar 14 12:41:58 volumio volumio[1171]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Mar 14 12:41:58 volumio volumio[1171]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Mar 14 12:41:58 volumio volumio[1171]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Mar 14 12:41:58 volumio volumio[1171]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Mar 14 12:41:58 volumio volumio[1171]: at writeOrBuffer (internal/streams/writable.js:358:12) Mar 14 12:41:58 volumio volumio[1171]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Mar 14 12:41:58 volumio volumio[1171]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Mar 14 12:41:58 volumio volumio[1171]: at Socket.emit (events.js:315:20) Mar 14 12:41:58 volumio volumio[1171]: at addChunk (internal/streams/readable.js:309:12) Mar 14 12:41:58 volumio volumio[1171]: at readableAddChunk (internal/streams/readable.js:284:9) Mar 14 12:41:58 volumio volumio[1171]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 14 12:41:58 volumio sudo[1531]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-14 12:40 Mar 14 12:41:58 volumio sudo[1531]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="a01a833dd28483f88cb390596f5090b7187992af" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 11:42:54 AM CET" VOLUMIO_VERSION="3.795" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4049a67f1c09d4a94e033ba35a80a144"