-- Logs begin at Thu 2019-02-14 18:11:59 +08, end at Sat 2025-06-21 22:55:16 +08. -- Jun 21 22:55:00 volumio systemd-timedated[985]: Changed local time to Sat Jun 21 22:55:00 2025 Jun 21 22:55:00 volumio sudo[983]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:00 volumio volumio-time-update[620]: volumio-time-update-util: System time updated successfully. Jun 21 22:55:00 volumio systemd[1]: Starting Daily apt download activities... Jun 21 22:55:00 volumio systemd[1]: Started Volumio Time Update Utility. Jun 21 22:55:00 volumio systemd[1]: Reached target Multi-User System. Jun 21 22:55:00 volumio systemd[1]: Reached target Graphical Interface. Jun 21 22:55:00 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Jun 21 22:55:00 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jun 21 22:55:00 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Jun 21 22:55:01 volumio systemd[1]: apt-daily.service: Succeeded. Jun 21 22:55:01 volumio systemd[1]: Started Daily apt download activities. Jun 21 22:55:01 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Jun 21 22:55:01 volumio volumio-remote-updater[626]: [2025-06-21 22:55:01] [connect] Successful connection Jun 21 22:55:01 volumio volumio[933]: info: Loading plugin "network"... Jun 21 22:55:01 volumio volumio[933]: info: Refreshing Cached IP Addresses Jun 21 22:55:01 volumio sudo[1085]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 21 22:55:01 volumio sudo[1085]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 22:55:02 volumio sudo[1085]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:02 volumio sudo[1087]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 21 22:55:02 volumio sudo[1087]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 22:55:02 volumio volumio[933]: info: Loading plugin "services"... Jun 21 22:55:02 volumio sudo[1087]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:02 volumio volumio[933]: info: Loading plugin "alsa_controller"... Jun 21 22:55:02 volumio sudo[1097]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jun 21 22:55:02 volumio sudo[1097]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 22:55:02 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Jun 21 22:55:02 volumio systemd[1]: Started Daily apt upgrade and clean activities. Jun 21 22:55:02 volumio systemd[1]: Startup finished in 14.147s (kernel) + 19.054s (userspace) = 33.201s. Jun 21 22:55:02 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 21 22:55:02 volumio volumio[933]: info: Loading plugin "wizard"... Jun 21 22:55:02 volumio volumio[933]: info: Loading plugin "networkfs"... Jun 21 22:55:02 volumio volumio[933]: info: Starting Udev Watcher for removable devices Jun 21 22:55:02 volumio sudo[1118]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Liang-shu,password=,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.15/Public/Music/ /mnt/NAS/Music Jun 21 22:55:02 volumio sudo[1118]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 22:55:02 volumio volumio[933]: info: Ignoring mount for partition: boot Jun 21 22:55:02 volumio volumio[933]: info: Ignoring mount for partition: volumio Jun 21 22:55:02 volumio volumio[933]: info: Ignoring mount for partition: volumio_data Jun 21 22:55:02 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 21 22:55:02 volumio volumio[933]: info: Loading plugin "volumio_command_line_client"... Jun 21 22:55:02 volumio volumio[933]: info: Loading plugin "upnp"... Jun 21 22:55:02 volumio volumio[933]: info: [1750517702349] Starting Upmpd Daemon Jun 21 22:55:02 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 21 22:55:02 volumio volumio[933]: info: Loading plugin "my_music"... Jun 21 22:55:02 volumio volumio[933]: info: Loading plugin "mpd"... Jun 21 22:55:02 volumio kernel: Key type cifs.spnego registered Jun 21 22:55:02 volumio kernel: Key type cifs.idmap registered Jun 21 22:55:02 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. Jun 21 22:55:02 volumio kernel: CIFS: Attempting to mount //192.168.0.15/Public/Music Jun 21 22:55:02 volumio sudo[1118]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:02 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Jun 21 22:55:02 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -111 Jun 21 22:55:02 volumio sudo[1097]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:02 volumio volumio[933]: info: Loading plugin "upnp_browser"... Jun 21 22:55:03 volumio volumio[933]: info: Loading plugin "alarm-clock"... Jun 21 22:55:03 volumio volumio[933]: info: Loading plugin "airplay_emulation"... Jun 21 22:55:03 volumio volumio[933]: info: Starting Shairport Sync Jun 21 22:55:03 volumio volumio[933]: info: Loading plugin "last_100"... Jun 21 22:55:03 volumio volumio[933]: info: Loading plugin "webradio"... Jun 21 22:55:03 volumio volumio[933]: info: Loading plugin "i2s_dacs"... Jun 21 22:55:03 volumio volumio[933]: info: I2S DAC not set, start Auto-detection Jun 21 22:55:03 volumio volumio[933]: info: Loading plugin "volumiodiscovery"... Jun 21 22:55:03 volumio volumio[933]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 21 22:55:03 volumio volumio[933]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 21 22:55:03 volumio volumio[933]: *** WARNING *** For more information see Jun 21 22:55:03 volumio volumio[933]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 21 22:55:03 volumio node[933]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 21 22:55:03 volumio volumio[933]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 21 22:55:03 volumio volumio[933]: *** WARNING *** For more information see Jun 21 22:55:03 volumio node[933]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 21 22:55:03 volumio node[933]: *** WARNING *** For more information see Jun 21 22:55:03 volumio node[933]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 21 22:55:03 volumio node[933]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 21 22:55:03 volumio node[933]: *** WARNING *** For more information see Jun 21 22:55:03 volumio volumio[933]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 21 22:55:03 volumio volumio[933]: info: Discovery: Started advertising with name: Volumio Jun 21 22:55:03 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 21 22:55:03 volumio volumio[933]: info: Loading plugin "spop"... Jun 21 22:55:06 volumio volumio[933]: info: Loading plugin "outputs"... Jun 21 22:55:06 volumio volumio[933]: info: Loading plugin "albumart"... Jun 21 22:55:06 volumio volumio[933]: info: Plugin example_plugin is not enabled Jun 21 22:55:06 volumio volumio[933]: info: Loading plugin "inputs"... Jun 21 22:55:06 volumio volumio[933]: info: Loading plugin "updater_comm"... Jun 21 22:55:06 volumio volumio[933]: info: Plugin mpdemulation is not enabled Jun 21 22:55:06 volumio volumio[933]: info: Loading plugin "rest_api"... Jun 21 22:55:06 volumio volumio[933]: info: Loading plugin "websocket"... Jun 21 22:55:06 volumio volumio[933]: info: Starting Socket.io Server version 2.3.0 Jun 21 22:55:06 volumio volumio[933]: info: Loading i18n strings for locale zh Jun 21 22:55:06 volumio volumio[933]: Updating browse sources language Jun 21 22:55:06 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 22:55:06 volumio volumio[933]: Forking 3 albumart workers Jun 21 22:55:06 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 21 22:55:06 volumio volumio[933]: info: CoreCommandRouter::initPlayerControls Jun 21 22:55:06 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:06 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:06 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:06 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:06 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:06 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:06 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:06 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:06 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 21 22:55:06 volumio volumio[933]: Express server listening on port 3000 Jun 21 22:55:06 volumio volumio[933]: [Metrics] WebUI: 9s 957.66ms Jun 21 22:55:07 volumio volumio[933]: info: CoreStateMachine::resetVolumioState Jun 21 22:55:07 volumio volumio[933]: info: CoreStateMachine::getcurrentVolume Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::volumioRetrievevolume Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 21 22:55:07 volumio volumio[933]: info: Volumio Network Manager: Network status updated: 1 Jun 21 22:55:07 volumio volumio[933]: info: Cannot mount NAS Music at system boot, trial number 1 ,retrying in 5 seconds Jun 21 22:55:07 volumio volumio[933]: info: Reloading queue from file Jun 21 22:55:07 volumio volumio[933]: info: CoreStateMachine::setRepeat null single undefined Jun 21 22:55:07 volumio volumio[933]: info: CoreStateMachine::pushState Jun 21 22:55:07 volumio volumio[933]: info: CorePlayQueue::getTrack 0 Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::volumioPushState Jun 21 22:55:07 volumio volumio[933]: info: CoreStateMachine::setRandom null Jun 21 22:55:07 volumio volumio[933]: info: CoreStateMachine::pushState Jun 21 22:55:07 volumio volumio[933]: info: CorePlayQueue::getTrack 0 Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::volumioPushState Jun 21 22:55:07 volumio volumio[933]: info: Setting Device type: Raspberry PI Jun 21 22:55:07 volumio volumio[933]: info: VolumeController:: Volume=100 Mute =false Jun 21 22:55:07 volumio volumio[933]: info: CoreStateMachine::pushState Jun 21 22:55:07 volumio volumio[933]: info: CorePlayQueue::getTrack 0 Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::volumioPushState Jun 21 22:55:07 volumio volumio[933]: info: CoreStateMachine::updateTrackBlock Jun 21 22:55:07 volumio volumio[933]: info: CorePlayQueue::getTrackBlock Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::volumioRetrievevolume Jun 21 22:55:07 volumio volumio[933]: info: Discovery: adding dddb96e2-d6fc-442b-8ea3-33834df7247a Jun 21 22:55:07 volumio volumio[933]: info: Discovery: Found device Volumio Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::volumioGetState Jun 21 22:55:07 volumio volumio[933]: info: CorePlayQueue::getTrack 0 Jun 21 22:55:07 volumio volumio[933]: info: Discovery: this is already registered, dddb96e2-d6fc-442b-8ea3-33834df7247a Jun 21 22:55:07 volumio volumio[933]: info: Discovery: Found device Volumio Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::volumioGetState Jun 21 22:55:07 volumio volumio[933]: info: CorePlayQueue::getTrack 0 Jun 21 22:55:07 volumio volumio[933]: info: Completed loading Core Plugins Jun 21 22:55:07 volumio volumio[933]: info: Preparing to generate the ALSA configuration file Jun 21 22:55:07 volumio volumio[933]: info: Asound.conf file unchanged, so no further update is needed Jun 21 22:55:07 volumio volumio[933]: info: Output device has changed, restarting MPD Jun 21 22:55:07 volumio volumio[933]: Starting albumart workers Jun 21 22:55:07 volumio volumio[933]: info: Output device has changed, restarting Shairport Sync Jun 21 22:55:07 volumio volumio[933]: Starting albumart workers Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 21 22:55:07 volumio sudo[1180]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 21 22:55:07 volumio sudo[1180]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 22:55:07 volumio sudo[1182]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 21 22:55:07 volumio sudo[1180]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:07 volumio volumio[933]: Starting albumart workers Jun 21 22:55:07 volumio sudo[1182]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 22:55:07 volumio systemd[1]: Stopping Music Player Daemon... Jun 21 22:55:07 volumio volumio[933]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 21 22:55:07 volumio volumio[933]: info: ___________ START PLUGINS ___________ Jun 21 22:55:07 volumio volumio[933]: info: ControllerMpd::onStart: Initializing MPD Jun 21 22:55:07 volumio volumio[933]: info: Creating MPD Configuration file Jun 21 22:55:07 volumio sudo[1189]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 21 22:55:07 volumio sudo[1189]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 21 22:55:07 volumio volumio[933]: info: [1750517707845] CoreMusicLibrary::Adding element 媒体服务器 Jun 21 22:55:07 volumio sudo[1189]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 21 22:55:07 volumio sudo[1192]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 21 22:55:07 volumio sudo[1192]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 22:55:07 volumio systemd[1]: mpd.service: Succeeded. Jun 21 22:55:07 volumio systemd[1]: Stopped Music Player Daemon. Jun 21 22:55:07 volumio volumio[933]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:07 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 21 22:55:08 volumio systemd[1]: Starting Music Player Daemon... Jun 21 22:55:08 volumio volumio[933]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 21 22:55:08 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jun 21 22:55:08 volumio systemd[1]: mpd.service: Succeeded. Jun 21 22:55:08 volumio systemd[1]: Stopped Music Player Daemon. Jun 21 22:55:08 volumio volumio[933]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 21 22:55:08 volumio volumio[933]: info: [1750517708084] CoreMusicLibrary::Adding element Last_100 Jun 21 22:55:08 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 22:55:08 volumio volumio[933]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 21 22:55:08 volumio volumio[933]: info: [1750517708095] CoreMusicLibrary::Adding element Webradio Jun 21 22:55:08 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 22:55:08 volumio systemd[1]: Starting Music Player Daemon... Jun 21 22:55:08 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 21 22:55:08 volumio volumio[933]: info: Initializing BBC Radios Jun 21 22:55:08 volumio sudo[1201]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 21 22:55:08 volumio sudo[1201]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 22:55:08 volumio sudo[1201]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:08 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 21 22:55:08 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 21 22:55:08 volumio volumio[933]: info: Creating Spotify config file Jun 21 22:55:08 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:08 volumio volumio[933]: info: Volumio Calling Home Jun 21 22:55:08 volumio volumio[933]: info: MPD Permissions set Jun 21 22:55:08 volumio volumio[933]: info: MPD Permissions set Jun 21 22:55:08 volumio volumio[933]: info: VolumeController:: Volume=100 Mute =false Jun 21 22:55:08 volumio volumio[933]: info: CoreStateMachine::pushState Jun 21 22:55:08 volumio volumio[933]: info: CorePlayQueue::getTrack 0 Jun 21 22:55:08 volumio volumio[933]: info: CoreCommandRouter::volumioPushState Jun 21 22:55:08 volumio volumio[933]: info: Spotify config file written Jun 21 22:55:08 volumio sudo[1234]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jun 21 22:55:08 volumio sudo[1234]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 22:55:08 volumio volumio[933]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jun 21 22:55:08 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:08 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:08 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:08 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 21 22:55:09 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:09 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:09 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:09 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:09 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:09 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:09 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:09 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:09 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:09 volumio systemd[1]: Started go-librespot Daemon. Jun 21 22:55:09 volumio go-librespot[1241]: Librespot-go daemon starting... Jun 21 22:55:09 volumio sudo[1234]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:09 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 21 22:55:09 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 21 22:55:09 volumio volumio[933]: info: Starting Shairport Sync Jun 21 22:55:09 volumio volumio[933]: info: Starting Shairport Sync Jun 21 22:55:09 volumio volumio[933]: info: Starting Shairport Sync Jun 21 22:55:09 volumio sudo[1255]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 21 22:55:09 volumio sudo[1257]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 21 22:55:09 volumio sudo[1257]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 22:55:09 volumio sudo[1255]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 22:55:09 volumio sudo[1264]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 21 22:55:09 volumio sudo[1264]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 22:55:09 volumio volumio[933]: info: CoreCommandRouter::volumioGetState Jun 21 22:55:09 volumio volumio[933]: info: CorePlayQueue::getTrack 0 Jun 21 22:55:09 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 21 22:55:09 volumio systemd[1]: shairport-sync.service: Succeeded. Jun 21 22:55:09 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 21 22:55:09 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 21 22:55:09 volumio sudo[1257]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:09 volumio sudo[1264]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:09 volumio volumio[933]: info: Volumio called home Jun 21 22:55:09 volumio sudo[1255]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:09 volumio volumio[933]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 21 22:55:09 volumio volumio[933]: SPOTIFY: BQAKIgwQt5f5z--hFpqVmaEEKt46zmemKcNyu4Xwrh7pEHzcjGmUnMdoUklOYoJhhQgwjZMvUVq1U2tGsj6qorXS4rjdwFSb_ZgXlaDLDlRgVofydMhboYgItFWnFB5sH3A72GGg4rCuipkgqLp3s7uCj6fdfc53wOtu1JNE8MM9znWcUig50rGlJ6zI4sOZV-QHt18s2i0eNsDET7yiDTW7m7Avw883FqrUaApq_LKiUF1AN0ZSB6VllFakwfsyAixGYBdAnrdtiOE0gQ5iP4S9Ne8plyedR-VdQqaKKeYA-Go Jun 21 22:55:09 volumio volumio[933]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 21 22:55:09 volumio volumio[933]: info: New Spotify access token = BQAKIgwQt5f5z--hFpqVmaEEKt46zmemKcNyu4Xwrh7pEHzcjGmUnMdoUklOYoJhhQgwjZMvUVq1U2tGsj6qorXS4rjdwFSb_ZgXlaDLDlRgVofydMhboYgItFWnFB5sH3A72GGg4rCuipkgqLp3s7uCj6fdfc53wOtu1JNE8MM9znWcUig50rGlJ6zI4sOZV-QHt18s2i0eNsDET7yiDTW7m7Avw883FqrUaApq_LKiUF1AN0ZSB6VllFakwfsyAixGYBdAnrdtiOE0gQ5iP4S9Ne8plyedR-VdQqaKKeYA-Go Jun 21 22:55:09 volumio volumio[933]: info: Spotify credentials grant success - running version from March 24, 2019 Jun 21 22:55:09 volumio volumio[933]: info: Shairport-Sync Started Jun 21 22:55:09 volumio volumio[933]: Error adding Membership: Error: addMembership EINVAL Jun 21 22:55:09 volumio volumio[933]: info: Shairport-Sync Started Jun 21 22:55:09 volumio volumio[933]: info: Shairport-Sync Started Jun 21 22:55:09 volumio volumio[933]: SPOTIFY: User informations: {"country":"TW","display_name":"21b63kwp3h6bwtcss2p5wgqcq","email":"lianghsuwang@yahoo.com.tw","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/21b63kwp3h6bwtcss2p5wgqcq"},"followers":{"href":null,"total":5},"href":"https://api.spotify.com/v1/users/21b63kwp3h6bwtcss2p5wgqcq","id":"21b63kwp3h6bwtcss2p5wgqcq","images":[],"product":"premium","type":"user","uri":"spotify:user:21b63kwp3h6bwtcss2p5wgqcq"} Jun 21 22:55:09 volumio volumio[933]: info: Spotify Successfully logged in Jun 21 22:55:09 volumio volumio[933]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 21 22:55:09 volumio volumio[933]: info: [1750517709593] CoreMusicLibrary::Adding element Spotify Jun 21 22:55:09 volumio volumio[933]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 21 22:55:09 volumio volumio[933]: Cannot find translation for source Spotify Jun 21 22:55:09 volumio go-librespot[1241]: time="2025-06-21T22:55:09+08:00" level=info msg="generated new device id: 3c9649ee9f0e47c499ed156512c79b6781b04700" Jun 21 22:55:09 volumio go-librespot[1241]: time="2025-06-21T22:55:09+08:00" level=debug msg="stored credentials found for 21b63kwp3h6bwtcss2p5wgqcq" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+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]" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+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]" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+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]" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+08:00" level=debug msg="zeroconf server listening on port 46047" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+08:00" level=debug msg="obtained new client token: AACSaTxMZ10Mz2sCXklJoL7pCp9HpxxtmQ0QQO9uiwphEJVAPMEffnBtucBNxPuy9AdVE3WcaGKlw30rFMwWqEZP9uDW+81L+7JJvCpAPYuQoWcUaTiwFLFhtx9SqkHg4UQj/7vpEno0jJR5FMw0BQ8RZdgw5sM4tVveM+yqlfC6g4Yk8Q3D0Xf0cHyU8TthBcQstgo7TdERhB+0f0IhESy+5MFyO9uN/+KyK5/7rayxyjHM8JXHiXY/" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+08:00" level=debug msg="completed keyexchange" Jun 21 22:55:10 volumio mpd[1213]: Jun 21 22:55 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 21 22:55:10 volumio systemd[1]: Started Music Player Daemon. Jun 21 22:55:10 volumio sudo[1192]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:10 volumio sudo[1182]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:10 volumio volumio[933]: info: Completed starting Core Plugins Jun 21 22:55:10 volumio volumio[933]: info: ------------------------------------------- Jun 21 22:55:10 volumio volumio[933]: info: ----- MyVolumio plugins startup ---- Jun 21 22:55:10 volumio volumio[933]: info: ------------------------------------------- Jun 21 22:55:10 volumio volumio[933]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 21 22:55:10 volumio volumio[933]: error: MPD error: The expression evaluated to a falsy value: Jun 21 22:55:10 volumio volumio[933]: assert.ok(self.idling) Jun 21 22:55:10 volumio volumio[933]: error: The expression evaluated to a falsy value: Jun 21 22:55:10 volumio volumio[933]: assert.ok(self.idling) Jun 21 22:55:10 volumio volumio[933]: info: MPD running with PID1213 Jun 21 22:55:10 volumio volumio[933]: ,establishing connection Jun 21 22:55:10 volumio volumio[933]: error: updateQueue error: null Jun 21 22:55:10 volumio volumio[933]: error: updateQueue error: null Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+08:00" level=debug msg="completed challenge" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+08:00" level=debug msg="authenticated as 21b63kwp3h6bwtcss2p5wgqcq" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+08:00" level=debug msg="authenticated as 21b63kwp3h6bwtcss2p5wgqcq" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+08:00" level=debug msg="dealer connection opened" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+08:00" level=debug msg="initializing zeroconf session, username: 21b63kwp3h6bwtcss2p5wgqcq" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+08:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+08:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+08:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+08:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+08:00" level=debug msg="autoplay enabled: false" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+08:00" level=debug msg="received connection id: ZTMwNTU4NTUtNDQ4Yy00YmFjLWJiMDgtMWUxYzA2NjJhNmNjK2RlYWxlcit0Y3A6Ly8wYWM5NDg2ZC5pcC5nYWUyLnNwb3RpZnkubmV0OjU3MDArQjg0NEMwOTcxQ0Y4RjA5MjBDNjM5OTY4RDE5REE1RjlDNUI5N0QxODY1QTVFM0YwNTE3MUYwNzdCRTlENUI4Mw==" Jun 21 22:55:10 volumio go-librespot[1241]: time="2025-06-21T22:55:10+08:00" level=debug msg="put connect state because NEW_DEVICE" Jun 21 22:55:12 volumio sudo[1293]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Liang-shu,password=,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.15/Public/Music/ /mnt/NAS/Music Jun 21 22:55:12 volumio sudo[1293]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 22:55:12 volumio kernel: CIFS: Attempting to mount //192.168.0.15/Public/Music Jun 21 22:55:12 volumio volumio[933]: info: go-librespot daemon successfully initialized Jun 21 22:55:12 volumio sudo[1293]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:12 volumio volumio[933]: info: Cannot mount NAS Music at system boot, trial number 2 ,retrying in 5 seconds Jun 21 22:55:12 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Jun 21 22:55:12 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -111 Jun 21 22:55:12 volumio sudo[1298]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 21 22:55:12 volumio sudo[1298]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 22:55:12 volumio sudo[1298]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:12 volumio sudo[1300]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 21 22:55:12 volumio sudo[1300]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 22:55:12 volumio sudo[1300]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:12 volumio sudo[1304]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 21 22:55:12 volumio sudo[1304]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 21 22:55:12 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Jun 21 22:55:12 volumio sudo[1304]: pam_unix(sudo:session): session closed for user root Jun 21 22:55:12 volumio volumio[933]: info: Upmpdcli Daemon Started Jun 21 22:55:12 volumio volumio[1306]: Generating RSA private key, 4096 bit long modulus (2 primes) Jun 21 22:55:13 volumio go-librespot[1241]: time="2025-06-21T22:55:13+08:00" level=debug msg="handling transfer player command from 44ca1a99536af9559a89caa293c455ddc32884a1" Jun 21 22:55:13 volumio go-librespot[1241]: time="2025-06-21T22:55:13+08:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZF1E36JSHD0tWEuz" Jun 21 22:55:13 volumio go-librespot[1241]: time="2025-06-21T22:55:13+08:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:playlist:37i9dQZF1E36JSHD0tWEuz" Jun 21 22:55:13 volumio go-librespot[1241]: time="2025-06-21T22:55:13+08:00" level=debug msg="loading track (paused: true, position: 119819ms)" uri="spotify:track:2afwRzNiZPHOw4FawJTtlV" Jun 21 22:55:13 volumio go-librespot[1241]: time="2025-06-21T22:55:13+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Jun 21 22:55:13 volumio go-librespot[1241]: time="2025-06-21T22:55:13+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 21 22:55:13 volumio go-librespot[1241]: time="2025-06-21T22:55:13+08:00" level=trace msg="emitting websocket event: will_play" Jun 21 22:55:13 volumio go-librespot[1241]: time="2025-06-21T22:55:13+08:00" level=debug msg="selected format OGG_VORBIS_320 (6da1be613b86e9469e71ab68a91e19f76dedaed2)" uri="spotify:track:2afwRzNiZPHOw4FawJTtlV" Jun 21 22:55:13 volumio go-librespot[1241]: time="2025-06-21T22:55:13+08:00" level=debug msg="requested aes key for file 6da1be613b86e9469e71ab68a91e19f76dedaed2, gid: 2afwRzNiZPHOw4FawJTtlV" Jun 21 22:55:13 volumio go-librespot[1241]: time="2025-06-21T22:55:13+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Jun 21 22:55:14 volumio go-librespot[1241]: time="2025-06-21T22:55:14+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1400" Jun 21 22:55:14 volumio go-librespot[1241]: time="2025-06-21T22:55:14+08:00" level=debug msg="fetched first chunk of 19, total size is 9897476 bytes" uri="spotify:track:2afwRzNiZPHOw4FawJTtlV" Jun 21 22:55:14 volumio go-librespot[1241]: time="2025-06-21T22:55:14+08:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:2afwRzNiZPHOw4FawJTtlV" Jun 21 22:55:14 volumio go-librespot[1241]: time="2025-06-21T22:55:14+08:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:2afwRzNiZPHOw4FawJTtlV" Jun 21 22:55:14 volumio go-librespot[1241]: time="2025-06-21T22:55:14+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1144" Jun 21 22:55:14 volumio go-librespot[1241]: time="2025-06-21T22:55:14+08:00" level=debug msg="fetched chunk 11/18, size: 524288" uri="spotify:track:2afwRzNiZPHOw4FawJTtlV" Jun 21 22:55:14 volumio go-librespot[1241]: time="2025-06-21T22:55:14+08:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:2afwRzNiZPHOw4FawJTtlV" Jun 21 22:55:14 volumio go-librespot[1241]: time="2025-06-21T22:55:14+08:00" level=debug msg="fetched chunk 9/18, size: 524288" uri="spotify:track:2afwRzNiZPHOw4FawJTtlV" Jun 21 22:55:14 volumio go-librespot[1241]: time="2025-06-21T22:55:14+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Jun 21 22:55:15 volumio volumio[933]: info: Initializing connection to go-librespot Websocket Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="new websocket client" Jun 21 22:55:15 volumio volumio[933]: info: Connection to go-librespot Websocket established Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="fetched chunk 10/18, size: 524288" uri="spotify:track:2afwRzNiZPHOw4FawJTtlV" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="fetched chunk 8/18, size: 524288" uri="spotify:track:2afwRzNiZPHOw4FawJTtlV" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=trace msg="seek to 119819ms (diff: 142ms, samples: 5284017, bytes: 4269088)" uri="spotify:track:2afwRzNiZPHOw4FawJTtlV" Jun 21 22:55:15 volumio volumio[933]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5011 us, period size = 221 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 99 frames" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="created new output device" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=info msg="loaded track \"永不失联的爱 - Live\" (paused: true, position: 119819ms, duration: 263530ms, prefetched: false)" uri="spotify:track:2afwRzNiZPHOw4FawJTtlV" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=trace msg="emitting websocket event: metadata" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=trace msg="emitting websocket event: active" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="sending successful reply for dealer request" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1E36JSHD0tWEuz" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1E36JSHD0tWEuz" Jun 21 22:55:15 volumio volumio[933]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2afwRzNiZPHOw4FawJTtlV","name":"永不失联的爱 - Live","artist_names":["單依純"],"album_name":"2020中国好声音 第3期 (Live)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02d0fb3d7791cce9b85be917d8","position":119819,"duration":263530,"release_date":"year:2020 month:9 day:4","track_number":3,"disc_number":1}} Jun 21 22:55:15 volumio volumio[933]: SPOTIFY: received: {"type":"active","data":null} Jun 21 22:55:15 volumio volumio[933]: info: Aligning Spotify Volume to Volumio Volume Jun 21 22:55:15 volumio volumio[933]: info: CoreCommandRouter::volumioGetState Jun 21 22:55:15 volumio volumio[933]: info: CorePlayQueue::getTrack 0 Jun 21 22:55:15 volumio volumio[933]: info: Setting Spotify Volume from Volumio: 100 Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=trace msg="emitting websocket event: paused" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="handling update_context player command from 44ca1a99536af9559a89caa293c455ddc32884a1" Jun 21 22:55:15 volumio volumio[933]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2afwRzNiZPHOw4FawJTtlV","play_origin":"playlist"}} Jun 21 22:55:15 volumio volumio[933]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="sending successful reply for dealer request" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="handling resume player command from 44ca1a99536af9559a89caa293c455ddc32884a1" Jun 21 22:55:15 volumio volumio[933]: TypeError: Cannot read property 'service' of undefined Jun 21 22:55:15 volumio volumio[933]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Jun 21 22:55:15 volumio volumio[933]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:270:18) Jun 21 22:55:15 volumio volumio[933]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Jun 21 22:55:15 volumio volumio[933]: at WebSocket.emit (events.js:315:20) Jun 21 22:55:15 volumio volumio[933]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Jun 21 22:55:15 volumio volumio[933]: at Receiver.emit (events.js:315:20) Jun 21 22:55:15 volumio volumio[933]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Jun 21 22:55:15 volumio volumio[933]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Jun 21 22:55:15 volumio volumio[933]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Jun 21 22:55:15 volumio volumio[933]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Jun 21 22:55:15 volumio volumio[933]: at writeOrBuffer (internal/streams/writable.js:358:12) Jun 21 22:55:15 volumio volumio[933]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Jun 21 22:55:15 volumio volumio[933]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Jun 21 22:55:15 volumio volumio[933]: at Socket.emit (events.js:315:20) Jun 21 22:55:15 volumio volumio[933]: at addChunk (internal/streams/readable.js:309:12) Jun 21 22:55:15 volumio volumio[933]: at readableAddChunk (internal/streams/readable.js:284:9) Jun 21 22:55:15 volumio volumio[933]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=trace msg="seek to 119819ms (diff: 142ms, samples: 5284017, bytes: 4269088)" uri="spotify:track:2afwRzNiZPHOw4FawJTtlV" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5011 us, period size = 221 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 99 frames" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="resume track at 119677ms" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=trace msg="scheduling prefetch in 114s" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="sending successful reply for dealer request" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 21 22:55:15 volumio go-librespot[1241]: time="2025-06-21T22:55:15+08:00" level=trace msg="emitting websocket event: playing" Jun 21 22:55:16 volumio volumio[1306]: ........................++++ Jun 21 22:55:16 volumio sudo[1334]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-21 22:54 Jun 21 22:55:16 volumio sudo[1334]: 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"