-- Logs begin at Sun 2025-05-04 14:23:52 EDT, end at Sun 2025-05-04 15:57:47 EDT. -- May 04 15:56:13 pawse-speakers volumio-remote-updater[542]: [2025-05-04 15:56:13] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] May 04 15:56:18 pawse-speakers volumio-remote-updater[542]: [2025-05-04 15:56:18] [connect] Successful connection May 04 15:56:29 pawse-speakers volumio[19715]: <--- Last few GCs ---> May 04 15:56:29 pawse-speakers volumio[19715]: [19715:0x38a0780] 53996 ms: Mark-sweep (reduce) 213.0 (219.6) -> 213.0 (219.8) MB, 532.3 / 0.1 ms (average mu = 0.102, current mu = 0.002) allocation failure GC in old space requested May 04 15:56:29 pawse-speakers volumio[19715]: [19715:0x38a0780] 55406 ms: Mark-sweep (reduce) 213.0 (218.3) -> 213.0 (218.6) MB, 1409.9 / 0.1 ms (average mu = 0.039, current mu = 0.000) allocation failure GC in old space requested May 04 15:56:29 pawse-speakers volumio[19715]: <--- JS stacktrace ---> May 04 15:56:29 pawse-speakers volumio[19715]: FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory May 04 15:56:29 pawse-speakers go-librespot[19876]: time="2025-05-04T15:56:29-04:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" May 04 15:56:29 pawse-speakers systemd[1]: volumio.service: Main process exited, code=killed, status=6/ABRT May 04 15:56:29 pawse-speakers systemd[1]: volumio.service: Failed with result 'signal'. May 04 15:56:29 pawse-speakers systemd[1]: Started dynamicswap service. May 04 15:56:29 pawse-speakers systemd[1]: dynamicswap.service: Succeeded. May 04 15:56:29 pawse-speakers systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. May 04 15:56:29 pawse-speakers systemd[1]: volumio.service: Scheduled restart job, restart counter is at 51. May 04 15:56:29 pawse-speakers systemd[1]: Started dynamicswap service. May 04 15:56:29 pawse-speakers systemd[1]: Stopped Volumio Backend Module. May 04 15:56:29 pawse-speakers systemd[1]: Started Volumio Backend Module. May 04 15:56:29 pawse-speakers systemd[1]: dynamicswap.service: Succeeded. May 04 15:56:30 pawse-speakers volumio-remote-updater[542]: [2025-05-04 15:56:30] [connect] Successful connection May 04 15:56:31 pawse-speakers volumio[20125]: info: ------------------------------------------- May 04 15:56:31 pawse-speakers volumio[20125]: info: ----- Volumio3 ---- May 04 15:56:31 pawse-speakers volumio[20125]: info: ------------------------------------------- May 04 15:56:31 pawse-speakers volumio[20125]: info: ----- System startup ---- May 04 15:56:31 pawse-speakers volumio[20125]: info: ------------------------------------------- May 04 15:56:31 pawse-speakers volumio[20125]: info: MYVOLUMIO Environment detected May 04 15:56:32 pawse-speakers volumio[20125]: info: Plugin folders cleanup May 04 15:56:32 pawse-speakers volumio[20125]: info: Scanning into folder /volumio/app/plugins/ May 04 15:56:32 pawse-speakers volumio[20125]: info: Scanning category audio_interface May 04 15:56:32 pawse-speakers volumio[20125]: info: Scanning category miscellanea May 04 15:56:32 pawse-speakers volumio[20125]: info: Scanning category music_service May 04 15:56:32 pawse-speakers volumio[20125]: info: Scanning category plugins.json May 04 15:56:32 pawse-speakers volumio[20125]: info: Scanning category system_controller May 04 15:56:32 pawse-speakers volumio[20125]: info: Scanning category user_interface May 04 15:56:32 pawse-speakers volumio[20125]: info: Scanning into folder /data/plugins/ May 04 15:56:32 pawse-speakers volumio[20125]: info: Scanning category audio_interface May 04 15:56:32 pawse-speakers volumio[20125]: info: Scanning category music_service May 04 15:56:32 pawse-speakers volumio[20125]: info: Scanning category user_interface May 04 15:56:32 pawse-speakers volumio[20125]: info: Plugin folders cleanup completed May 04 15:56:32 pawse-speakers volumio[20125]: info: ------------------------------------------- May 04 15:56:32 pawse-speakers volumio[20125]: info: ----- Core plugins startup ---- May 04 15:56:32 pawse-speakers volumio[20125]: info: ------------------------------------------- May 04 15:56:32 pawse-speakers volumio[20125]: info: Loading plugins from folder /volumio/app/plugins/ May 04 15:56:32 pawse-speakers volumio[20125]: info: Adding plugin upnp to MyMusic Plugins May 04 15:56:32 pawse-speakers volumio[20125]: info: Adding plugin airplay_emulation to MyMusic Plugins May 04 15:56:32 pawse-speakers volumio[20125]: info: Adding plugin upnp_browser to MyMusic Plugins May 04 15:56:32 pawse-speakers volumio[20125]: info: Loading plugins from folder /data/plugins/ May 04 15:56:32 pawse-speakers volumio[20125]: info: Loading plugin "system"... May 04 15:56:32 pawse-speakers volumio[20125]: info: Loading plugin "appearance"... May 04 15:56:33 pawse-speakers volumio[20125]: info: Loading plugin "network"... May 04 15:56:33 pawse-speakers volumio[20125]: info: Refreshing Cached IP Addresses May 04 15:56:33 pawse-speakers sudo[20151]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 04 15:56:33 pawse-speakers sudo[20151]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:33 pawse-speakers sudo[20151]: pam_unix(sudo:session): session closed for user root May 04 15:56:33 pawse-speakers sudo[20153]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 04 15:56:33 pawse-speakers volumio[20125]: info: Loading plugin "services"... May 04 15:56:33 pawse-speakers sudo[20153]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:33 pawse-speakers volumio[20125]: info: Loading plugin "alsa_controller"... May 04 15:56:33 pawse-speakers sudo[20153]: pam_unix(sudo:session): session closed for user root May 04 15:56:33 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 04 15:56:33 pawse-speakers volumio[20125]: info: Loading plugin "wizard"... May 04 15:56:33 pawse-speakers volumio[20125]: info: Loading plugin "networkfs"... May 04 15:56:33 pawse-speakers volumio[20125]: info: Cannot mount NAS Server at system boot, trial number 1 ,retrying in 5 seconds May 04 15:56:33 pawse-speakers volumio[20125]: info: Starting Udev Watcher for removable devices May 04 15:56:33 pawse-speakers volumio[20125]: info: Ignoring mount for partition: boot May 04 15:56:33 pawse-speakers volumio[20125]: info: Ignoring mount for partition: volumio May 04 15:56:33 pawse-speakers volumio[20125]: info: Ignoring mount for partition: volumio_data May 04 15:56:33 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 04 15:56:33 pawse-speakers volumio[20125]: info: Loading plugin "volumio_command_line_client"... May 04 15:56:33 pawse-speakers volumio[20125]: info: Loading plugin "upnp"... May 04 15:56:33 pawse-speakers volumio[20125]: info: [1746388593401] Starting Upmpd Daemon May 04 15:56:33 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 04 15:56:33 pawse-speakers volumio[20125]: info: Loading plugin "my_music"... May 04 15:56:33 pawse-speakers volumio[20125]: info: Loading plugin "mpd"... May 04 15:56:33 pawse-speakers volumio[20125]: info: Loading plugin "upnp_browser"... May 04 15:56:34 pawse-speakers volumio[20125]: info: Loading plugin "alarm-clock"... May 04 15:56:34 pawse-speakers volumio[20125]: info: Loading plugin "airplay_emulation"... May 04 15:56:34 pawse-speakers volumio[20125]: info: Starting Shairport Sync May 04 15:56:34 pawse-speakers volumio[20125]: info: Loading plugin "last_100"... May 04 15:56:34 pawse-speakers volumio[20125]: info: Loading plugin "webradio"... May 04 15:56:34 pawse-speakers volumio[20125]: info: Loading plugin "i2s_dacs"... May 04 15:56:34 pawse-speakers volumio[20125]: info: Loading plugin "volumiodiscovery"... May 04 15:56:34 pawse-speakers volumio[20125]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 04 15:56:34 pawse-speakers volumio[20125]: *** WARNING *** Please fix your application to use the native API of Avahi! May 04 15:56:34 pawse-speakers volumio[20125]: *** WARNING *** For more information see May 04 15:56:34 pawse-speakers node[20125]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 04 15:56:34 pawse-speakers volumio[20125]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 04 15:56:34 pawse-speakers volumio[20125]: *** WARNING *** Please fix your application to use the native API of Avahi! May 04 15:56:34 pawse-speakers volumio[20125]: *** WARNING *** For more information see May 04 15:56:34 pawse-speakers node[20125]: *** WARNING *** Please fix your application to use the native API of Avahi! May 04 15:56:34 pawse-speakers node[20125]: *** WARNING *** For more information see May 04 15:56:34 pawse-speakers node[20125]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 04 15:56:34 pawse-speakers node[20125]: *** WARNING *** Please fix your application to use the native API of Avahi! May 04 15:56:34 pawse-speakers node[20125]: *** WARNING *** For more information see May 04 15:56:34 pawse-speakers volumio[20125]: info: Applying required configuration parameters for plugin volumiodiscovery May 04 15:56:34 pawse-speakers volumio[20125]: info: Discovery: Started advertising with name: Pawse Speakers May 04 15:56:34 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 04 15:56:34 pawse-speakers volumio[20125]: info: Loading plugin "spop"... May 04 15:56:35 pawse-speakers volumio[20125]: info: Loading plugin "outputs"... May 04 15:56:35 pawse-speakers volumio[20125]: info: Loading plugin "albumart"... May 04 15:56:35 pawse-speakers volumio[20125]: info: Plugin example_plugin is not enabled May 04 15:56:35 pawse-speakers volumio[20125]: info: Loading plugin "inputs"... May 04 15:56:35 pawse-speakers volumio[20125]: info: Loading plugin "updater_comm"... May 04 15:56:35 pawse-speakers volumio[20125]: info: Plugin mpdemulation is not enabled May 04 15:56:35 pawse-speakers volumio[20125]: info: Loading plugin "rest_api"... May 04 15:56:35 pawse-speakers volumio[20125]: info: Loading plugin "websocket"... May 04 15:56:35 pawse-speakers volumio[20125]: info: Starting Socket.io Server version 2.3.0 May 04 15:56:35 pawse-speakers volumio[20125]: info: Loading plugin "fusiondsp"... May 04 15:56:36 pawse-speakers volumio[20125]: Forking 3 albumart workers May 04 15:56:36 pawse-speakers volumio[20125]: info: Applying required configuration parameters for plugin fusiondsp May 04 15:56:36 pawse-speakers volumio[20125]: info: Loading plugin "Systeminfo"... May 04 15:56:36 pawse-speakers volumio[20125]: info: Loading i18n strings for locale en May 04 15:56:36 pawse-speakers volumio[20125]: Updating browse sources language May 04 15:56:36 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 15:56:36 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 04 15:56:36 pawse-speakers volumio[20125]: info: CoreCommandRouter::initPlayerControls May 04 15:56:36 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:36 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:36 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:36 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:36 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:36 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:36 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:36 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:36 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 04 15:56:36 pawse-speakers volumio[20125]: Express server listening on port 3000 May 04 15:56:36 pawse-speakers volumio[20125]: [Metrics] WebUI: 6s 253.90ms May 04 15:56:36 pawse-speakers volumio[20125]: info: CoreStateMachine::resetVolumioState May 04 15:56:36 pawse-speakers volumio[20125]: info: CoreStateMachine::getcurrentVolume May 04 15:56:36 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioRetrievevolume May 04 15:56:37 pawse-speakers volumio[20125]: info: Volumio Network Manager: Network status updated: 1 May 04 15:56:37 pawse-speakers volumio[20125]: Starting albumart workers May 04 15:56:37 pawse-speakers volumio[20125]: Starting albumart workers May 04 15:56:37 pawse-speakers volumio[20125]: Starting albumart workers May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioGetState May 04 15:56:37 pawse-speakers volumio[20125]: info: CorePlayQueue::getTrack 0 May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:56:37 pawse-speakers volumio[20125]: info: Reloading queue from file May 04 15:56:37 pawse-speakers volumio[20125]: info: VolumeController:: Volume=45 Mute =false May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreStateMachine::pushState May 04 15:56:37 pawse-speakers volumio[20125]: info: CorePlayQueue::getTrack 0 May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioPushState May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreStateMachine::updateTrackBlock May 04 15:56:37 pawse-speakers volumio[20125]: info: CorePlayQueue::getTrackBlock May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioRetrievevolume May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreStateMachine::setRepeat null single undefined May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreStateMachine::pushState May 04 15:56:37 pawse-speakers volumio[20125]: info: CorePlayQueue::getTrack 0 May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioPushState May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreStateMachine::setRandom true May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreStateMachine::pushState May 04 15:56:37 pawse-speakers volumio[20125]: info: CorePlayQueue::getTrack 0 May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioPushState May 04 15:56:37 pawse-speakers volumio[20125]: info: Setting Device type: Raspberry PI May 04 15:56:37 pawse-speakers volumio[20125]: info: Listing playlists May 04 15:56:37 pawse-speakers volumio[20125]: info: Listing playlists May 04 15:56:37 pawse-speakers volumio[20125]: info: Completed loading Core Plugins May 04 15:56:37 pawse-speakers volumio[20125]: info: Preparing to generate the ALSA configuration file May 04 15:56:37 pawse-speakers volumio[20125]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 04 15:56:37 pawse-speakers volumio[20125]: info: Reading ALSA contributions from plugins. May 04 15:56:37 pawse-speakers volumio[20125]: info: Asound.conf file unchanged, so no further update is needed May 04 15:56:37 pawse-speakers volumio[20125]: info: Output device has changed, restarting MPD May 04 15:56:37 pawse-speakers sudo[20221]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 04 15:56:37 pawse-speakers sudo[20221]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:37 pawse-speakers sudo[20221]: pam_unix(sudo:session): session closed for user root May 04 15:56:37 pawse-speakers volumio[20125]: info: Output device has changed, restarting Shairport Sync May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:56:37 pawse-speakers sudo[20225]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 04 15:56:37 pawse-speakers sudo[20225]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:37 pawse-speakers volumio[20125]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 04 15:56:37 pawse-speakers volumio[20125]: info: ___________ START PLUGINS ___________ May 04 15:56:37 pawse-speakers volumio[20125]: info: ControllerMpd::onStart: Initializing MPD May 04 15:56:37 pawse-speakers volumio[20125]: info: Creating MPD Configuration file May 04 15:56:37 pawse-speakers systemd[1]: Stopping Music Player Daemon... May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 15:56:37 pawse-speakers volumio[20125]: info: [1746388597915] CoreMusicLibrary::Adding element Media Servers May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 15:56:37 pawse-speakers sudo[20231]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 04 15:56:37 pawse-speakers sudo[20231]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:37 pawse-speakers systemd[1]: mpd.service: Succeeded. May 04 15:56:37 pawse-speakers systemd[1]: Stopped Music Player Daemon. May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:37 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:56:37 pawse-speakers sudo[20233]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 04 15:56:37 pawse-speakers sudo[20233]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:38 pawse-speakers systemd[1]: Starting Music Player Daemon... May 04 15:56:37 pawse-speakers sudo[20231]: pam_unix(sudo:session): session closed for user root May 04 15:56:38 pawse-speakers systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM May 04 15:56:38 pawse-speakers systemd[1]: mpd.service: Succeeded. May 04 15:56:38 pawse-speakers systemd[1]: Stopped Music Player Daemon. May 04 15:56:38 pawse-speakers volumio[20125]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:56:38 pawse-speakers systemd[1]: Starting Music Player Daemon... May 04 15:56:38 pawse-speakers volumio[20125]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 15:56:38 pawse-speakers volumio[20125]: info: [1746388598144] CoreMusicLibrary::Adding element Last_100 May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 15:56:38 pawse-speakers volumio[20125]: info: [1746388598148] CoreMusicLibrary::Adding element Webradio May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 04 15:56:38 pawse-speakers volumio[20125]: info: Initializing BBC Radios May 04 15:56:38 pawse-speakers sudo[20256]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 04 15:56:38 pawse-speakers sudo[20256]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:38 pawse-speakers sudo[20256]: pam_unix(sudo:session): session closed for user root May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:56:38 pawse-speakers volumio[20125]: info: Creating Spotify config file May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:38 pawse-speakers volumio[20125]: info: Loading i18n strings for locale en May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:38 pawse-speakers volumio[20125]: info: FusionDsp - mixtype--------------------- Hardware May 04 15:56:38 pawse-speakers volumio[20125]: info: Volumio Calling Home May 04 15:56:38 pawse-speakers volumio[20125]: info: Preparing to generate the ALSA configuration file May 04 15:56:38 pawse-speakers volumio[20125]: info: Cannot mount NAS Server at system boot, trial number 2 ,retrying in 5 seconds May 04 15:56:38 pawse-speakers volumio[20125]: info: Discovery: adding 93e32e89-0306-43bc-b876-efb00cb7ebbb May 04 15:56:38 pawse-speakers volumio[20125]: info: Discovery: Found device Pawse Speakers May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioGetState May 04 15:56:38 pawse-speakers volumio[20125]: info: CorePlayQueue::getTrack 0 May 04 15:56:38 pawse-speakers volumio[20125]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 04 15:56:38 pawse-speakers volumio[20125]: info: Reading ALSA contributions from plugins. May 04 15:56:38 pawse-speakers volumio[20125]: info: MPD Permissions set May 04 15:56:38 pawse-speakers volumio[20125]: info: MPD Permissions set May 04 15:56:38 pawse-speakers volumio[20125]: info: VolumeController:: Volume=45 Mute =false May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreStateMachine::pushState May 04 15:56:38 pawse-speakers volumio[20125]: info: CorePlayQueue::getTrack 0 May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioPushState May 04 15:56:38 pawse-speakers volumio[20125]: info: Spotify config file written May 04 15:56:38 pawse-speakers sudo[20284]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 04 15:56:38 pawse-speakers sudo[20284]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:38 pawse-speakers volumio[20125]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:38 pawse-speakers systemd[1]: Stopping go-librespot Daemon... May 04 15:56:38 pawse-speakers systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM May 04 15:56:38 pawse-speakers systemd[1]: go-librespot-daemon.service: Succeeded. May 04 15:56:38 pawse-speakers systemd[1]: Stopped go-librespot Daemon. May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:38 pawse-speakers systemd[1]: Started go-librespot Daemon. May 04 15:56:38 pawse-speakers go-librespot[20290]: Librespot-go daemon starting... May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:56:38 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:38 pawse-speakers sudo[20284]: pam_unix(sudo:session): session closed for user root May 04 15:56:38 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:38-04:00" level=info msg="generated new device id: d2c3be9df626327d4e9961ff0d14bc9167db08b8" May 04 15:56:38 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:38-04:00" level=debug msg="stored credentials found for 21bhtp2smvadava6jxb4tv7ti" May 04 15:56:38 pawse-speakers volumio[20125]: info: Volumio called home May 04 15:56:38 pawse-speakers volumio[20125]: info: Starting Shairport Sync May 04 15:56:38 pawse-speakers volumio[20125]: info: Starting Shairport Sync May 04 15:56:39 pawse-speakers volumio[20125]: info: Starting Shairport Sync May 04 15:56:39 pawse-speakers sudo[20303]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 04 15:56:39 pawse-speakers sudo[20303]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:39 pawse-speakers sudo[20305]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 04 15:56:39 pawse-speakers sudo[20305]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:39 pawse-speakers sudo[20308]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 04 15:56:39 pawse-speakers sudo[20308]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:39 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioGetState May 04 15:56:39 pawse-speakers volumio[20125]: info: CorePlayQueue::getTrack 0 May 04 15:56:39 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:39-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 04 15:56:39 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:39-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 04 15:56:39 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:39-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 04 15:56:39 pawse-speakers systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 04 15:56:39 pawse-speakers systemd[1]: shairport-sync.service: Succeeded. May 04 15:56:39 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:39-04:00" level=debug msg="zeroconf server listening on port 39711" May 04 15:56:39 pawse-speakers systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 04 15:56:39 pawse-speakers volumio[20125]: info: Asound.conf file unchanged, so no further update is needed May 04 15:56:39 pawse-speakers volumio[20125]: info: Output device has changed, restarting MPD May 04 15:56:39 pawse-speakers volumio[20125]: info: Output device has changed, restarting Shairport Sync May 04 15:56:39 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:39 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:56:39 pawse-speakers sudo[20313]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 04 15:56:39 pawse-speakers systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 04 15:56:39 pawse-speakers sudo[20313]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:39 pawse-speakers sudo[20305]: pam_unix(sudo:session): session closed for user root May 04 15:56:39 pawse-speakers sudo[20303]: pam_unix(sudo:session): session closed for user root May 04 15:56:39 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:39-04:00" level=debug msg="obtained new client token: AABmvhRNCoB7tl0bCgNwGIrCPLQqc1Eyn0crfwRu6yIM7cxniTH3kBDnkjSWjYGrNXVGOGBOyMbRQD8urvEGEb969/xfR5FsG6AqlhtLtU7Q5+X9h9jjlbNBDIxFBmAyHNPJL8hxH1VypsSZ/o9wGS2YnuQYTBBB9JT4hKjnEjZ/92G01j8BT7kQsuT2/Gt+o/v4IlPt0pqSjmngcSsPivly+VvdRTh6gembk0tMkaJIKdGqCz3aNh32" May 04 15:56:39 pawse-speakers sudo[20315]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 04 15:56:39 pawse-speakers sudo[20315]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:39 pawse-speakers sudo[20308]: pam_unix(sudo:session): session closed for user root May 04 15:56:39 pawse-speakers sudo[20313]: pam_unix(sudo:session): session closed for user root May 04 15:56:39 pawse-speakers systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 04 15:56:39 pawse-speakers systemd[1]: mpd.service: Succeeded. May 04 15:56:39 pawse-speakers systemd[1]: Stopped Music Player Daemon. May 04 15:56:39 pawse-speakers systemd[1]: Starting Music Player Daemon... May 04 15:56:39 pawse-speakers volumio[20125]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 04 15:56:39 pawse-speakers volumio[20125]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 04 15:56:39 pawse-speakers volumio[20125]: SPOTIFY: BQB2NUe94NzJnwtzDxt9hVNgLSGU8fzs1j5TrjpxcEPk3QSSh0kvEpweE5MTIA94uHJ8HgPp6EEz7yiOPsjFReT-BEhs2RANRNBymrQTjSWtdfcZ7yB0ieUv9PQhbnYtnnH6r1p3hgwB77nJNCLFdbtdlaDDj1_FArfTc5xwseFXRXlkLuwSfdnIgqp1upEmvoHVGGb2mxY6v1uVTC-oPelQFmM1z9QRs3UyySbIZiGbtTMdFYuD0iyCTEWu_NZXqJmGqOV1Q8b2JXvAKYP2AFg83-u7UfcWfF4iwLtJAbPc2xE May 04 15:56:39 pawse-speakers volumio[20125]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 04 15:56:39 pawse-speakers volumio[20125]: info: New Spotify access token = BQB2NUe94NzJnwtzDxt9hVNgLSGU8fzs1j5TrjpxcEPk3QSSh0kvEpweE5MTIA94uHJ8HgPp6EEz7yiOPsjFReT-BEhs2RANRNBymrQTjSWtdfcZ7yB0ieUv9PQhbnYtnnH6r1p3hgwB77nJNCLFdbtdlaDDj1_FArfTc5xwseFXRXlkLuwSfdnIgqp1upEmvoHVGGb2mxY6v1uVTC-oPelQFmM1z9QRs3UyySbIZiGbtTMdFYuD0iyCTEWu_NZXqJmGqOV1Q8b2JXvAKYP2AFg83-u7UfcWfF4iwLtJAbPc2xE May 04 15:56:39 pawse-speakers volumio[20125]: info: Spotify credentials grant success - running version from March 24, 2019 May 04 15:56:39 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:39-04:00" level=debug msg="completed keyexchange" May 04 15:56:39 pawse-speakers volumio[20125]: info: MPD Permissions set May 04 15:56:39 pawse-speakers volumio[20125]: info: Shairport-Sync Started May 04 15:56:39 pawse-speakers volumio[20125]: Error adding Membership: Error: addMembership EINVAL May 04 15:56:39 pawse-speakers volumio[20125]: info: Shairport-Sync Started May 04 15:56:39 pawse-speakers volumio[20125]: info: Shairport-Sync Started May 04 15:56:39 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:39 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:39 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:39 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:39 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:39 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:39 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:39 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:39 pawse-speakers sudo[20323]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 04 15:56:39 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:56:39 pawse-speakers sudo[20323]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:39 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:39 pawse-speakers sudo[20323]: pam_unix(sudo:session): session closed for user root May 04 15:56:39 pawse-speakers volumio[20125]: info: Starting Shairport Sync May 04 15:56:39 pawse-speakers sudo[20332]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 04 15:56:39 pawse-speakers sudo[20332]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:39 pawse-speakers systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 04 15:56:39 pawse-speakers systemd[1]: shairport-sync.service: Succeeded. May 04 15:56:39 pawse-speakers systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 04 15:56:39 pawse-speakers systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 04 15:56:39 pawse-speakers volumio[20125]: SPOTIFY: User informations: {"country":"CA","display_name":"Paul Goodship","email":"itsme16688@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/21bhtp2smvadava6jxb4tv7ti"},"followers":{"href":null,"total":19},"href":"https://api.spotify.com/v1/users/21bhtp2smvadava6jxb4tv7ti","id":"21bhtp2smvadava6jxb4tv7ti","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=10152364741440856&height=300&width=300&ext=1748954433&hash=AbbQ6gNcuvaDcOW2jcpTQkvq","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=10152364741440856&height=50&width=50&ext=1748954433&hash=AbZHo20tk5vS50abgqpzoDUg","width":64}],"product":"premium","type":"user","uri":"spotify:user:21bhtp2smvadava6jxb4tv7ti"} May 04 15:56:39 pawse-speakers volumio[20125]: info: Spotify Successfully logged in May 04 15:56:39 pawse-speakers sudo[20332]: pam_unix(sudo:session): session closed for user root May 04 15:56:39 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 15:56:39 pawse-speakers volumio[20125]: info: [1746388599584] CoreMusicLibrary::Adding element Spotify May 04 15:56:39 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 15:56:39 pawse-speakers volumio[20125]: Cannot find translation for source Spotify May 04 15:56:39 pawse-speakers volumio[20125]: info: Shairport-Sync Started May 04 15:56:39 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:39-04:00" level=debug msg="completed challenge" May 04 15:56:39 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:39-04:00" level=debug msg="authenticated as 21bhtp2smvadava6jxb4tv7ti" May 04 15:56:40 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:40-04:00" level=debug msg="authenticated as 21bhtp2smvadava6jxb4tv7ti" May 04 15:56:40 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:40-04:00" level=debug msg="dealer connection opened" May 04 15:56:40 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:40-04:00" level=debug msg="initializing zeroconf session, username: 21bhtp2smvadava6jxb4tv7ti" May 04 15:56:40 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:40-04:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 04 15:56:40 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:40-04:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 04 15:56:40 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:40-04:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 04 15:56:40 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:40-04:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 04 15:56:40 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:40-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 04 15:56:40 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:40-04:00" level=debug msg="autoplay enabled: false" May 04 15:56:40 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:40-04:00" level=debug msg="received connection id: MWU3ZWExNmUtMDI2Mi00MDkwLTk1MGMtNGM1ZjM2MGE5YTE3K2RlYWxlcit0Y3A6Ly8wYWNiZmJjYS5pcC5ndWUxLnNwb3RpZnkubmV0OjU3MDArMDgxN0Q2MEJEOUY3Q0Q3NUY2MDM5MzIzMEZENzhFQzNCRTczQkQ2OEQwMzZBQTQ2MjE1OUNBQzBFQjQ3Njg4Mw==" May 04 15:56:40 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:40-04:00" level=debug msg="put connect state because NEW_DEVICE" May 04 15:56:40 pawse-speakers volumio[20125]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists May 04 15:56:40 pawse-speakers volumio[20125]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo May 04 15:56:40 pawse-speakers volumio[20125]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists May 04 15:56:40 pawse-speakers volumio[20125]: info: camilladsp spawned new process with pid 20344, instance 1, run: true May 04 15:56:40 pawse-speakers volumio[20125]: info: camilladsp service started and running in background, instance 1 May 04 15:56:40 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:56:40 pawse-speakers volumio[20125]: cannot open device 'volumioHw': Device or resource busy May 04 15:56:40 pawse-speakers volumio[20125]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json May 04 15:56:40 pawse-speakers volumio[20125]: cannot open device 'volumioHw': Device or resource busy May 04 15:56:40 pawse-speakers volumio[20125]: info: FusionDsp loaded May 04 15:56:40 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 04 15:56:40 pawse-speakers sudo[20354]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service May 04 15:56:40 pawse-speakers sudo[20354]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:40 pawse-speakers volumio[20125]: info: FusionDsp - Reporting Fusion DSP Enabled May 04 15:56:40 pawse-speakers volumio[20125]: info: Adding Signal Path Element [object Object] May 04 15:56:40 pawse-speakers volumio[20125]: info: Adding fusiondspeq DSP Signal Path Element May 04 15:56:40 pawse-speakers volumio[20125]: info: FusionDsp - ---- installed callbackRead May 04 15:56:40 pawse-speakers volumio[20125]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 04 15:56:40 pawse-speakers sudo[20354]: pam_unix(sudo:session): session closed for user root May 04 15:56:40 pawse-speakers volumio[20125]: info: FusionDsp - Loudness is ON true May 04 15:56:40 pawse-speakers volumio[20125]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 May 04 15:56:40 pawse-speakers volumio[20125]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 04 15:56:40 pawse-speakers mpd[20330]: May 04 15:56 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 04 15:56:41 pawse-speakers systemd[1]: Started Music Player Daemon. May 04 15:56:41 pawse-speakers sudo[20233]: pam_unix(sudo:session): session closed for user root May 04 15:56:41 pawse-speakers sudo[20315]: pam_unix(sudo:session): session closed for user root May 04 15:56:41 pawse-speakers sudo[20225]: pam_unix(sudo:session): session closed for user root May 04 15:56:41 pawse-speakers volumio[20125]: info: Completed starting Core Plugins May 04 15:56:41 pawse-speakers volumio[20125]: info: ------------------------------------------- May 04 15:56:41 pawse-speakers volumio[20125]: info: ----- MyVolumio plugins startup ---- May 04 15:56:41 pawse-speakers volumio[20125]: info: ------------------------------------------- May 04 15:56:41 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Fetching plans data.... May 04 15:56:41 pawse-speakers volumio[20125]: error: MPD error: The expression evaluated to a falsy value: May 04 15:56:41 pawse-speakers volumio[20125]: assert.ok(self.idling) May 04 15:56:41 pawse-speakers volumio[20125]: error: The expression evaluated to a falsy value: May 04 15:56:41 pawse-speakers volumio[20125]: assert.ok(self.idling) May 04 15:56:41 pawse-speakers volumio[20125]: error: MPD error: The expression evaluated to a falsy value: May 04 15:56:41 pawse-speakers volumio[20125]: assert.ok(self.idling) May 04 15:56:41 pawse-speakers volumio[20125]: error: The expression evaluated to a falsy value: May 04 15:56:41 pawse-speakers volumio[20125]: assert.ok(self.idling) May 04 15:56:41 pawse-speakers volumio[20125]: info: MPD running with PID20330 May 04 15:56:41 pawse-speakers volumio[20125]: ,establishing connection May 04 15:56:41 pawse-speakers volumio[20125]: error: updateQueue error: null May 04 15:56:41 pawse-speakers volumio[20125]: error: updateQueue error: null May 04 15:56:41 pawse-speakers volumio[20125]: info: go-librespot daemon successfully initialized May 04 15:56:43 pawse-speakers sudo[20376]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 04 15:56:43 pawse-speakers sudo[20376]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:43 pawse-speakers sudo[20376]: pam_unix(sudo:session): session closed for user root May 04 15:56:43 pawse-speakers sudo[20378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 04 15:56:43 pawse-speakers sudo[20378]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:43 pawse-speakers sudo[20378]: pam_unix(sudo:session): session closed for user root May 04 15:56:43 pawse-speakers sudo[20382]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 04 15:56:43 pawse-speakers sudo[20382]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:43 pawse-speakers sudo[20382]: pam_unix(sudo:session): session closed for user root May 04 15:56:43 pawse-speakers volumio[20125]: info: Upmpdcli Daemon Started May 04 15:56:43 pawse-speakers volumio[20125]: info: Cannot mount NAS Server at system boot, trial number 3 ,retrying in 5 seconds May 04 15:56:44 pawse-speakers volumio[20125]: info: Initializing connection to go-librespot Websocket May 04 15:56:44 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:44-04:00" level=debug msg="new websocket client" May 04 15:56:44 pawse-speakers volumio[20125]: info: Connection to go-librespot Websocket established May 04 15:56:45 pawse-speakers volumio-remote-updater[542]: [2025-05-04 15:56:45] [connect] Successful connection May 04 15:56:45 pawse-speakers volumio[20125]: 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: 3 May 04 15:56:45 pawse-speakers volumio-remote-updater[542]: [2025-05-04 15:56:45] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1746388605 101 May 04 15:56:46 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioGetState May 04 15:56:46 pawse-speakers volumio[20125]: info: CorePlayQueue::getTrack 0 May 04 15:56:46 pawse-speakers volumio[20125]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory May 04 15:56:48 pawse-speakers volumio[20125]: info: Getting Spotify volume May 04 15:56:49 pawse-speakers volumio[20125]: info: Spotify volume: 100 May 04 15:56:50 pawse-speakers volumio[20125]: info: Cannot mount NAS Server at system boot, trial number 4 ,retrying in 5 seconds May 04 15:56:50 pawse-speakers volumio[20125]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 May 04 15:56:50 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioGetState May 04 15:56:50 pawse-speakers volumio[20125]: info: CorePlayQueue::getTrack 0 May 04 15:56:50 pawse-speakers volumio[20125]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 May 04 15:56:50 pawse-speakers volumio[20125]: SPOTIFY: SPOTIFY VOLUME 100 May 04 15:56:50 pawse-speakers volumio[20125]: SPOTIFY: VOLUMIO VOLUME 45 May 04 15:56:50 pawse-speakers volumio[20125]: SPOTIFY: DELTA VOLUME ENOUGH: true May 04 15:56:50 pawse-speakers volumio[20125]: info: Setting Spotify Volume from Volumio: 45 May 04 15:56:50 pawse-speakers volumio[20125]: verbose: New Socket.io Connection to 192.168.1.41 from 192.168.1.101 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.4 Safari/605.1.15 Engine version: 3 Transport: polling Total Clients: 5 May 04 15:56:50 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 04 15:56:50 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioGetVisibleSources May 04 15:56:50 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 15:56:50 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioGetState May 04 15:56:50 pawse-speakers volumio[20125]: info: CorePlayQueue::getTrack 0 May 04 15:56:50 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioGetState May 04 15:56:50 pawse-speakers volumio[20125]: info: CorePlayQueue::getTrack 0 May 04 15:56:50 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 04 15:56:50 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 04 15:56:50 pawse-speakers volumio[20125]: info: Received Get System Info May 04 15:56:50 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 04 15:56:50 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 04 15:56:50 pawse-speakers volumio[20125]: info: Discovery: Getting this device information May 04 15:56:50 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioGetState May 04 15:56:50 pawse-speakers volumio[20125]: info: CorePlayQueue::getTrack 0 May 04 15:56:50 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 04 15:56:50 pawse-speakers volumio[20125]: info: CoreCommandRouter::volumioGetState May 04 15:56:50 pawse-speakers volumio[20125]: info: CorePlayQueue::getTrack 0 May 04 15:56:50 pawse-speakers volumio[20125]: info: Listing playlists May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso May 04 15:56:50 pawse-speakers volumio[20125]: info: Adding plugin bluetooth to MyMusic Plugins May 04 15:56:50 pawse-speakers volumio[20125]: info: Adding plugin multiroom to MyMusic Plugins May 04 15:56:50 pawse-speakers volumio[20125]: info: Adding plugin metavolumio to MyMusic Plugins May 04 15:56:50 pawse-speakers volumio[20125]: info: Adding plugin cd_controller to MyMusic Plugins May 04 15:56:50 pawse-speakers volumio[20125]: info: Adding plugin smart_inputs to MyMusic Plugins May 04 15:56:50 pawse-speakers volumio[20125]: info: Adding plugin tidalconnect to MyMusic Plugins May 04 15:56:50 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... May 04 15:56:51 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded May 04 15:56:51 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio May 04 15:56:51 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:56:51 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:56:51 pawse-speakers volumio[20125]: info: Starting MyVolumio Remote Streaming Endpoints May 04 15:56:51 pawse-speakers volumio[20125]: info: MyVolumio login type: Token May 04 15:56:51 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started May 04 15:56:51 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... May 04 15:56:52 pawse-speakers volumio[20125]: info: Starting Streaming Service Transparent Proxy May 04 15:56:52 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded May 04 15:56:52 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services May 04 15:56:52 pawse-speakers volumio[20125]: info: Streaming services startup May 04 15:56:52 pawse-speakers volumio[20125]: info: Starting Streaming Daemon May 04 15:56:52 pawse-speakers sudo[20391]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 04 15:56:52 pawse-speakers sudo[20391]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:52 pawse-speakers sudo[20391]: pam_unix(sudo:session): session closed for user root May 04 15:56:52 pawse-speakers volumio[20125]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started May 04 15:56:52 pawse-speakers volumio[20125]: SPOTIFY: SETTING SPOTIFY VOLUME 45 May 04 15:56:52 pawse-speakers volumio[20125]: info: Sending Spotify command with payload to local API: /player/volume May 04 15:56:52 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:52-04:00" level=debug msg="update volume to 29490/65535" May 04 15:56:52 pawse-speakers volumio[20125]: error: Cannot start Volumio Streaming Daemon May 04 15:56:52 pawse-speakers volumio[20125]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 04 15:56:52 pawse-speakers volumio[20125]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 04 15:56:52 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:52-04:00" level=debug msg="put connect state because VOLUME_CHANGED" May 04 15:56:52 pawse-speakers go-librespot[20290]: time="2025-05-04T15:56:52-04:00" level=trace msg="emitting websocket event: volume" May 04 15:56:52 pawse-speakers volumio[20125]: SPOTIFY: received: {"type":"volume","data":{"value":45,"max":100}} May 04 15:56:52 pawse-speakers volumio[20125]: SPOTIFY: RECEIVED SPOTIFY VOLUME 45 May 04 15:56:53 pawse-speakers volumio[20125]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN May 04 15:56:53 pawse-speakers volumio[20125]: info: MyVolumio token set successfully May 04 15:56:53 pawse-speakers volumio[20125]: info: MYVOLUMIO: Adding device May 04 15:56:53 pawse-speakers volumio[20125]: info: MYVOLUMIO: Evaluating Server May 04 15:56:53 pawse-speakers volumio[20125]: STREAMING PROXY: Starting server on port 3245 May 04 15:56:53 pawse-speakers volumio[20125]: Node JS runtime: 14 May 04 15:56:53 pawse-speakers volumio[20125]: info: MyVolumio status changed May 04 15:56:53 pawse-speakers volumio[20125]: info: Streaming services startup May 04 15:56:53 pawse-speakers volumio[20125]: info: Starting Streaming Daemon May 04 15:56:53 pawse-speakers volumio[20125]: info: Removing browser output: myVolumio user plan is not superstar May 04 15:56:53 pawse-speakers volumio[20125]: info: Removing audio output: May 04 15:56:54 pawse-speakers volumio[20125]: info: Stoppping Tunnel 1 May 04 15:56:54 pawse-speakers sudo[20430]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 04 15:56:54 pawse-speakers sudo[20430]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:54 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:54 pawse-speakers sudo[20430]: pam_unix(sudo:session): session closed for user root May 04 15:56:54 pawse-speakers sudo[20433]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service May 04 15:56:54 pawse-speakers sudo[20433]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:56:54 pawse-speakers volumio[20125]: error: Cannot start Volumio Streaming Daemon May 04 15:56:54 pawse-speakers volumio[20125]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 04 15:56:54 pawse-speakers volumio[20125]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 04 15:56:54 pawse-speakers sudo[20433]: pam_unix(sudo:session): session closed for user root May 04 15:56:54 pawse-speakers volumio[20125]: info: Setting Geolocation for MyVolumio to us3 May 04 15:56:54 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:56:54 pawse-speakers volumio[20125]: info: Remote SSH Stopped May 04 15:56:55 pawse-speakers volumio[20125]: info: Cannot mount NAS at system boot, trial number 4 ,stopping May 04 15:56:55 pawse-speakers volumio[20125]: info: Updating MyVolumio device info May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:56:55 pawse-speakers volumio[20125]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} May 04 15:56:55 pawse-speakers volumio[20125]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:55 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumio[20125]: info: CoreCommandRouter::getUIConfigOnPlugin May 04 15:56:56 pawse-speakers volumiologrotate[519]: ls: cannot access '/var/log/samba/log.wb-PAWSE': No such file or directory May 04 15:56:56 pawse-speakers volumiologrotate[519]: ls: cannot access 'SPEAKERS': No such file or directory May 04 15:57:15 pawse-speakers volumio-remote-updater[542]: [2025-05-04 15:57:15] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] May 04 15:57:20 pawse-speakers volumio-remote-updater[542]: [2025-05-04 15:57:20] [connect] Successful connection May 04 15:57:25 pawse-speakers volumio[20125]: <--- Last few GCs ---> May 04 15:57:25 pawse-speakers volumio[20125]: [20125:0x43b0780] 53685 ms: Mark-sweep (reduce) 213.5 (219.4) -> 213.2 (219.6) MB, 678.2 / 0.1 ms (average mu = 0.121, current mu = 0.033) allocation failure scavenge might not succeed May 04 15:57:25 pawse-speakers volumio[20125]: [20125:0x43b0780] 54415 ms: Mark-sweep (reduce) 213.8 (218.1) -> 212.8 (218.5) MB, 708.0 / 0.1 ms (average mu = 0.076, current mu = 0.030) allocation failure scavenge might not succeed May 04 15:57:25 pawse-speakers volumio[20125]: <--- JS stacktrace ---> May 04 15:57:25 pawse-speakers volumio[20125]: FATAL ERROR: MarkCompactCollector: young object promotion failed Allocation failed - JavaScript heap out of memory May 04 15:57:25 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:25-04:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" May 04 15:57:25 pawse-speakers volumio-remote-updater[542]: [2025-05-04 15:57:25] [info] asio async_read_at_least error: system:104 (Connection reset by peer) May 04 15:57:25 pawse-speakers volumio-remote-updater[542]: [2025-05-04 15:57:25] [error] handle_read_http_response error: websocketpp.transport:2 (Underlying Transport Error) May 04 15:57:25 pawse-speakers volumio-remote-updater[542]: [2025-05-04 15:57:25] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) May 04 15:57:25 pawse-speakers systemd[1]: volumio.service: Main process exited, code=killed, status=6/ABRT May 04 15:57:25 pawse-speakers systemd[1]: volumio.service: Failed with result 'signal'. May 04 15:57:25 pawse-speakers systemd[1]: Started dynamicswap service. May 04 15:57:25 pawse-speakers systemd[1]: dynamicswap.service: Succeeded. May 04 15:57:25 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:25-04:00" level=debug msg="handling transfer player command from 1b9044c72d4884a90ae4df5effc7e183c17518f3" May 04 15:57:25 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:25-04:00" level=debug msg="resolved context of track" uri="spotify:playlist:482hSt5kSpiqzVZxtAfHDO" May 04 15:57:25 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:25-04:00" level=trace msg="fetched new page 0 with 54 items (list: 54)" uri="spotify:playlist:482hSt5kSpiqzVZxtAfHDO" May 04 15:57:25 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:25-04:00" level=debug msg="loading track (paused: false, position: 2949980ms)" uri="spotify:track:505T6oQpAfLJ2EQkkWuJ0u" May 04 15:57:25 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:25-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 15:57:25 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:25-04:00" level=trace msg="emitting websocket event: will_play" May 04 15:57:25 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:25-04:00" level=debug msg="selected format OGG_VORBIS_320 (4676fd13e6a8505e559542fc645ba86ddeddbf80)" uri="spotify:track:505T6oQpAfLJ2EQkkWuJ0u" May 04 15:57:25 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:25-04:00" level=debug msg="requested aes key for file 4676fd13e6a8505e559542fc645ba86ddeddbf80, gid: 505T6oQpAfLJ2EQkkWuJ0u" May 04 15:57:25 pawse-speakers systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. May 04 15:57:25 pawse-speakers systemd[1]: volumio.service: Scheduled restart job, restart counter is at 52. May 04 15:57:25 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:25-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1469" May 04 15:57:25 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:25-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" May 04 15:57:25 pawse-speakers systemd[1]: Started dynamicswap service. May 04 15:57:25 pawse-speakers systemd[1]: Stopped Volumio Backend Module. May 04 15:57:25 pawse-speakers systemd[1]: Started Volumio Backend Module. May 04 15:57:25 pawse-speakers systemd[1]: dynamicswap.service: Succeeded. May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=debug msg="fetched first chunk of 28, total size is 14445968 bytes" uri="spotify:track:505T6oQpAfLJ2EQkkWuJ0u" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=debug msg="fetched chunk 1/27, size: 524288" uri="spotify:track:505T6oQpAfLJ2EQkkWuJ0u" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=debug msg="fetched chunk 27/27, size: 290192" uri="spotify:track:505T6oQpAfLJ2EQkkWuJ0u" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=trace msg="seek to 340333ms (diff: 197ms, samples: 15008685, bytes: 14434980)" uri="spotify:track:505T6oQpAfLJ2EQkkWuJ0u" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=debug msg="fetched chunk 2/27, size: 524288" uri="spotify:track:505T6oQpAfLJ2EQkkWuJ0u" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=debug msg="created new output device" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=info msg="loaded track \"In the Margins\" (paused: false, position: 2949980ms, duration: 340333ms, prefetched: false)" uri="spotify:track:505T6oQpAfLJ2EQkkWuJ0u" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=debug msg="fetched chunk 3/27, size: 524288" uri="spotify:track:505T6oQpAfLJ2EQkkWuJ0u" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=trace msg="cleared closed output device" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=trace msg="scheduling prefetch in 310s" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=trace msg="emitting websocket event: metadata" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=trace msg="emitting websocket event: active" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=debug msg="sending successful reply for dealer request" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=trace msg="emitting websocket event: playing" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=trace msg="emitting websocket event: not_playing" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:4fTD07LyxE3MMFWN6nNyrd" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=trace msg="emitting websocket event: will_play" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=debug msg="selected format OGG_VORBIS_320 (a008e504f242190cab85b7f03e0467905d8df60e)" uri="spotify:track:4fTD07LyxE3MMFWN6nNyrd" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=debug msg="requested aes key for file a008e504f242190cab85b7f03e0467905d8df60e, gid: 4fTD07LyxE3MMFWN6nNyrd" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=debug msg="fetched first chunk of 23, total size is 11917056 bytes" uri="spotify:track:4fTD07LyxE3MMFWN6nNyrd" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:4fTD07LyxE3MMFWN6nNyrd" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=debug msg="created new output device" May 04 15:57:26 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:26-04:00" level=info msg="loaded track \"What It Is Is\" (paused: false, position: 1ms, duration: 273857ms, prefetched: false)" uri="spotify:track:4fTD07LyxE3MMFWN6nNyrd" May 04 15:57:27 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:27-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 15:57:27 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:27-04:00" level=debug msg="fetched chunk 1/22, size: 524288" uri="spotify:track:4fTD07LyxE3MMFWN6nNyrd" May 04 15:57:27 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:27-04:00" level=debug msg="fetched chunk 2/22, size: 524288" uri="spotify:track:4fTD07LyxE3MMFWN6nNyrd" May 04 15:57:27 pawse-speakers go-librespot[20290]: time="2025-05-04T15:57:27-04:00" level=debug msg="fetched chunk 3/22, size: 524288" uri="spotify:track:4fTD07LyxE3MMFWN6nNyrd" May 04 15:57:27 pawse-speakers volumio[20533]: info: ------------------------------------------- May 04 15:57:27 pawse-speakers volumio[20533]: info: ----- Volumio3 ---- May 04 15:57:27 pawse-speakers volumio[20533]: info: ------------------------------------------- May 04 15:57:27 pawse-speakers volumio[20533]: info: ----- System startup ---- May 04 15:57:27 pawse-speakers volumio[20533]: info: ------------------------------------------- May 04 15:57:28 pawse-speakers volumio[20533]: info: MYVOLUMIO Environment detected May 04 15:57:28 pawse-speakers volumio[20533]: info: Plugin folders cleanup May 04 15:57:28 pawse-speakers volumio[20533]: info: Scanning into folder /volumio/app/plugins/ May 04 15:57:28 pawse-speakers volumio[20533]: info: Scanning category audio_interface May 04 15:57:28 pawse-speakers volumio[20533]: info: Scanning category miscellanea May 04 15:57:28 pawse-speakers volumio[20533]: info: Scanning category music_service May 04 15:57:28 pawse-speakers volumio[20533]: info: Scanning category plugins.json May 04 15:57:28 pawse-speakers volumio[20533]: info: Scanning category system_controller May 04 15:57:28 pawse-speakers volumio[20533]: info: Scanning category user_interface May 04 15:57:28 pawse-speakers volumio[20533]: info: Scanning into folder /data/plugins/ May 04 15:57:28 pawse-speakers volumio[20533]: info: Scanning category audio_interface May 04 15:57:28 pawse-speakers volumio[20533]: info: Scanning category music_service May 04 15:57:28 pawse-speakers volumio[20533]: info: Scanning category user_interface May 04 15:57:28 pawse-speakers volumio[20533]: info: Plugin folders cleanup completed May 04 15:57:28 pawse-speakers volumio[20533]: info: ------------------------------------------- May 04 15:57:28 pawse-speakers volumio[20533]: info: ----- Core plugins startup ---- May 04 15:57:28 pawse-speakers volumio[20533]: info: ------------------------------------------- May 04 15:57:28 pawse-speakers volumio[20533]: info: Loading plugins from folder /volumio/app/plugins/ May 04 15:57:28 pawse-speakers volumio[20533]: info: Adding plugin upnp to MyMusic Plugins May 04 15:57:28 pawse-speakers volumio[20533]: info: Adding plugin airplay_emulation to MyMusic Plugins May 04 15:57:28 pawse-speakers volumio[20533]: info: Adding plugin upnp_browser to MyMusic Plugins May 04 15:57:28 pawse-speakers volumio[20533]: info: Loading plugins from folder /data/plugins/ May 04 15:57:28 pawse-speakers volumio[20533]: info: Loading plugin "system"... May 04 15:57:28 pawse-speakers volumio[20533]: info: Loading plugin "appearance"... May 04 15:57:29 pawse-speakers volumio[20533]: info: Loading plugin "network"... May 04 15:57:29 pawse-speakers volumio[20533]: info: Refreshing Cached IP Addresses May 04 15:57:29 pawse-speakers sudo[20561]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 04 15:57:29 pawse-speakers sudo[20561]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:29 pawse-speakers sudo[20561]: pam_unix(sudo:session): session closed for user root May 04 15:57:29 pawse-speakers sudo[20563]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 04 15:57:29 pawse-speakers volumio[20533]: info: Loading plugin "services"... May 04 15:57:29 pawse-speakers sudo[20563]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:29 pawse-speakers volumio[20533]: info: Loading plugin "alsa_controller"... May 04 15:57:29 pawse-speakers sudo[20563]: pam_unix(sudo:session): session closed for user root May 04 15:57:29 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 04 15:57:29 pawse-speakers volumio[20533]: info: Loading plugin "wizard"... May 04 15:57:29 pawse-speakers volumio[20533]: info: Loading plugin "networkfs"... May 04 15:57:29 pawse-speakers volumio[20533]: info: Cannot mount NAS Server at system boot, trial number 1 ,retrying in 5 seconds May 04 15:57:29 pawse-speakers volumio[20533]: info: Starting Udev Watcher for removable devices May 04 15:57:29 pawse-speakers volumio[20533]: info: Ignoring mount for partition: boot May 04 15:57:29 pawse-speakers volumio[20533]: info: Ignoring mount for partition: volumio May 04 15:57:29 pawse-speakers volumio[20533]: info: Ignoring mount for partition: volumio_data May 04 15:57:29 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 04 15:57:29 pawse-speakers volumio[20533]: info: Loading plugin "volumio_command_line_client"... May 04 15:57:29 pawse-speakers volumio[20533]: info: Loading plugin "upnp"... May 04 15:57:29 pawse-speakers volumio[20533]: info: [1746388649762] Starting Upmpd Daemon May 04 15:57:29 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 04 15:57:29 pawse-speakers volumio[20533]: info: Loading plugin "my_music"... May 04 15:57:29 pawse-speakers volumio[20533]: info: Loading plugin "mpd"... May 04 15:57:30 pawse-speakers volumio[20533]: info: Loading plugin "upnp_browser"... May 04 15:57:30 pawse-speakers volumio[20533]: info: Loading plugin "alarm-clock"... May 04 15:57:30 pawse-speakers volumio[20533]: info: Loading plugin "airplay_emulation"... May 04 15:57:30 pawse-speakers volumio[20533]: info: Starting Shairport Sync May 04 15:57:30 pawse-speakers volumio[20533]: info: Loading plugin "last_100"... May 04 15:57:30 pawse-speakers volumio[20533]: info: Loading plugin "webradio"... May 04 15:57:30 pawse-speakers volumio[20533]: info: Loading plugin "i2s_dacs"... May 04 15:57:30 pawse-speakers volumio[20533]: info: Loading plugin "volumiodiscovery"... May 04 15:57:30 pawse-speakers volumio[20533]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 04 15:57:30 pawse-speakers volumio[20533]: *** WARNING *** Please fix your application to use the native API of Avahi! May 04 15:57:30 pawse-speakers volumio[20533]: *** WARNING *** For more information see May 04 15:57:30 pawse-speakers node[20533]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 04 15:57:30 pawse-speakers volumio[20533]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 04 15:57:30 pawse-speakers volumio[20533]: *** WARNING *** Please fix your application to use the native API of Avahi! May 04 15:57:30 pawse-speakers volumio[20533]: *** WARNING *** For more information see May 04 15:57:30 pawse-speakers node[20533]: *** WARNING *** Please fix your application to use the native API of Avahi! May 04 15:57:30 pawse-speakers node[20533]: *** WARNING *** For more information see May 04 15:57:30 pawse-speakers node[20533]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 04 15:57:30 pawse-speakers node[20533]: *** WARNING *** Please fix your application to use the native API of Avahi! May 04 15:57:30 pawse-speakers node[20533]: *** WARNING *** For more information see May 04 15:57:30 pawse-speakers volumio[20533]: info: Applying required configuration parameters for plugin volumiodiscovery May 04 15:57:30 pawse-speakers volumio[20533]: info: Discovery: Started advertising with name: Pawse Speakers May 04 15:57:30 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 04 15:57:30 pawse-speakers volumio[20533]: info: Loading plugin "spop"... May 04 15:57:31 pawse-speakers volumio[20533]: info: Loading plugin "outputs"... May 04 15:57:31 pawse-speakers volumio[20533]: info: Loading plugin "albumart"... May 04 15:57:31 pawse-speakers volumio[20533]: info: Plugin example_plugin is not enabled May 04 15:57:31 pawse-speakers volumio[20533]: info: Loading plugin "inputs"... May 04 15:57:31 pawse-speakers volumio[20533]: info: Loading plugin "updater_comm"... May 04 15:57:32 pawse-speakers volumio[20533]: info: Plugin mpdemulation is not enabled May 04 15:57:32 pawse-speakers volumio[20533]: info: Loading plugin "rest_api"... May 04 15:57:32 pawse-speakers volumio[20533]: info: Loading plugin "websocket"... May 04 15:57:32 pawse-speakers volumio[20533]: info: Starting Socket.io Server version 2.3.0 May 04 15:57:32 pawse-speakers volumio[20533]: info: Loading plugin "fusiondsp"... May 04 15:57:32 pawse-speakers volumio[20533]: Forking 3 albumart workers May 04 15:57:32 pawse-speakers volumio[20533]: info: Applying required configuration parameters for plugin fusiondsp May 04 15:57:32 pawse-speakers volumio[20533]: info: Loading plugin "Systeminfo"... May 04 15:57:32 pawse-speakers volumio-remote-updater[542]: [2025-05-04 15:57:32] [connect] Successful connection May 04 15:57:33 pawse-speakers volumio[20533]: info: Loading i18n strings for locale en May 04 15:57:33 pawse-speakers volumio[20533]: Updating browse sources language May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::initPlayerControls May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 04 15:57:33 pawse-speakers volumio[20533]: Express server listening on port 3000 May 04 15:57:33 pawse-speakers volumio[20533]: [Metrics] WebUI: 6s 320.35ms May 04 15:57:33 pawse-speakers volumio[20533]: Starting albumart workers May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreStateMachine::resetVolumioState May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreStateMachine::getcurrentVolume May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::volumioRetrievevolume May 04 15:57:33 pawse-speakers volumio[20533]: Starting albumart workers May 04 15:57:33 pawse-speakers volumio[20533]: Starting albumart workers May 04 15:57:33 pawse-speakers volumio[20533]: info: Volumio Network Manager: Network status updated: 1 May 04 15:57:33 pawse-speakers volumio-remote-updater[542]: [2025-05-04 15:57:33] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1746388652 101 May 04 15:57:33 pawse-speakers volumio[20533]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:57:33 pawse-speakers volumio[20533]: info: Reloading queue from file May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreStateMachine::setRepeat null single undefined May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreStateMachine::pushState May 04 15:57:33 pawse-speakers volumio[20533]: info: CorePlayQueue::getTrack 0 May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::volumioPushState May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreStateMachine::setRandom true May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreStateMachine::pushState May 04 15:57:33 pawse-speakers volumio[20533]: info: CorePlayQueue::getTrack 0 May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::volumioPushState May 04 15:57:33 pawse-speakers volumio[20533]: info: Setting Device type: Raspberry PI May 04 15:57:33 pawse-speakers volumio[20533]: info: Completed loading Core Plugins May 04 15:57:33 pawse-speakers volumio[20533]: info: Preparing to generate the ALSA configuration file May 04 15:57:33 pawse-speakers volumio[20533]: info: VolumeController:: Volume=45 Mute =false May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreStateMachine::pushState May 04 15:57:33 pawse-speakers volumio[20533]: info: CorePlayQueue::getTrack 0 May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::volumioPushState May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreStateMachine::updateTrackBlock May 04 15:57:33 pawse-speakers volumio[20533]: info: CorePlayQueue::getTrackBlock May 04 15:57:33 pawse-speakers volumio[20533]: info: CoreCommandRouter::volumioRetrievevolume May 04 15:57:34 pawse-speakers volumio[20533]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 04 15:57:34 pawse-speakers volumio[20533]: info: Reading ALSA contributions from plugins. May 04 15:57:34 pawse-speakers volumio[20533]: info: Discovery: adding 93e32e89-0306-43bc-b876-efb00cb7ebbb May 04 15:57:34 pawse-speakers volumio[20533]: info: Discovery: Found device Pawse Speakers May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::volumioGetState May 04 15:57:34 pawse-speakers volumio[20533]: info: CorePlayQueue::getTrack 0 May 04 15:57:34 pawse-speakers volumio[20533]: info: Asound.conf file unchanged, so no further update is needed May 04 15:57:34 pawse-speakers volumio[20533]: info: Output device has changed, restarting MPD May 04 15:57:34 pawse-speakers sudo[20640]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 04 15:57:34 pawse-speakers sudo[20640]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:34 pawse-speakers volumio[20533]: info: Output device has changed, restarting Shairport Sync May 04 15:57:34 pawse-speakers sudo[20640]: pam_unix(sudo:session): session closed for user root May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:57:34 pawse-speakers sudo[20644]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 04 15:57:34 pawse-speakers sudo[20644]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:34 pawse-speakers systemd[1]: Stopping Music Player Daemon... May 04 15:57:34 pawse-speakers volumio[20533]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 04 15:57:34 pawse-speakers volumio[20533]: info: ___________ START PLUGINS ___________ May 04 15:57:34 pawse-speakers volumio[20533]: info: ControllerMpd::onStart: Initializing MPD May 04 15:57:34 pawse-speakers volumio[20533]: info: Creating MPD Configuration file May 04 15:57:34 pawse-speakers systemd[1]: mpd.service: Succeeded. May 04 15:57:34 pawse-speakers systemd[1]: Stopped Music Player Daemon. May 04 15:57:34 pawse-speakers sudo[20662]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 04 15:57:34 pawse-speakers sudo[20662]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 15:57:34 pawse-speakers volumio[20533]: info: [1746388654432] CoreMusicLibrary::Adding element Media Servers May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 15:57:34 pawse-speakers systemd[1]: Starting Music Player Daemon... May 04 15:57:34 pawse-speakers sudo[20662]: pam_unix(sudo:session): session closed for user root May 04 15:57:34 pawse-speakers sudo[20664]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 04 15:57:34 pawse-speakers sudo[20664]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:57:34 pawse-speakers systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM May 04 15:57:34 pawse-speakers systemd[1]: mpd.service: Succeeded. May 04 15:57:34 pawse-speakers systemd[1]: Stopped Music Player Daemon. May 04 15:57:34 pawse-speakers systemd[1]: Starting Music Player Daemon... May 04 15:57:34 pawse-speakers volumio[20533]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:57:34 pawse-speakers volumio[20533]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 15:57:34 pawse-speakers volumio[20533]: info: [1746388654577] CoreMusicLibrary::Adding element Last_100 May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 15:57:34 pawse-speakers volumio[20533]: info: [1746388654581] CoreMusicLibrary::Adding element Webradio May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 04 15:57:34 pawse-speakers volumio[20533]: info: Initializing BBC Radios May 04 15:57:34 pawse-speakers sudo[20670]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 04 15:57:34 pawse-speakers sudo[20670]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:34 pawse-speakers sudo[20670]: pam_unix(sudo:session): session closed for user root May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:57:34 pawse-speakers volumio[20533]: info: Creating Spotify config file May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:34 pawse-speakers volumio[20533]: info: Loading i18n strings for locale en May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 04 15:57:34 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:34 pawse-speakers volumio[20533]: info: FusionDsp - mixtype--------------------- Hardware May 04 15:57:34 pawse-speakers volumio[20533]: info: Volumio Calling Home May 04 15:57:34 pawse-speakers volumio[20533]: info: Preparing to generate the ALSA configuration file May 04 15:57:34 pawse-speakers volumio[20533]: info: Cannot mount NAS Server at system boot, trial number 2 ,retrying in 5 seconds May 04 15:57:34 pawse-speakers volumio[20533]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf May 04 15:57:34 pawse-speakers volumio[20533]: info: Reading ALSA contributions from plugins. May 04 15:57:34 pawse-speakers volumio[20533]: info: MPD Permissions set May 04 15:57:35 pawse-speakers volumio[20533]: info: MPD Permissions set May 04 15:57:35 pawse-speakers volumio[20533]: info: VolumeController:: Volume=45 Mute =false May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreStateMachine::pushState May 04 15:57:35 pawse-speakers volumio[20533]: info: CorePlayQueue::getTrack 0 May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::volumioPushState May 04 15:57:35 pawse-speakers volumio[20533]: info: Spotify config file written May 04 15:57:35 pawse-speakers sudo[20691]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 04 15:57:35 pawse-speakers sudo[20691]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:35 pawse-speakers volumio[20533]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:35 pawse-speakers systemd[1]: Stopping go-librespot Daemon... May 04 15:57:35 pawse-speakers systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM May 04 15:57:35 pawse-speakers systemd[1]: go-librespot-daemon.service: Succeeded. May 04 15:57:35 pawse-speakers systemd[1]: Stopped go-librespot Daemon. May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:35 pawse-speakers systemd[1]: Started go-librespot Daemon. May 04 15:57:35 pawse-speakers go-librespot[20697]: Librespot-go daemon starting... May 04 15:57:35 pawse-speakers sudo[20691]: pam_unix(sudo:session): session closed for user root May 04 15:57:35 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:35-04:00" level=info msg="generated new device id: 60637bf4eff2c7bcc7cadc27fb6ba1093736db77" May 04 15:57:35 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:35-04:00" level=debug msg="stored credentials found for 21bhtp2smvadava6jxb4tv7ti" May 04 15:57:35 pawse-speakers volumio[20533]: info: Volumio called home May 04 15:57:35 pawse-speakers volumio[20533]: info: Starting Shairport Sync May 04 15:57:35 pawse-speakers volumio[20533]: info: Starting Shairport Sync May 04 15:57:35 pawse-speakers sudo[20711]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 04 15:57:35 pawse-speakers volumio[20533]: info: Starting Shairport Sync May 04 15:57:35 pawse-speakers sudo[20711]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:35 pawse-speakers sudo[20713]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 04 15:57:35 pawse-speakers systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 04 15:57:35 pawse-speakers sudo[20713]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::volumioGetState May 04 15:57:35 pawse-speakers volumio[20533]: info: CorePlayQueue::getTrack 0 May 04 15:57:35 pawse-speakers systemd[1]: shairport-sync.service: Succeeded. May 04 15:57:35 pawse-speakers systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 04 15:57:35 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:35-04:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" May 04 15:57:35 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:35-04:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" May 04 15:57:35 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:35-04:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" May 04 15:57:35 pawse-speakers sudo[20716]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 04 15:57:35 pawse-speakers sudo[20716]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:35 pawse-speakers volumio[20533]: info: Asound.conf file unchanged, so no further update is needed May 04 15:57:35 pawse-speakers volumio[20533]: info: Output device has changed, restarting MPD May 04 15:57:35 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:35-04:00" level=debug msg="zeroconf server listening on port 41933" May 04 15:57:35 pawse-speakers systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 04 15:57:35 pawse-speakers sudo[20711]: pam_unix(sudo:session): session closed for user root May 04 15:57:35 pawse-speakers volumio[20533]: info: Output device has changed, restarting Shairport Sync May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:35 pawse-speakers systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:57:35 pawse-speakers systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 04 15:57:35 pawse-speakers systemd[1]: shairport-sync.service: Succeeded. May 04 15:57:35 pawse-speakers systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 04 15:57:35 pawse-speakers sudo[20721]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 04 15:57:35 pawse-speakers sudo[20721]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:35 pawse-speakers systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 04 15:57:35 pawse-speakers sudo[20713]: pam_unix(sudo:session): session closed for user root May 04 15:57:35 pawse-speakers sudo[20723]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 04 15:57:35 pawse-speakers sudo[20723]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:35 pawse-speakers sudo[20721]: pam_unix(sudo:session): session closed for user root May 04 15:57:35 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:35-04:00" level=debug msg="obtained new client token: AAC+wvaXR28hkPtMBm+NdJx9ENWlPs8WWV1Fn9KLIDHmxx5gKn7Cu2khva0PitDwMHdahzroIGy4OOD+iTSsYhW6VaRonv+pCmmu/f+1zXN+RPPAIRL3ClxHvMwOrdQV5jFfAo2GSC7UIUW0Ce/Ar0z8DyY5VqiN1g78B2at3lYsiutHVcigQsrQz0Xb7HL1ryF5aEs7mRnmiFzsLlP/x4oFNZl3vV9sngI3ayC6BhJrGcEr3+77HDG5uqs=" May 04 15:57:35 pawse-speakers sudo[20716]: pam_unix(sudo:session): session closed for user root May 04 15:57:35 pawse-speakers volumio[20533]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 04 15:57:35 pawse-speakers systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 04 15:57:35 pawse-speakers systemd[1]: mpd.service: Succeeded. May 04 15:57:35 pawse-speakers systemd[1]: Stopped Music Player Daemon. May 04 15:57:35 pawse-speakers volumio[20533]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 04 15:57:35 pawse-speakers volumio[20533]: SPOTIFY: BQDW8AhgXBXfHzv4LGIJEHrZNwU8WfcEZLI9We6vM5XAdL0q7LMncUSFhvFgITj3CKMMMjSNeVL3enblrD_hzZ-mSRfCkoQuE1m8vzdXmpyr0yna2YT9YM43yuZlJAzFod49bac1EtJNyfSc0pRE0DzixCVPYePtJxEUQL-A7zJBCcDB_UgyjUUzaKS4QC7CL63dA1BoAZQs5n1Kc5KPTfJT1KhqILNyHwfUSwP_PqB-pNWcCwDddaGOKYkJHBIZ_yUhyWmMsYzx4wY3-4dhhNe6FxSuK1LT0xrmw8ZPMZnBKEg May 04 15:57:35 pawse-speakers volumio[20533]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 04 15:57:35 pawse-speakers volumio[20533]: info: New Spotify access token = BQDW8AhgXBXfHzv4LGIJEHrZNwU8WfcEZLI9We6vM5XAdL0q7LMncUSFhvFgITj3CKMMMjSNeVL3enblrD_hzZ-mSRfCkoQuE1m8vzdXmpyr0yna2YT9YM43yuZlJAzFod49bac1EtJNyfSc0pRE0DzixCVPYePtJxEUQL-A7zJBCcDB_UgyjUUzaKS4QC7CL63dA1BoAZQs5n1Kc5KPTfJT1KhqILNyHwfUSwP_PqB-pNWcCwDddaGOKYkJHBIZ_yUhyWmMsYzx4wY3-4dhhNe6FxSuK1LT0xrmw8ZPMZnBKEg May 04 15:57:35 pawse-speakers volumio[20533]: info: Spotify credentials grant success - running version from March 24, 2019 May 04 15:57:35 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:35-04:00" level=debug msg="completed keyexchange" May 04 15:57:35 pawse-speakers volumio[20533]: info: MPD Permissions set May 04 15:57:35 pawse-speakers volumio[20533]: info: Shairport-Sync Started May 04 15:57:35 pawse-speakers volumio[20533]: Error adding Membership: Error: addMembership EINVAL May 04 15:57:35 pawse-speakers volumio[20533]: info: Shairport-Sync Started May 04 15:57:35 pawse-speakers volumio[20533]: info: Shairport-Sync Started May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:35 pawse-speakers systemd[1]: Starting Music Player Daemon... May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 15:57:35 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:35 pawse-speakers volumio[20533]: info: Starting Shairport Sync May 04 15:57:35 pawse-speakers sudo[20741]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 04 15:57:35 pawse-speakers sudo[20741]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:35 pawse-speakers systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 04 15:57:35 pawse-speakers systemd[1]: shairport-sync.service: Succeeded. May 04 15:57:35 pawse-speakers systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 04 15:57:35 pawse-speakers systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 04 15:57:35 pawse-speakers sudo[20741]: pam_unix(sudo:session): session closed for user root May 04 15:57:35 pawse-speakers sudo[20731]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 04 15:57:35 pawse-speakers sudo[20731]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:35 pawse-speakers sudo[20731]: pam_unix(sudo:session): session closed for user root May 04 15:57:36 pawse-speakers volumio[20533]: info: Shairport-Sync Started May 04 15:57:36 pawse-speakers volumio[20533]: SPOTIFY: User informations: {"country":"CA","display_name":"Paul Goodship","email":"itsme16688@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/21bhtp2smvadava6jxb4tv7ti"},"followers":{"href":null,"total":19},"href":"https://api.spotify.com/v1/users/21bhtp2smvadava6jxb4tv7ti","id":"21bhtp2smvadava6jxb4tv7ti","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=10152364741440856&height=300&width=300&ext=1748954433&hash=AbbQ6gNcuvaDcOW2jcpTQkvq","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=10152364741440856&height=50&width=50&ext=1748954433&hash=AbZHo20tk5vS50abgqpzoDUg","width":64}],"product":"premium","type":"user","uri":"spotify:user:21bhtp2smvadava6jxb4tv7ti"} May 04 15:57:36 pawse-speakers volumio[20533]: info: Spotify Successfully logged in May 04 15:57:36 pawse-speakers volumio[20533]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 15:57:36 pawse-speakers volumio[20533]: info: [1746388656037] CoreMusicLibrary::Adding element Spotify May 04 15:57:36 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 15:57:36 pawse-speakers volumio[20533]: Cannot find translation for source Spotify May 04 15:57:36 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:36-04:00" level=debug msg="completed challenge" May 04 15:57:36 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:36-04:00" level=debug msg="authenticated as 21bhtp2smvadava6jxb4tv7ti" May 04 15:57:36 pawse-speakers volumio[20533]: info: CoreCommandRouter::volumioGetState May 04 15:57:36 pawse-speakers volumio[20533]: info: CorePlayQueue::getTrack 0 May 04 15:57:36 pawse-speakers volumio[20533]: info: Listing playlists May 04 15:57:36 pawse-speakers volumio[20533]: info: Listing playlists May 04 15:57:36 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:36-04:00" level=debug msg="authenticated as 21bhtp2smvadava6jxb4tv7ti" May 04 15:57:36 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:36-04:00" level=debug msg="dealer connection opened" May 04 15:57:36 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:36-04:00" level=debug msg="initializing zeroconf session, username: 21bhtp2smvadava6jxb4tv7ti" May 04 15:57:36 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:36-04:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 04 15:57:36 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:36-04:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 04 15:57:36 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:36-04:00" level=debug msg="autoplay enabled: false" May 04 15:57:36 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:36-04:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 04 15:57:36 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:36-04:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 04 15:57:36 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:36-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 04 15:57:36 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:36-04:00" level=debug msg="received connection id: MmI3MTczNTItYjcyYS00N2ZjLWExYjAtMmUxMDAxNzI2NjVhK2RlYWxlcit0Y3A6Ly8wYWNiZjliZC5pcC5ndWUxLnNwb3RpZnkubmV0OjU3MDArMDQxQ0M2NTZFQ0Q2NjlGMDAyMEJCODNEMzA2OUE1NTU4NDZBMzZCRDY3NDhDREZDM0Y5NjI1RjIzRTNCRDBDRA==" May 04 15:57:36 pawse-speakers volumio[20533]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists May 04 15:57:36 pawse-speakers volumio[20533]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo May 04 15:57:36 pawse-speakers volumio[20533]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists May 04 15:57:36 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:36-04:00" level=debug msg="put connect state because NEW_DEVICE" May 04 15:57:36 pawse-speakers volumio[20533]: info: camilladsp spawned new process with pid 20754, instance 1, run: true May 04 15:57:36 pawse-speakers volumio[20533]: info: camilladsp service started and running in background, instance 1 May 04 15:57:36 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 15:57:36 pawse-speakers volumio[20533]: cannot open device 'volumioHw': Device or resource busy May 04 15:57:36 pawse-speakers volumio[20533]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json May 04 15:57:36 pawse-speakers volumio[20533]: cannot open device 'volumioHw': Device or resource busy May 04 15:57:36 pawse-speakers volumio[20533]: info: FusionDsp loaded May 04 15:57:36 pawse-speakers volumio[20533]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 04 15:57:36 pawse-speakers sudo[20764]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service May 04 15:57:36 pawse-speakers sudo[20764]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:36 pawse-speakers volumio[20533]: info: FusionDsp - Reporting Fusion DSP Enabled May 04 15:57:36 pawse-speakers volumio[20533]: info: Adding Signal Path Element [object Object] May 04 15:57:36 pawse-speakers volumio[20533]: info: Adding fusiondspeq DSP Signal Path Element May 04 15:57:36 pawse-speakers volumio[20533]: info: FusionDsp - ---- installed callbackRead May 04 15:57:36 pawse-speakers volumio[20533]: info: FusionDsp - If filter freq >samplerate/2 then disable it May 04 15:57:36 pawse-speakers sudo[20764]: pam_unix(sudo:session): session closed for user root May 04 15:57:36 pawse-speakers volumio[20533]: info: FusionDsp - Loudness is ON true May 04 15:57:37 pawse-speakers volumio[20533]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 May 04 15:57:37 pawse-speakers volumio[20533]: info: FusionDsp - {"Reload":{"result":"Ok"}} May 04 15:57:37 pawse-speakers mpd[20745]: May 04 15:57 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 04 15:57:37 pawse-speakers systemd[1]: Started Music Player Daemon. May 04 15:57:37 pawse-speakers sudo[20644]: pam_unix(sudo:session): session closed for user root May 04 15:57:37 pawse-speakers sudo[20664]: pam_unix(sudo:session): session closed for user root May 04 15:57:37 pawse-speakers sudo[20723]: pam_unix(sudo:session): session closed for user root May 04 15:57:37 pawse-speakers volumio[20533]: info: Completed starting Core Plugins May 04 15:57:37 pawse-speakers volumio[20533]: info: ------------------------------------------- May 04 15:57:37 pawse-speakers volumio[20533]: info: ----- MyVolumio plugins startup ---- May 04 15:57:37 pawse-speakers volumio[20533]: info: ------------------------------------------- May 04 15:57:37 pawse-speakers volumio[20533]: info: [MyVolumio PluginManager] Fetching plans data.... May 04 15:57:38 pawse-speakers volumio[20533]: error: MPD error: The expression evaluated to a falsy value: May 04 15:57:38 pawse-speakers volumio[20533]: assert.ok(self.idling) May 04 15:57:38 pawse-speakers volumio[20533]: error: The expression evaluated to a falsy value: May 04 15:57:38 pawse-speakers volumio[20533]: assert.ok(self.idling) May 04 15:57:38 pawse-speakers volumio[20533]: error: MPD error: The expression evaluated to a falsy value: May 04 15:57:38 pawse-speakers volumio[20533]: assert.ok(self.idling) May 04 15:57:38 pawse-speakers volumio[20533]: error: The expression evaluated to a falsy value: May 04 15:57:38 pawse-speakers volumio[20533]: assert.ok(self.idling) May 04 15:57:38 pawse-speakers volumio[20533]: info: MPD running with PID20745 May 04 15:57:38 pawse-speakers volumio[20533]: ,establishing connection May 04 15:57:38 pawse-speakers volumio[20533]: error: updateQueue error: null May 04 15:57:38 pawse-speakers volumio[20533]: error: updateQueue error: null May 04 15:57:38 pawse-speakers volumio[20533]: info: go-librespot daemon successfully initialized May 04 15:57:39 pawse-speakers sudo[20789]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 04 15:57:39 pawse-speakers sudo[20789]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:39 pawse-speakers sudo[20789]: pam_unix(sudo:session): session closed for user root May 04 15:57:39 pawse-speakers sudo[20791]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 04 15:57:39 pawse-speakers sudo[20791]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:39 pawse-speakers sudo[20791]: pam_unix(sudo:session): session closed for user root May 04 15:57:39 pawse-speakers sudo[20794]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 04 15:57:39 pawse-speakers sudo[20794]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 15:57:39 pawse-speakers sudo[20794]: pam_unix(sudo:session): session closed for user root May 04 15:57:39 pawse-speakers volumio[20533]: info: Upmpdcli Daemon Started May 04 15:57:39 pawse-speakers volumio[20533]: info: Cannot mount NAS Server at system boot, trial number 3 ,retrying in 5 seconds May 04 15:57:40 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:40-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 04 15:57:40 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:40-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 347" May 04 15:57:40 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:40-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 04 15:57:40 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:40-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2107" May 04 15:57:41 pawse-speakers volumio[20533]: info: Initializing connection to go-librespot Websocket May 04 15:57:41 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:41-04:00" level=debug msg="new websocket client" May 04 15:57:41 pawse-speakers volumio[20533]: info: Connection to go-librespot Websocket established May 04 15:57:43 pawse-speakers volumio[20533]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory May 04 15:57:44 pawse-speakers volumio[20533]: info: Getting Spotify volume May 04 15:57:44 pawse-speakers volumio[20533]: info: Spotify volume: 100 May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="handling transfer player command from 1b9044c72d4884a90ae4df5effc7e183c17518f3" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZF1EIdNTvkcjcOzJ" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:playlist:37i9dQZF1EIdNTvkcjcOzJ" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="loading track (paused: false, position: 6498ms)" uri="spotify:track:4I59UjiR1vDGGdLmdvFoJO" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=trace msg="emitting websocket event: will_play" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="selected format OGG_VORBIS_320 (67471318aa006026379060b2683bb6eddb8ad0c2)" uri="spotify:track:4I59UjiR1vDGGdLmdvFoJO" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="requested aes key for file 67471318aa006026379060b2683bb6eddb8ad0c2, gid: 4I59UjiR1vDGGdLmdvFoJO" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2039" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1469" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="fetched first chunk of 19, total size is 9553540 bytes" uri="spotify:track:4I59UjiR1vDGGdLmdvFoJO" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=trace msg="seek to 6498ms (diff: 106ms, samples: 286561, bytes: 224983)" uri="spotify:track:4I59UjiR1vDGGdLmdvFoJO" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="created new output device" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=info msg="loaded track \"August 10\" (paused: false, position: 6498ms, duration: 265410ms, prefetched: false)" uri="spotify:track:4I59UjiR1vDGGdLmdvFoJO" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=trace msg="scheduling prefetch in 228s" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=trace msg="emitting websocket event: metadata" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=trace msg="emitting websocket event: active" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="sending successful reply for dealer request" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:4I59UjiR1vDGGdLmdvFoJO" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:4I59UjiR1vDGGdLmdvFoJO" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=trace msg="emitting websocket event: playing" May 04 15:57:45 pawse-speakers go-librespot[20697]: time="2025-05-04T15:57:45-04:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:4I59UjiR1vDGGdLmdvFoJO" May 04 15:57:46 pawse-speakers volumio[20533]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 May 04 15:57:46 pawse-speakers volumio[20533]: info: Cannot mount NAS Server at system boot, trial number 4 ,retrying in 5 seconds May 04 15:57:46 pawse-speakers volumio[20533]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4I59UjiR1vDGGdLmdvFoJO","play_origin":"home"}} May 04 15:57:46 pawse-speakers volumio[20533]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4I59UjiR1vDGGdLmdvFoJO","name":"August 10","artist_names":["Khruangbin"],"album_name":"Con Todo El Mundo","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02bcee8e2aa4ded86f18661153","position":6498,"duration":265410,"release_date":"year:2018 month:1 day:26","track_number":4,"disc_number":1}} May 04 15:57:46 pawse-speakers volumio[20533]: SPOTIFY: received: {"type":"active","data":null} May 04 15:57:46 pawse-speakers volumio[20533]: info: Aligning Spotify Volume to Volumio Volume May 04 15:57:46 pawse-speakers volumio[20533]: info: CoreCommandRouter::volumioGetState May 04 15:57:46 pawse-speakers volumio[20533]: info: CorePlayQueue::getTrack 0 May 04 15:57:46 pawse-speakers volumio[20533]: info: Setting Spotify Volume from Volumio: 45 May 04 15:57:46 pawse-speakers volumio[20533]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4I59UjiR1vDGGdLmdvFoJO","play_origin":"home"}} May 04 15:57:46 pawse-speakers volumio[20533]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 04 15:57:46 pawse-speakers volumio[20533]: TypeError: Cannot read property 'service' of undefined May 04 15:57:46 pawse-speakers volumio[20533]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) May 04 15:57:46 pawse-speakers volumio[20533]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:262:18) May 04 15:57:46 pawse-speakers volumio[20533]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) May 04 15:57:46 pawse-speakers volumio[20533]: at WebSocket.emit (events.js:315:20) May 04 15:57:46 pawse-speakers volumio[20533]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) May 04 15:57:46 pawse-speakers volumio[20533]: at Receiver.emit (events.js:315:20) May 04 15:57:46 pawse-speakers volumio[20533]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) May 04 15:57:46 pawse-speakers volumio[20533]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) May 04 15:57:46 pawse-speakers volumio[20533]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) May 04 15:57:46 pawse-speakers volumio[20533]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) May 04 15:57:46 pawse-speakers volumio[20533]: at writeOrBuffer (internal/streams/writable.js:358:12) May 04 15:57:46 pawse-speakers volumio[20533]: at Receiver.Writable.write (internal/streams/writable.js:303:10) May 04 15:57:46 pawse-speakers volumio[20533]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) May 04 15:57:46 pawse-speakers volumio[20533]: at Socket.emit (events.js:315:20) May 04 15:57:46 pawse-speakers volumio[20533]: at addChunk (internal/streams/readable.js:309:12) May 04 15:57:46 pawse-speakers volumio[20533]: at readableAddChunk (internal/streams/readable.js:284:9) May 04 15:57:46 pawse-speakers volumio[20533]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 04 15:57:47 pawse-speakers sudo[20808]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-04 15:56 May 04 15:57:47 pawse-speakers sudo[20808]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 06:54:47 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="436f3f84f6d0b4ffc344f0bc132a32e8"