-- Logs begin at Thu 2019-02-14 18:11:58 CST, end at Thu 2025-02-27 01:24:02 CST. -- Feb 27 01:23:30 volumio systemd-timedated[953]: Changed local time to Thu Feb 27 01:23:30 2025 Feb 27 01:23:30 volumio sudo[951]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:30 volumio volumio-time-update[614]: volumio-time-update-util: System time updated successfully. Feb 27 01:23:30 volumio systemd[1]: Starting Daily apt download activities... Feb 27 01:23:30 volumio systemd[1]: Started Volumio Time Update Utility. Feb 27 01:23:30 volumio nmbd[752]: [2025/02/27 01:23:30.627222, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 27 01:23:30 volumio nmbd[752]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Feb 27 01:23:30 volumio systemd[1]: Started Samba NMB Daemon. Feb 27 01:23:30 volumio systemd[1]: Starting Samba Winbind Daemon... Feb 27 01:23:30 volumio dhcpcd[863]: eth0: leased 192.168.1.23 for 86400 seconds Feb 27 01:23:30 volumio dhcpcd[863]: eth0: adding route to 192.168.1.0/24 Feb 27 01:23:30 volumio dhcpcd[863]: eth0: adding default route via 192.168.1.1 Feb 27 01:23:30 volumio dhcpcd[863]: forked to background, child pid 999 Feb 27 01:23:30 volumio sudo[862]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:30 volumio wireless.js[596]: trying... Feb 27 01:23:30 volumio sudo[1001]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 27 01:23:30 volumio sudo[1001]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:30 volumio sudo[1001]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:30 volumio winbindd[977]: [2025/02/27 01:23:30.949702, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Feb 27 01:23:30 volumio winbindd[977]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Feb 27 01:23:31 volumio winbindd[977]: [2025/02/27 01:23:31.020403, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 27 01:23:31 volumio systemd[1]: Started Samba Winbind Daemon. Feb 27 01:23:31 volumio winbindd[977]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Feb 27 01:23:31 volumio systemd[1]: Starting Samba SMB Daemon... Feb 27 01:23:31 volumio wpa_supplicant[876]: wlan0: Trying to associate with SSID 'FallenHome' Feb 27 01:23:31 volumio smbd[1006]: [2025/02/27 01:23:31.513805, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 27 01:23:31 volumio smbd[1006]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Feb 27 01:23:31 volumio systemd[1]: Started Samba SMB Daemon. Feb 27 01:23:31 volumio dhcpcd[999]: wlan0: carrier acquired Feb 27 01:23:31 volumio wpa_supplicant[876]: wlan0: Associated with 02:eb:d8:23:80:56 Feb 27 01:23:31 volumio wpa_supplicant[876]: wlan0: CTRL-EVENT-CONNECTED - Connection to 02:eb:d8:23:80:56 completed [id=0 id_str=] Feb 27 01:23:31 volumio wpa_supplicant[876]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Feb 27 01:23:31 volumio wpa_supplicant[876]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE Feb 27 01:23:31 volumio dhcpcd[999]: wlan0: IAID dd:57:fb:b4 Feb 27 01:23:31 volumio dhcpcd[999]: wlan0: adding address fe80::da3a:ddff:fe57:fbb4 Feb 27 01:23:31 volumio dhcpcd[999]: ipv6_addaddr1: Permission denied Feb 27 01:23:31 volumio dhcpcd[999]: wlan0: carrier lost Feb 27 01:23:31 volumio dhcpcd[999]: wlan0: carrier acquired Feb 27 01:23:31 volumio dhcpcd[999]: wlan0: connected to Access Point `FallenHome' Feb 27 01:23:31 volumio dhcpcd[999]: wlan0: IAID dd:57:fb:b4 Feb 27 01:23:31 volumio dhcpcd[999]: wlan0: soliciting an IPv6 router Feb 27 01:23:31 volumio volumio-remote-updater[625]: [2025-02-27 01:23:31] [info] asio async_connect error: system:111 (Connection refused) Feb 27 01:23:31 volumio volumio-remote-updater[625]: [2025-02-27 01:23:31] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Feb 27 01:23:31 volumio volumio-remote-updater[625]: [2025-02-27 01:23:31] [error] handle_connect error: Underlying Transport Error Feb 27 01:23:31 volumio wireless.js[596]: trying... Feb 27 01:23:31 volumio sudo[1044]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 27 01:23:31 volumio sudo[1044]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:31 volumio sudo[1044]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:31 volumio dhcpcd[999]: wlan0: rebinding lease of 192.168.1.14 Feb 27 01:23:32 volumio dhcpcd[999]: wlan0: probing address 192.168.1.14/24 Feb 27 01:23:32 volumio systemd[1]: apt-daily.service: Succeeded. Feb 27 01:23:32 volumio systemd[1]: Started Daily apt download activities. Feb 27 01:23:32 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Feb 27 01:23:32 volumio wpa_supplicant[876]: RRM: Ignoring radio measurement request: Not RRM network Feb 27 01:23:32 volumio wireless.js[596]: trying... Feb 27 01:23:32 volumio sudo[1090]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 27 01:23:32 volumio sudo[1090]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:32 volumio sudo[1090]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:33 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Feb 27 01:23:33 volumio systemd[1]: Started Daily apt upgrade and clean activities. Feb 27 01:23:33 volumio dhcpcd[999]: wlan0: carrier lost Feb 27 01:23:33 volumio wpa_supplicant[876]: wlan0: Associated with 02:eb:d8:73:80:57 Feb 27 01:23:33 volumio wpa_supplicant[876]: wlan0: CTRL-EVENT-CONNECTED - Connection to 02:eb:d8:73:80:57 completed [id=0 id_str=] Feb 27 01:23:33 volumio wpa_supplicant[876]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Feb 27 01:23:33 volumio dhcpcd[999]: wlan0: carrier acquired Feb 27 01:23:33 volumio dhcpcd[999]: wlan0: IAID dd:57:fb:b4 Feb 27 01:23:33 volumio dhcpcd[999]: wlan0: soliciting an IPv6 router Feb 27 01:23:33 volumio wireless.js[596]: trying... Feb 27 01:23:33 volumio sudo[1156]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 27 01:23:33 volumio sudo[1156]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:33 volumio sudo[1156]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:34 volumio dhcpcd[999]: wlan0: rebinding lease of 192.168.1.14 Feb 27 01:23:34 volumio dhcpcd[999]: wlan0: probing address 192.168.1.14/24 Feb 27 01:23:34 volumio wireless.js[596]: trying... Feb 27 01:23:34 volumio sudo[1159]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 27 01:23:34 volumio sudo[1159]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:34 volumio sudo[1159]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:35 volumio wireless.js[596]: trying... Feb 27 01:23:35 volumio sudo[1162]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 27 01:23:35 volumio sudo[1162]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:35 volumio sudo[1162]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:36 volumio wireless.js[596]: trying... Feb 27 01:23:36 volumio sudo[1165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 27 01:23:36 volumio sudo[1165]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:36 volumio sudo[1165]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:37 volumio wireless.js[596]: trying... Feb 27 01:23:37 volumio sudo[1168]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 27 01:23:37 volumio sudo[1168]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:37 volumio sudo[1168]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:38 volumio dhcpcd[999]: wlan0: leased 192.168.1.14 for 86400 seconds Feb 27 01:23:38 volumio avahi-daemon[616]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.14. Feb 27 01:23:38 volumio dhcpcd[999]: wlan0: adding route to 192.168.1.0/24 Feb 27 01:23:38 volumio dhcpcd[999]: wlan0: adding default route via 192.168.1.1 Feb 27 01:23:38 volumio avahi-daemon[616]: New relevant interface wlan0.IPv4 for mDNS. Feb 27 01:23:38 volumio avahi-daemon[616]: Registering new address record for 192.168.1.14 on wlan0.IPv4. Feb 27 01:23:38 volumio wireless.js[596]: trying... Feb 27 01:23:38 volumio sudo[1192]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Feb 27 01:23:38 volumio sudo[1192]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:38 volumio sudo[1192]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:38 volumio wireless.js[596]: Connected to: ----FallenHome Feb 27 01:23:38 volumio wireless.js[596]: ---- Feb 27 01:23:38 volumio sudo[1195]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 27 01:23:38 volumio sudo[1195]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:38 volumio sudo[1195]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:38 volumio wireless.js[596]: ... joined AP, wlan0 IPv4 is 192.168.1.14, ipV6 is undefined Feb 27 01:23:38 volumio wireless.js[596]: It's done! AP Feb 27 01:23:39 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Feb 27 01:23:39 volumio systemd[1]: Started Wireless Services. Feb 27 01:23:39 volumio systemd[1]: Started Volumio Backend Module. Feb 27 01:23:39 volumio systemd[1]: Started Volumio Cpu Tweaker. Feb 27 01:23:39 volumio systemd[1]: Reached target Multi-User System. Feb 27 01:23:39 volumio systemd[1]: Reached target Graphical Interface. Feb 27 01:23:39 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Feb 27 01:23:39 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Feb 27 01:23:39 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Feb 27 01:23:39 volumio systemd[1]: Startup finished in 11.830s (kernel) + 23.649s (userspace) = 35.479s. Feb 27 01:23:39 volumio volumio-cpu-tweak[1201]: Setting RT Priority for mpd Feb 27 01:23:39 volumio volumio-cpu-tweak[1201]: Setting MPD Affinity Feb 27 01:23:39 volumio volumio-cpu-tweak[1201]: pid 793's current affinity mask: f Feb 27 01:23:39 volumio volumio-cpu-tweak[1201]: pid 793's new affinity mask: 3 Feb 27 01:23:39 volumio volumio-cpu-tweak[1201]: /bin/volumio_cpu_tweak: line 27: warning: command substitution: ignored null byte in input Feb 27 01:23:39 volumio volumio-cpu-tweak[1201]: VOLUMIO CPU TWEAK: Setting CPU Governor: performance Feb 27 01:23:39 volumio systemd[1]: volumio_cpu_tweak.service: Succeeded. Feb 27 01:23:39 volumio ntpd[775]: Listen normally on 4 wlan0 192.168.1.14:123 Feb 27 01:23:39 volumio ntpd[775]: new interface(s) found: waking up resolver Feb 27 01:23:40 volumio volumio[1200]: info: ------------------------------------------- Feb 27 01:23:40 volumio volumio[1200]: info: ----- Volumio3 ---- Feb 27 01:23:40 volumio volumio[1200]: info: ------------------------------------------- Feb 27 01:23:40 volumio volumio[1200]: info: ----- System startup ---- Feb 27 01:23:40 volumio volumio[1200]: info: ------------------------------------------- Feb 27 01:23:41 volumio volumio[1200]: info: MYVOLUMIO Environment detected Feb 27 01:23:41 volumio volumio[1200]: info: Plugin folders cleanup Feb 27 01:23:41 volumio volumio[1200]: info: Scanning into folder /volumio/app/plugins/ Feb 27 01:23:41 volumio volumio[1200]: info: Scanning category audio_interface Feb 27 01:23:41 volumio volumio[1200]: info: Scanning category miscellanea Feb 27 01:23:41 volumio volumio[1200]: info: Scanning category music_service Feb 27 01:23:41 volumio volumio[1200]: info: Scanning category plugins.json Feb 27 01:23:41 volumio volumio[1200]: info: Scanning category system_controller Feb 27 01:23:41 volumio volumio[1200]: info: Scanning category user_interface Feb 27 01:23:41 volumio volumio[1200]: info: Scanning into folder /data/plugins/ Feb 27 01:23:41 volumio volumio[1200]: info: Scanning category audio_interface Feb 27 01:23:41 volumio volumio[1200]: info: Scanning category music_service Feb 27 01:23:41 volumio volumio[1200]: info: Plugin folders cleanup completed Feb 27 01:23:41 volumio volumio[1200]: info: ------------------------------------------- Feb 27 01:23:41 volumio volumio[1200]: info: ----- Core plugins startup ---- Feb 27 01:23:41 volumio volumio[1200]: info: ------------------------------------------- Feb 27 01:23:41 volumio volumio[1200]: info: Loading plugins from folder /volumio/app/plugins/ Feb 27 01:23:41 volumio volumio[1200]: info: Adding plugin upnp to MyMusic Plugins Feb 27 01:23:41 volumio volumio[1200]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 27 01:23:41 volumio volumio[1200]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 27 01:23:41 volumio volumio[1200]: info: Loading plugins from folder /data/plugins/ Feb 27 01:23:41 volumio volumio[1200]: info: Loading plugin "system"... Feb 27 01:23:41 volumio volumio-remote-updater[625]: [2025-02-27 01:23:41] [connect] Successful connection Feb 27 01:23:41 volumio volumio[1200]: info: Loading plugin "appearance"... Feb 27 01:23:42 volumio volumio[1200]: info: Loading plugin "network"... Feb 27 01:23:42 volumio volumio[1200]: info: Refreshing Cached IP Addresses Feb 27 01:23:42 volumio sudo[1235]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 27 01:23:42 volumio sudo[1235]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:42 volumio sudo[1235]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:42 volumio sudo[1237]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 27 01:23:42 volumio sudo[1237]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:42 volumio volumio[1200]: info: Loading plugin "services"... Feb 27 01:23:42 volumio sudo[1237]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:42 volumio volumio[1200]: info: Loading plugin "alsa_controller"... Feb 27 01:23:42 volumio sudo[1245]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 27 01:23:42 volumio sudo[1245]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 27 01:23:42 volumio volumio[1200]: info: Loading plugin "wizard"... Feb 27 01:23:42 volumio volumio[1200]: info: Loading plugin "networkfs"... Feb 27 01:23:42 volumio volumio[1200]: info: Starting Udev Watcher for removable devices Feb 27 01:23:42 volumio sudo[1261]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=server,password=zxcv4321,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.19/nas_hdd/音樂 /mnt/NAS/Nas Feb 27 01:23:42 volumio sudo[1261]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:42 volumio volumio[1200]: info: Ignoring mount for partition: boot Feb 27 01:23:42 volumio volumio[1200]: info: Ignoring mount for partition: volumio Feb 27 01:23:42 volumio volumio[1200]: info: Ignoring mount for partition: volumio_data Feb 27 01:23:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 27 01:23:42 volumio volumio[1200]: info: Loading plugin "volumio_command_line_client"... Feb 27 01:23:42 volumio volumio[1200]: info: Loading plugin "upnp"... Feb 27 01:23:42 volumio volumio[1200]: info: [1740590622801] Starting Upmpd Daemon Feb 27 01:23:42 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 27 01:23:42 volumio volumio[1200]: info: Loading plugin "my_music"... Feb 27 01:23:42 volumio volumio[1200]: info: Loading plugin "mpd"... Feb 27 01:23:42 volumio kernel: Key type cifs.spnego registered Feb 27 01:23:42 volumio kernel: Key type cifs.idmap registered Feb 27 01:23:42 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. Feb 27 01:23:42 volumio kernel: CIFS: Attempting to mount //192.168.1.19/nas_hdd/音樂 Feb 27 01:23:42 volumio kernel: cryptd: max_cpu_qlen set to 1000 Feb 27 01:23:43 volumio sudo[1261]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:43 volumio wpa_supplicant[876]: RRM: Ignoring radio measurement request: Not RRM network Feb 27 01:23:43 volumio volumio[1200]: info: Loading plugin "upnp_browser"... Feb 27 01:23:43 volumio volumio[1200]: info: Loading plugin "alarm-clock"... Feb 27 01:23:43 volumio volumio[1200]: info: Loading plugin "airplay_emulation"... Feb 27 01:23:43 volumio volumio[1200]: info: Starting Shairport Sync Feb 27 01:23:43 volumio volumio[1200]: info: Loading plugin "last_100"... Feb 27 01:23:43 volumio volumio[1200]: info: Loading plugin "webradio"... Feb 27 01:23:43 volumio volumio[1200]: info: Loading plugin "i2s_dacs"... Feb 27 01:23:43 volumio volumio[1200]: info: I2S DAC not set, start Auto-detection Feb 27 01:23:43 volumio volumio[1200]: info: Loading plugin "volumiodiscovery"... Feb 27 01:23:43 volumio volumio[1200]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 27 01:23:43 volumio volumio[1200]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 27 01:23:43 volumio node[1200]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 27 01:23:43 volumio volumio[1200]: *** WARNING *** For more information see Feb 27 01:23:43 volumio volumio[1200]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 27 01:23:43 volumio volumio[1200]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 27 01:23:43 volumio volumio[1200]: *** WARNING *** For more information see Feb 27 01:23:43 volumio node[1200]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 27 01:23:43 volumio node[1200]: *** WARNING *** For more information see Feb 27 01:23:43 volumio node[1200]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 27 01:23:43 volumio node[1200]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 27 01:23:43 volumio node[1200]: *** WARNING *** For more information see Feb 27 01:23:43 volumio volumio[1200]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 27 01:23:43 volumio volumio[1200]: info: Discovery: Started advertising with name: Volumio Feb 27 01:23:43 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 27 01:23:43 volumio volumio[1200]: info: Loading plugin "soundcloud"... Feb 27 01:23:44 volumio volumio[1200]: info: Loading plugin "spop"... Feb 27 01:23:45 volumio volumio[1200]: info: Loading plugin "youtube2"... Feb 27 01:23:46 volumio sudo[1245]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:47 volumio volumio[1200]: info: Loading plugin "ytcr"... Feb 27 01:23:48 volumio systemd[1]: systemd-fsckd.service: Succeeded. Feb 27 01:23:50 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Feb 27 01:23:50 volumio volumio[1200]: info: Loading plugin "ytmusic"... Feb 27 01:23:52 volumio volumio[1200]: info: Loading plugin "outputs"... Feb 27 01:23:52 volumio volumio[1200]: info: Loading plugin "albumart"... Feb 27 01:23:53 volumio volumio[1200]: info: Plugin example_plugin is not enabled Feb 27 01:23:53 volumio volumio[1200]: info: Loading plugin "inputs"... Feb 27 01:23:53 volumio volumio[1200]: info: Loading plugin "updater_comm"... Feb 27 01:23:53 volumio volumio[1200]: info: Plugin mpdemulation is not enabled Feb 27 01:23:53 volumio volumio[1200]: info: Loading plugin "rest_api"... Feb 27 01:23:53 volumio volumio[1200]: info: Loading plugin "websocket"... Feb 27 01:23:53 volumio volumio[1200]: info: Starting Socket.io Server version 2.3.0 Feb 27 01:23:53 volumio volumio[1200]: info: Loading plugin "fusiondsp"... Feb 27 01:23:53 volumio volumio[1200]: Forking 3 albumart workers Feb 27 01:23:53 volumio volumio[1200]: info: Applying required configuration parameters for plugin fusiondsp Feb 27 01:23:53 volumio volumio[1200]: info: Loading plugin "minidlna"... Feb 27 01:23:53 volumio volumio[1200]: info: Applying required configuration parameters for plugin minidlna Feb 27 01:23:53 volumio volumio[1200]: Starting albumart workers Feb 27 01:23:53 volumio volumio[1200]: Starting albumart workers Feb 27 01:23:53 volumio volumio[1200]: Starting albumart workers Feb 27 01:23:53 volumio volumio[1200]: info: Loading i18n strings for locale zh_TW Feb 27 01:23:53 volumio volumio[1200]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. Feb 27 01:23:53 volumio volumio[1200]: Updating browse sources language Feb 27 01:23:53 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::initPlayerControls Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 27 01:23:54 volumio volumio[1200]: Express server listening on port 3000 Feb 27 01:23:54 volumio volumio[1200]: [Metrics] WebUI: 14s 96.47ms Feb 27 01:23:54 volumio volumio[1200]: info: CoreStateMachine::resetVolumioState Feb 27 01:23:54 volumio volumio[1200]: info: CoreStateMachine::getcurrentVolume Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::volumioRetrievevolume Feb 27 01:23:54 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 27 01:23:54 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 01:23:54 volumio sudo[1377]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 27 01:23:54 volumio sudo[1377]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:54 volumio sudo[1377]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:54 volumio sudo[1380]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 27 01:23:54 volumio sudo[1380]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:54 volumio volumio[1200]: info: Volumio Network Manager: Network status updated: 3 Feb 27 01:23:54 volumio sudo[1380]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:54 volumio volumio[1200]: info: Reloading queue from file Feb 27 01:23:54 volumio volumio[1200]: info: CoreStateMachine::setRepeat false single undefined Feb 27 01:23:54 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 27 01:23:54 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 27 01:23:54 volumio volumio[1200]: info: CoreStateMachine::setRandom true Feb 27 01:23:54 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 27 01:23:54 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 27 01:23:54 volumio volumio[1200]: info: Setting Device type: Raspberry PI Feb 27 01:23:54 volumio volumio[1200]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Feb 27 01:23:54 volumio volumio[1200]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03115 Feb 27 01:23:54 volumio volumio[1200]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Feb 27 01:23:54 volumio volumio[1200]: info: Completed loading Core Plugins Feb 27 01:23:54 volumio volumio[1200]: info: Preparing to generate the ALSA configuration file Feb 27 01:23:54 volumio sudo[1389]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 27 01:23:54 volumio sudo[1389]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:54 volumio volumio[1200]: info: Discovery: adding 3104596e-39f5-4cc9-b0f5-b218499a231d Feb 27 01:23:54 volumio volumio[1200]: info: Discovery: Found device Volumio Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 27 01:23:54 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 27 01:23:54 volumio volumio[1200]: info: Discovery: this is already registered, 3104596e-39f5-4cc9-b0f5-b218499a231d Feb 27 01:23:54 volumio volumio[1200]: info: Discovery: Found device Volumio Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 27 01:23:54 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 27 01:23:54 volumio volumio[1200]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Feb 27 01:23:54 volumio volumio[1200]: info: Reading ALSA contributions from plugins. Feb 27 01:23:54 volumio volumio[1200]: info: Asound.conf file unchanged, so no further update is needed Feb 27 01:23:54 volumio volumio[1200]: info: Output device has changed, restarting MPD Feb 27 01:23:54 volumio sudo[1393]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 27 01:23:54 volumio sudo[1393]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:54 volumio volumio[1200]: info: Output device has changed, restarting Shairport Sync Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 01:23:54 volumio sudo[1393]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:54 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Feb 27 01:23:54 volumio sudo[1396]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 27 01:23:54 volumio sudo[1396]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:54 volumio sudo[1389]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:54 volumio systemd[1]: Stopping Music Player Daemon... Feb 27 01:23:54 volumio volumio[1200]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 27 01:23:54 volumio volumio[1200]: info: ___________ START PLUGINS ___________ Feb 27 01:23:54 volumio volumio[1200]: info: ControllerMpd::onStart: Initializing MPD Feb 27 01:23:54 volumio volumio[1200]: info: Creating MPD Configuration file Feb 27 01:23:54 volumio sudo[1402]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 27 01:23:54 volumio sudo[1402]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 27 01:23:54 volumio volumio[1200]: info: [1740590634689] CoreMusicLibrary::Adding element Media Servers Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 27 01:23:54 volumio sudo[1402]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:54 volumio sudo[1404]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 27 01:23:54 volumio sudo[1404]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 01:23:54 volumio systemd[1]: mpd.service: Succeeded. Feb 27 01:23:54 volumio systemd[1]: Stopped Music Player Daemon. Feb 27 01:23:54 volumio volumio[1200]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 01:23:54 volumio systemd[1]: Starting Music Player Daemon... Feb 27 01:23:54 volumio volumio[1200]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 27 01:23:54 volumio volumio[1200]: info: [1740590634790] CoreMusicLibrary::Adding element Last_100 Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 27 01:23:54 volumio volumio[1200]: info: [1740590634792] CoreMusicLibrary::Adding element Webradio Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 27 01:23:54 volumio volumio[1200]: info: Initializing BBC Radios Feb 27 01:23:54 volumio sudo[1408]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 27 01:23:54 volumio sudo[1408]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:54 volumio sudo[1408]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 27 01:23:54 volumio volumio[1200]: info: [1740590634873] CoreMusicLibrary::Adding element SoundCloud Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 27 01:23:54 volumio volumio[1200]: Cannot find translation for source SoundCloud Feb 27 01:23:54 volumio volumio[1200]: info: Creating Spotify config file Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 27 01:23:54 volumio volumio[1200]: info: [1740590634969] CoreMusicLibrary::Adding element YouTube2 Feb 27 01:23:54 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 27 01:23:54 volumio volumio[1200]: Cannot find translation for source SoundCloud Feb 27 01:23:54 volumio volumio[1200]: Cannot find translation for source YouTube2 Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 27 01:23:55 volumio volumio[1200]: info: [1740590635008] CoreMusicLibrary::Adding element YouTube Music Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 27 01:23:55 volumio volumio[1200]: Cannot find translation for source SoundCloud Feb 27 01:23:55 volumio volumio[1200]: Cannot find translation for source YouTube2 Feb 27 01:23:55 volumio volumio[1200]: Cannot find translation for source YouTube Music Feb 27 01:23:55 volumio volumio[1200]: info: Loading i18n strings for locale zh_TW Feb 27 01:23:55 volumio volumio[1200]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: FusionDsp - mixtype--------------------- None Feb 27 01:23:55 volumio volumio[1200]: info: Loading i18n strings for locale zh_TW Feb 27 01:23:55 volumio volumio[1200]: error: minidlna: Fetching language file: Error: i18n file complementing the system language not found. Feb 27 01:23:55 volumio volumio[1200]: info: Volumio Calling Home Feb 27 01:23:55 volumio volumio[1200]: info: Preparing to generate the ALSA configuration file Feb 27 01:23:55 volumio volumio[1200]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Feb 27 01:23:55 volumio volumio[1200]: info: Reading ALSA contributions from plugins. Feb 27 01:23:55 volumio volumio[1200]: info: MPD Permissions set Feb 27 01:23:55 volumio volumio[1200]: info: MPD Permissions set Feb 27 01:23:55 volumio volumio[1200]: info: Upmpdcli Daemon Started Feb 27 01:23:55 volumio volumio[1200]: info: Spotify config file written Feb 27 01:23:55 volumio sudo[1432]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 27 01:23:55 volumio sudo[1432]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:55 volumio volumio[1200]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Feb 27 01:23:55 volumio volumio[1200]: info: No need to fix Spotify hosts Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio systemd[1]: Started go-librespot Daemon. Feb 27 01:23:55 volumio go-librespot[1434]: go-librespot daemon starting... Feb 27 01:23:55 volumio sudo[1432]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:55 volumio volumio[1200]: info: minidlna: Found miniDLNA version 1.2.1 Feb 27 01:23:55 volumio volumio[1200]: info: minidlna: Starting minidlna.service Feb 27 01:23:55 volumio sudo[1445]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start minidlna.service Feb 27 01:23:55 volumio sudo[1445]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:55 volumio volumio[1200]: info: Starting Shairport Sync Feb 27 01:23:55 volumio volumio[1200]: info: Starting Shairport Sync Feb 27 01:23:55 volumio systemd[1]: Started MiniDLNA lightweight DLNA/UPnP-AV server. Feb 27 01:23:55 volumio sudo[1454]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 27 01:23:55 volumio sudo[1454]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:55 volumio sudo[1445]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:55 volumio volumio[1200]: info: Starting Shairport Sync Feb 27 01:23:55 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 27 01:23:55 volumio systemd[1]: shairport-sync.service: Succeeded. Feb 27 01:23:55 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 27 01:23:55 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 27 01:23:55 volumio sudo[1454]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:55 volumio sudo[1457]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 27 01:23:55 volumio sudo[1457]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:55 volumio sudo[1460]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 27 01:23:55 volumio sudo[1460]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:55 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 27 01:23:55 volumio systemd[1]: shairport-sync.service: Succeeded. Feb 27 01:23:55 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 27 01:23:55 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 27 01:23:55 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 27 01:23:55 volumio sudo[1460]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:55 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 27 01:23:55 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Feb 27 01:23:55 volumio systemd[1]: shairport-sync.service: Succeeded. Feb 27 01:23:55 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 27 01:23:55 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 27 01:23:55 volumio volumio[1200]: info: Shairport-Sync Started Feb 27 01:23:55 volumio sudo[1457]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:55 volumio volumio[1200]: Error adding Membership: Error: addMembership EINVAL Feb 27 01:23:55 volumio volumio[1200]: info: minidlna: systemctl start minidlna.service succeeded. Feb 27 01:23:55 volumio mpd[1422]: Feb 27 01:23 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 27 01:23:55 volumio volumio[1200]: info: Asound.conf file unchanged, so no further update is needed Feb 27 01:23:55 volumio volumio[1200]: info: Output device has changed, restarting MPD Feb 27 01:23:55 volumio systemd[1]: Started Music Player Daemon. Feb 27 01:23:55 volumio sudo[1471]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 27 01:23:55 volumio sudo[1471]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:55 volumio sudo[1404]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:55 volumio sudo[1396]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:55 volumio sudo[1471]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:55 volumio volumio[1200]: info: Output device has changed, restarting Shairport Sync Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 01:23:55 volumio sudo[1477]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 27 01:23:55 volumio sudo[1477]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:55 volumio go-librespot[1434]: time="2025-02-27T01:23:55+08:00" level=info msg="running go-librespot 0.2.0" Feb 27 01:23:55 volumio go-librespot[1434]: time="2025-02-27T01:23:55+08:00" level=debug msg="app state loaded" Feb 27 01:23:55 volumio go-librespot[1434]: time="2025-02-27T01:23:55+08:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 27 01:23:55 volumio systemd[1]: Stopping Music Player Daemon... Feb 27 01:23:55 volumio systemd[1]: mpd.service: Succeeded. Feb 27 01:23:55 volumio systemd[1]: Stopped Music Player Daemon. Feb 27 01:23:55 volumio volumio[1200]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 27 01:23:55 volumio volumio[1200]: info: Volumio called home Feb 27 01:23:55 volumio volumio[1200]: info: Shairport-Sync Started Feb 27 01:23:55 volumio volumio[1200]: info: Shairport-Sync Started Feb 27 01:23:55 volumio volumio[1200]: info: MPD Permissions set Feb 27 01:23:55 volumio systemd[1]: Starting Music Player Daemon... Feb 27 01:23:55 volumio volumio[1200]: error: Upnp client error: Error: This socket has been ended by the other party Feb 27 01:23:55 volumio volumio[1200]: error: Cannot initialize MPD Connection: MPD is not running Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 27 01:23:55 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:55 volumio sudo[1484]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 27 01:23:55 volumio sudo[1484]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:55 volumio sudo[1484]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:55 volumio volumio[1200]: info: Starting Shairport Sync Feb 27 01:23:56 volumio sudo[1496]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 27 01:23:56 volumio sudo[1496]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 27 01:23:56 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 27 01:23:56 volumio systemd[1]: shairport-sync.service: Succeeded. Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=info msg="zeroconf server listening on port 42921" Feb 27 01:23:56 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 27 01:23:56 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 27 01:23:56 volumio sudo[1496]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:56 volumio volumio[1200]: info: Shairport-Sync Started Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=debug msg="obtained new client token: AAC/+Uvd0F2sHZQamUbzlndvedN8zV+vKjkfpQK1jTJF+O8CdF7nfrp8zN916DWWMnMEjQrY08bVD1ugn6kOxJlpqRy5odLr17kfxzRs9etw6WBW0jA2zVW4sVvUhOaAUhhPtvplRxDwPPcG+jf6R97rRJqc/ulgLGOJWBAvFENQZJOvh4DQuxsE48f422+crU/edlqoz3WbHBjj13twFJlIxSax35HS8/pKAIIJToYNXkLsGopozXRUsB4=" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=debug msg="completed keyexchange" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=debug msg="completed challenge" Feb 27 01:23:56 volumio systemd[1]: minidlna.service: Succeeded. Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=info msg="authenticated AP as 1lm6zgmq2hrsx2f9z0ibftzxl" Feb 27 01:23:56 volumio volumio[1200]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 27 01:23:56 volumio volumio[1200]: SPOTIFY: BQC1Dtyo9j31S4_yNbjRsgeYXrSGthEiU6npYTrp-nqwZ2_bfic2MavC_HA65Uq0nhlKs55mA58wQUVQq3-rnUhrQHuev1juDgqw0103P_hPs-82GpV3kk2z8zaIUwBZawpNjEk_C4R1ZK-r6RV71bQSV3r-4g2c-ryayL4dYXSgFoMRl_UHWEAciSXbgH90Zor8O2qfMKpuMNqs8i7t063HJ7TDKQx0wrUwdafQ-Sdm15l8Pmywn9olCn3QjqgHocVxc30l5-xuDbTdDsk9hvpZFApGVIAs4zSVK4I Feb 27 01:23:56 volumio volumio[1200]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 27 01:23:56 volumio volumio[1200]: info: New Spotify access token = BQC1Dtyo9j31S4_yNbjRsgeYXrSGthEiU6npYTrp-nqwZ2_bfic2MavC_HA65Uq0nhlKs55mA58wQUVQq3-rnUhrQHuev1juDgqw0103P_hPs-82GpV3kk2z8zaIUwBZawpNjEk_C4R1ZK-r6RV71bQSV3r-4g2c-ryayL4dYXSgFoMRl_UHWEAciSXbgH90Zor8O2qfMKpuMNqs8i7t063HJ7TDKQx0wrUwdafQ-Sdm15l8Pmywn9olCn3QjqgHocVxc30l5-xuDbTdDsk9hvpZFApGVIAs4zSVK4I Feb 27 01:23:56 volumio volumio[1200]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=info msg="authenticated Login5 as 1lm6zgmq2hrsx2f9z0ibftzxl" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=debug msg="initializing zeroconf session, username: 1lm6zgmq2hrsx2f9z0ibftzxl" Feb 27 01:23:56 volumio volumio[1200]: SPOTIFY: User informations: {"country":"TW","display_name":"fallengundam","email":"gegennee@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/1lm6zgmq2hrsx2f9z0ibftzxl"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/1lm6zgmq2hrsx2f9z0ibftzxl","id":"1lm6zgmq2hrsx2f9z0ibftzxl","images":[],"product":"premium","type":"user","uri":"spotify:user:1lm6zgmq2hrsx2f9z0ibftzxl"} Feb 27 01:23:56 volumio volumio[1200]: info: Spotify Successfully logged in Feb 27 01:23:56 volumio volumio[1200]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 27 01:23:56 volumio volumio[1200]: info: [1740590636311] CoreMusicLibrary::Adding element Spotify Feb 27 01:23:56 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 27 01:23:56 volumio volumio[1200]: Cannot find translation for source SoundCloud Feb 27 01:23:56 volumio volumio[1200]: Cannot find translation for source YouTube2 Feb 27 01:23:56 volumio volumio[1200]: Cannot find translation for source YouTube Music Feb 27 01:23:56 volumio volumio[1200]: Cannot find translation for source Spotify Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=debug msg="dealer connection opened" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=trace msg="starting accesspoint recv loop" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=trace msg="starting dealer recv loop" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=trace msg="received accesspoint ping" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=debug msg="received connection id: Y2ZlODJlYjQtMDc1Ni00ODg2LTk2ZjQtZWYzNjBlMTljY2YxK2RlYWxlcit0Y3A6Ly8wYWM5NDk5My5pcC5nYWUyLnNwb3RpZnkubmV0OjU3MDArNTU5NTA4M0VCRkNCM0ZBNEM1QzI4OTFFOTIzMkMyMTJFM0FBRkUwREMxNTA1NzY5MzhBNUMzNTNCMkJEMzhDOQ==" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=trace msg="received accesspoint pong ack" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=debug msg="put connect state because NEW_DEVICE" Feb 27 01:23:56 volumio go-librespot[1434]: time="2025-02-27T01:23:56+08:00" level=debug msg="update volume to 65535/65535" Feb 27 01:23:56 volumio volumio[1200]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 27 01:23:56 volumio volumio[1200]: info: CoreCommandRouter::volumioRetrievevolume Feb 27 01:23:56 volumio volumio[1200]: info: CoreCommandRouter::volumioGetState Feb 27 01:23:56 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 27 01:23:56 volumio volumio[1200]: info: CoreStateMachine::pushState Feb 27 01:23:56 volumio volumio[1200]: info: CorePlayQueue::getTrack 0 Feb 27 01:23:56 volumio volumio[1200]: info: CoreCommandRouter::volumioPushState Feb 27 01:23:56 volumio volumio[1200]: error: [ytcr] VolumeControl failed to obtain volume from Volumio: Feb 27 01:23:56 volumio volumio[1200]: (TypeError) Cannot read property 'vol' of undefined Feb 27 01:23:56 volumio volumio[1200]: TypeError: Cannot read property 'vol' of undefined Feb 27 01:23:56 volumio volumio[1200]: at VolumeControl.getVolume (/data/plugins/music_service/ytcr/dist/lib/VolumeControl.js:56:42) Feb 27 01:23:56 volumio volumio[1200]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Feb 27 01:23:56 volumio volumio[1200]: at async VolumeControl.init (/data/plugins/music_service/ytcr/dist/lib/VolumeControl.js:28:68) Feb 27 01:23:56 volumio volumio[1200]: at async /data/plugins/music_service/ytcr/dist/index.js:326:13 Feb 27 01:23:56 volumio volumio-remote-updater[625]: [2025-02-27 01:23:56] [connect] Successful connection Feb 27 01:23:56 volumio volumio-remote-updater[625]: [2025-02-27 01:23:56] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1740590636 101 Feb 27 01:23:56 volumio volumio[1200]: 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: 2 Feb 27 01:23:56 volumio mpd[1494]: Feb 27 01:23 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 27 01:23:56 volumio systemd[1]: Started Music Player Daemon. Feb 27 01:23:56 volumio sudo[1477]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:56 volumio volumio[1200]: error: MPD error: The expression evaluated to a falsy value: Feb 27 01:23:56 volumio volumio[1200]: assert.ok(self.idling) Feb 27 01:23:56 volumio volumio[1200]: error: The expression evaluated to a falsy value: Feb 27 01:23:56 volumio volumio[1200]: assert.ok(self.idling) Feb 27 01:23:56 volumio volumio[1200]: error: updateQueue error: null Feb 27 01:23:56 volumio volumio[1200]: error: updateQueue error: null Feb 27 01:23:56 volumio volumio[1200]: info: Completed starting Core Plugins Feb 27 01:23:56 volumio volumio[1200]: info: ------------------------------------------- Feb 27 01:23:56 volumio volumio[1200]: info: ----- MyVolumio plugins startup ---- Feb 27 01:23:56 volumio volumio[1200]: info: ------------------------------------------- Feb 27 01:23:56 volumio volumio[1200]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 27 01:23:57 volumio volumio[1200]: info: camilladsp spawned new process with pid 1510, instance 1, run: true Feb 27 01:23:57 volumio volumio[1200]: info: camilladsp service started and running in background, instance 1 Feb 27 01:23:57 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 27 01:23:57 volumio volumio[1200]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 384000 768000 <-AAAAAAAAAAAAA Feb 27 01:23:57 volumio volumio[1200]: info: FusionDsp loaded Feb 27 01:23:57 volumio volumio[1200]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 27 01:23:57 volumio sudo[1514]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Feb 27 01:23:57 volumio sudo[1514]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 27 01:23:57 volumio volumio[1200]: info: FusionDsp - Reporting Fusion DSP Enabled Feb 27 01:23:57 volumio volumio[1200]: info: Adding Signal Path Element [object Object] Feb 27 01:23:57 volumio volumio[1200]: info: Adding fusiondspeq DSP Signal Path Element Feb 27 01:23:57 volumio volumio[1200]: info: FusionDsp - ---- installed callbackRead Feb 27 01:23:57 volumio volumio[1200]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 27 01:23:57 volumio volumio[1200]: info: FusionDsp - Nulleq applied Feb 27 01:23:57 volumio systemd[1]: Started FusionDsp Daemon. Feb 27 01:23:57 volumio sudo[1514]: pam_unix(sudo:session): session closed for user root Feb 27 01:23:57 volumio volumio[1200]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 27 01:23:57 volumio volumio[1200]: info: FusionDsp - {"Reload":{"result":"Ok"}} Feb 27 01:23:57 volumio go-librespot[1434]: time="2025-02-27T01:23:57+08:00" level=debug msg="put connect state because VOLUME_CHANGED" Feb 27 01:23:57 volumio go-librespot[1434]: time="2025-02-27T01:23:57+08:00" level=trace msg="emitting websocket event: volume" Feb 27 01:23:57 volumio volumio[1391]: Generating RSA private key, 4096 bit long modulus (2 primes) Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="handling transfer player command from 3eafd065c2377956454b25f85e665a739c007192" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="resolved context of track" uri="spotify:user:1lm6zgmq2hrsx2f9z0ibftzxl:collection" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=trace msg="fetched new page 0 with 48 items (list: 48)" uri="spotify:user:1lm6zgmq2hrsx2f9z0ibftzxl:collection" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="loading track (paused: true, position: 143250ms)" uri="spotify:track:4Eskl0sOzOGZ33XpoNszID" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=trace msg="emitting websocket event: will_play" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="selected format OGG_VORBIS_320 (720faf49e24f26d0dc6126c8579df6119149629a)" uri="spotify:track:4Eskl0sOzOGZ33XpoNszID" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="requested aes key for file 720faf49e24f26d0dc6126c8579df6119149629a, gid: 4Eskl0sOzOGZ33XpoNszID" Feb 27 01:23:58 volumio volumio[1200]: info: go-librespot daemon successfully initialized Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="fetched first chunk of 21, total size is 10487254 bytes" uri="spotify:track:4Eskl0sOzOGZ33XpoNszID" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="fetched chunk 1/20, size: 524288" uri="spotify:track:4Eskl0sOzOGZ33XpoNszID" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="fetched chunk 3/20, size: 524288" uri="spotify:track:4Eskl0sOzOGZ33XpoNszID" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="fetched chunk 15/20, size: 524288" uri="spotify:track:4Eskl0sOzOGZ33XpoNszID" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="fetched chunk 12/20, size: 524288" uri="spotify:track:4Eskl0sOzOGZ33XpoNszID" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=trace msg="seek to 143250ms (diff: 130ms, samples: 6317325, bytes: 6378403)" uri="spotify:track:4Eskl0sOzOGZ33XpoNszID" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="created new output device" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=info msg="loaded track \"未遂\" (paused: true, position: 143250ms, duration: 240065ms, prefetched: false)" uri="spotify:track:4Eskl0sOzOGZ33XpoNszID" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="fetched chunk 13/20, size: 524288" uri="spotify:track:4Eskl0sOzOGZ33XpoNszID" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="fetched chunk 14/20, size: 524288" uri="spotify:track:4Eskl0sOzOGZ33XpoNszID" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=trace msg="emitting websocket event: metadata" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=trace msg="emitting websocket event: active" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="sending successful reply for dealer request" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="fetched chunk 2/20, size: 524288" uri="spotify:track:4Eskl0sOzOGZ33XpoNszID" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 27 01:23:58 volumio go-librespot[1434]: time="2025-02-27T01:23:58+08:00" level=trace msg="emitting websocket event: paused" Feb 27 01:24:00 volumio systemd[1]: systemd-timedated.service: Succeeded. Feb 27 01:24:01 volumio volumio[1200]: info: Initializing connection to go-librespot Websocket Feb 27 01:24:01 volumio go-librespot[1434]: time="2025-02-27T01:24:01+08:00" level=debug msg="new websocket client" Feb 27 01:24:01 volumio volumio[1200]: info: Connection to go-librespot Websocket established Feb 27 01:24:01 volumio go-librespot[1434]: time="2025-02-27T01:24:01+08:00" level=debug msg="handling resume player command from 3eafd065c2377956454b25f85e665a739c007192" Feb 27 01:24:01 volumio go-librespot[1434]: time="2025-02-27T01:24:01+08:00" level=trace msg="seek to 143250ms (diff: 130ms, samples: 6317325, bytes: 6378403)" uri="spotify:track:4Eskl0sOzOGZ33XpoNszID" Feb 27 01:24:01 volumio go-librespot[1434]: time="2025-02-27T01:24:01+08:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" Feb 27 01:24:01 volumio go-librespot[1434]: time="2025-02-27T01:24:01+08:00" level=debug msg="resume track at 143120ms" Feb 27 01:24:01 volumio volumio[1200]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Feb 27 01:24:01 volumio volumio[1200]: info: FusionDsp - ---- read samplerate from file: 44100 Feb 27 01:24:01 volumio volumio[1200]: info: camilladsp stopping service pid 1510... Feb 27 01:24:01 volumio volumio[1200]: info: camilladsp service terminated, instance 1 Feb 27 01:24:01 volumio volumio[1200]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 27 01:24:01 volumio volumio[1200]: info: FusionDsp - Nulleq applied Feb 27 01:24:01 volumio volumio[1200]: info: camilladsp service started and running in background, instance 1 Feb 27 01:24:01 volumio volumio[1200]: info: camilladsp spawned new process with pid 1544, instance 1, run: true Feb 27 01:24:01 volumio go-librespot[1434]: time="2025-02-27T01:24:01+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 27 01:24:01 volumio go-librespot[1434]: time="2025-02-27T01:24:01+08:00" level=trace msg="scheduling prefetch in 67s" Feb 27 01:24:01 volumio go-librespot[1434]: time="2025-02-27T01:24:01+08:00" level=debug msg="sending successful reply for dealer request" Feb 27 01:24:01 volumio go-librespot[1434]: time="2025-02-27T01:24:01+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 27 01:24:01 volumio go-librespot[1434]: time="2025-02-27T01:24:01+08:00" level=trace msg="emitting websocket event: playing" Feb 27 01:24:01 volumio volumio[1200]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4Eskl0sOzOGZ33XpoNszID","play_origin":"playlist"}} Feb 27 01:24:01 volumio volumio[1200]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 27 01:24:01 volumio volumio[1200]: TypeError: Cannot read property 'service' of undefined Feb 27 01:24:01 volumio volumio[1200]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) Feb 27 01:24:01 volumio volumio[1200]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:263:18) Feb 27 01:24:01 volumio volumio[1200]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Feb 27 01:24:01 volumio volumio[1200]: at WebSocket.emit (events.js:315:20) Feb 27 01:24:01 volumio volumio[1200]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Feb 27 01:24:01 volumio volumio[1200]: at Receiver.emit (events.js:315:20) Feb 27 01:24:01 volumio volumio[1200]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Feb 27 01:24:01 volumio volumio[1200]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Feb 27 01:24:01 volumio volumio[1200]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Feb 27 01:24:01 volumio volumio[1200]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Feb 27 01:24:01 volumio volumio[1200]: at writeOrBuffer (internal/streams/writable.js:358:12) Feb 27 01:24:01 volumio volumio[1200]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Feb 27 01:24:01 volumio volumio[1200]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Feb 27 01:24:01 volumio volumio[1200]: at Socket.emit (events.js:315:20) Feb 27 01:24:01 volumio volumio[1200]: at addChunk (internal/streams/readable.js:309:12) Feb 27 01:24:01 volumio volumio[1200]: at readableAddChunk (internal/streams/readable.js:284:9) Feb 27 01:24:01 volumio volumio[1200]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 27 01:24:02 volumio sudo[1560]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-27 01:23 Feb 27 01:24:02 volumio sudo[1560]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"