Dec 15 20:11:00 volumio-hall systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 20:11:00 volumio-hall systemd[1]: volumio.service: Scheduled restart job, restart counter is at 61. Dec 15 20:11:00 volumio-hall systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 20:11:00 volumio-hall systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 15 20:11:00 volumio-hall systemd[1]: volumio.service: Consumed 19.140s CPU time. Dec 15 20:11:00 volumio-hall systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 20:11:00 volumio-hall systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 20:11:01 volumio-hall volumio[24856]: info: ------------------------------------------- Dec 15 20:11:01 volumio-hall volumio[24856]: info: ----- Volumio3 ---- Dec 15 20:11:01 volumio-hall volumio[24856]: info: ------------------------------------------- Dec 15 20:11:01 volumio-hall volumio[24856]: info: ----- System startup ---- Dec 15 20:11:01 volumio-hall volumio[24856]: info: ------------------------------------------- Dec 15 20:11:01 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 20:11:01 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:01 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:01 volumio-hall go-librespot[24877]: go-librespot daemon starting... Dec 15 20:11:01 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:01+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:01 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:01+05:30" level=debug msg="app state loaded" Dec 15 20:11:01 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:01+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:11:01 volumio-hall volumio[24856]: info: MYVOLUMIO Environment detected Dec 15 20:11:01 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:01+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:11:01 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:01+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:11:01 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:01+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:11:01 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:01+05:30" level=info msg="zeroconf server listening on port 43445" Dec 15 20:11:01 volumio-hall volumio[24856]: info: Plugin folders cleanup Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning into folder /volumio/app/plugins/ Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning category audio_interface Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning category miscellanea Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning category music_service Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning category plugins.json Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning category system_controller Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning category user_interface Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning into folder /data/plugins/ Dec 15 20:11:01 volumio-hall volumio[24856]: info: Scanning category music_service Dec 15 20:11:01 volumio-hall volumio[24856]: info: Plugin folders cleanup completed Dec 15 20:11:01 volumio-hall volumio[24856]: info: ------------------------------------------- Dec 15 20:11:01 volumio-hall volumio[24856]: info: ----- Core plugins startup ---- Dec 15 20:11:01 volumio-hall volumio[24856]: info: ------------------------------------------- Dec 15 20:11:01 volumio-hall volumio[24856]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 20:11:01 volumio-hall volumio[24856]: info: Adding plugin upnp to MyMusic Plugins Dec 15 20:11:01 volumio-hall volumio[24856]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 20:11:01 volumio-hall volumio[24856]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 20:11:01 volumio-hall volumio[24856]: info: Loading plugins from folder /data/plugins/ Dec 15 20:11:01 volumio-hall volumio[24856]: info: Loading plugin "system"... Dec 15 20:11:01 volumio-hall volumio[24856]: info: Loading plugin "appearance"... Dec 15 20:11:01 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:01+05:30" level=debug msg="obtained new client token: AADO48gIuhp1KhDSGr8yo4aKSsxSkhyYNvgIt0QDGg4cC9Fkd2WuZRh5dHvA9pDOEeTDZOuUGTQGKgR82ej8nwQUo4JkNcdgg9L4zUA9mMBMqKqBqtElKQDnnMb0FH8duttI/7uEwdwRCJP64zMiyO46FDOmf+Ls53c24VO16S/nfKy8CI2lr5OMB6SAI8Z7uU5UQ+8mYjysSZcOB40I/r2xcOwLP7zBf7utRkqVR0O391yo4CjltFZKmg==" Dec 15 20:11:02 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:02+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:11:02 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:02+05:30" level=debug msg="completed keyexchange" Dec 15 20:11:02 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:02+05:30" level=debug msg="completed challenge" Dec 15 20:11:02 volumio-hall go-librespot[24878]: time="2025-12-15T20:11:02+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 20:11:02 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:11:02 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "network"... Dec 15 20:11:02 volumio-hall volumio[24856]: info: Refreshing Cached IP Addresses Dec 15 20:11:02 volumio-hall sudo[24893]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 20:11:02 volumio-hall sudo[24893]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:02 volumio-hall sudo[24895]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 20:11:02 volumio-hall sudo[24895]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:02 volumio-hall sudo[24893]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "services"... Dec 15 20:11:02 volumio-hall sudo[24895]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "alsa_controller"... Dec 15 20:11:02 volumio-hall sudo[24904]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 15 20:11:02 volumio-hall sudo[24904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:02 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "wizard"... Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "networkfs"... Dec 15 20:11:02 volumio-hall volumio[24856]: info: Cannot mount NAS AudioVideo at system boot, trial number 1 ,retrying in 5 seconds Dec 15 20:11:02 volumio-hall volumio[24856]: info: Starting Udev Watcher for removable devices Dec 15 20:11:02 volumio-hall volumio[24856]: info: Ignoring mount for partition: boot Dec 15 20:11:02 volumio-hall volumio[24856]: info: Ignoring mount for partition: volumio Dec 15 20:11:02 volumio-hall volumio[24856]: info: Ignoring mount for partition: volumio_data Dec 15 20:11:02 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "volumio_command_line_client"... Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "upnp"... Dec 15 20:11:02 volumio-hall volumio[24856]: info: [1765809662546] Starting Upmpd Daemon Dec 15 20:11:02 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "my_music"... Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "mpd"... Dec 15 20:11:02 volumio-hall volumio[24856]: info: Loading plugin "upnp_browser"... Dec 15 20:11:03 volumio-hall volumio[24856]: info: Starting UPNP Browser Dec 15 20:11:03 volumio-hall volumio[24856]: info: Loading plugin "alarm-clock"... Dec 15 20:11:03 volumio-hall volumio[24856]: info: Loading plugin "airplay_emulation"... Dec 15 20:11:03 volumio-hall volumio[24856]: info: Starting Shairport Sync Dec 15 20:11:03 volumio-hall volumio[24856]: info: Loading plugin "last_100"... Dec 15 20:11:03 volumio-hall volumio[24856]: info: Loading plugin "webradio"... Dec 15 20:11:03 volumio-hall volumio[24856]: info: Loading plugin "i2s_dacs"... Dec 15 20:11:03 volumio-hall volumio[24856]: info: Loading plugin "volumiodiscovery"... Dec 15 20:11:03 volumio-hall volumio[24856]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 20:11:03 volumio-hall volumio[24856]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:11:03 volumio-hall volumio[24856]: *** WARNING *** For more information see Dec 15 20:11:03 volumio-hall volumio[24856]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 20:11:03 volumio-hall volumio[24856]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:11:03 volumio-hall volumio[24856]: *** WARNING *** For more information see Dec 15 20:11:03 volumio-hall volumio[24856]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 20:11:03 volumio-hall node[24856]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 20:11:03 volumio-hall node[24856]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:11:03 volumio-hall node[24856]: *** WARNING *** For more information see Dec 15 20:11:03 volumio-hall node[24856]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 20:11:03 volumio-hall node[24856]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:11:03 volumio-hall node[24856]: *** WARNING *** For more information see Dec 15 20:11:03 volumio-hall volumio[24856]: info: Discovery: Started advertising with name: Volumio-Hall Dec 15 20:11:03 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:11:03 volumio-hall volumio[24856]: info: Loading plugin "spop"... Dec 15 20:11:04 volumio-hall volumio[24856]: info: Loading plugin "outputs"... Dec 15 20:11:04 volumio-hall volumio[24856]: info: Loading plugin "albumart"... Dec 15 20:11:04 volumio-hall volumio[24856]: info: Plugin example_plugin is not enabled Dec 15 20:11:04 volumio-hall volumio[24856]: info: Loading plugin "inputs"... Dec 15 20:11:04 volumio-hall volumio[24856]: info: Loading plugin "updater_comm"... Dec 15 20:11:04 volumio-hall volumio[24856]: info: Plugin mpdemulation is not enabled Dec 15 20:11:04 volumio-hall volumio[24856]: info: Loading plugin "rest_api"... Dec 15 20:11:04 volumio-hall volumio[24856]: info: Loading plugin "websocket"... Dec 15 20:11:04 volumio-hall volumio[24856]: info: Starting Socket.io Server version 1.7.4 Dec 15 20:11:04 volumio-hall volumio[24856]: info: Loading i18n strings for locale en Dec 15 20:11:04 volumio-hall volumio[24856]: Updating browse sources language Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::initPlayerControls Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: Express server listening on port 3000 Dec 15 20:11:04 volumio-hall volumio[24856]: [Metrics] WebUI: 3s 423.71ms Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreStateMachine::resetVolumioState Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreStateMachine::getcurrentVolume Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 20:11:04 volumio-hall volumio[24856]: info: Volumio Network Manager: Network status updated: 1 Dec 15 20:11:04 volumio-hall volumio[24856]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Dec 15 20:11:04 volumio-hall volumio[24856]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 15 20:11:04 volumio-hall volumio[24925]: Forking 3 albumart workers Dec 15 20:11:04 volumio-hall volumio[24856]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: Reloading queue from file Dec 15 20:11:04 volumio-hall volumio[24856]: info: VolumeController:: Volume=undefined Mute =false Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreStateMachine::pushState Dec 15 20:11:04 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioPushState Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreStateMachine::updateTrackBlock Dec 15 20:11:04 volumio-hall volumio[24856]: info: CorePlayQueue::getTrackBlock Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreStateMachine::setRepeat null single undefined Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreStateMachine::pushState Dec 15 20:11:04 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioPushState Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreStateMachine::setRandom null Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreStateMachine::pushState Dec 15 20:11:04 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioPushState Dec 15 20:11:04 volumio-hall volumio[24856]: info: Setting Device type: Raspberry PI Dec 15 20:11:04 volumio-hall volumio[24856]: info: Completed loading Core Plugins Dec 15 20:11:04 volumio-hall volumio[24856]: info: Preparing to generate the ALSA configuration file Dec 15 20:11:04 volumio-hall volumio[24856]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 15 20:11:04 volumio-hall volumio[24856]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03112 Dec 15 20:11:04 volumio-hall volumio[24856]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 15 20:11:04 volumio-hall volumio[24856]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 15 20:11:04 volumio-hall volumio[24856]: info: Asound.conf file unchanged, so no further update is needed Dec 15 20:11:04 volumio-hall volumio[24856]: info: Output device has changed, restarting MPD Dec 15 20:11:04 volumio-hall volumio[24856]: info: Output device has changed, restarting Shairport Sync Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:04 volumio-hall sudo[24982]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 20:11:04 volumio-hall sudo[24981]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 20:11:04 volumio-hall sudo[24982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:04 volumio-hall volumio[24856]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:11:04 volumio-hall sudo[24981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:04 volumio-hall volumio[24856]: info: ___________ START PLUGINS ___________ Dec 15 20:11:04 volumio-hall volumio[24856]: info: ControllerMpd::onStart: Initializing MPD Dec 15 20:11:04 volumio-hall volumio[24856]: info: Creating MPD Configuration file Dec 15 20:11:04 volumio-hall sudo[24981]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:04 volumio-hall systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:11:04 volumio-hall volumio[24856]: info: [1765809664835] CoreMusicLibrary::Adding element Media Servers Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:04 volumio-hall volumio[24856]: info: UPNP Browser: Client initialized successfully Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:04 volumio-hall sudo[24992]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 20:11:04 volumio-hall sudo[24992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:04 volumio-hall sudo[24994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 20:11:04 volumio-hall sudo[24994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:04 volumio-hall sudo[24992]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:04 volumio-hall volumio[24856]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:04 volumio-hall systemd[1]: mpd.service: Deactivated successfully. Dec 15 20:11:04 volumio-hall systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 20:11:04 volumio-hall systemd[1]: mpd.service: Consumed 2.426s CPU time. Dec 15 20:11:04 volumio-hall systemd[1]: mpd.socket: Deactivated successfully. Dec 15 20:11:04 volumio-hall systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 20:11:04 volumio-hall systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 20:11:04 volumio-hall volumio[24856]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:11:04 volumio-hall volumio[24856]: info: [1765809664926] CoreMusicLibrary::Adding element Last_100 Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:11:04 volumio-hall volumio[24856]: info: [1765809664929] CoreMusicLibrary::Adding element Webradio Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:04 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:11:04] [connect] Successful connection Dec 15 20:11:04 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:11:04 volumio-hall volumio[24856]: info: Initializing BBC Radios Dec 15 20:11:04 volumio-hall systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 20:11:04 volumio-hall systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 20:11:05 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:11:05 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:05 volumio-hall volumio[24856]: info: Creating Spotify config file Dec 15 20:11:05 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:05 volumio-hall sudo[25019]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 20:11:05 volumio-hall sudo[25019]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 20:11:05 volumio-hall sudo[25019]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:05 volumio-hall sudo[24904]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:05 volumio-hall volumio[24856]: info: Volumio Calling Home Dec 15 20:11:05 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 15 20:11:05 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:05 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:05 volumio-hall go-librespot[25025]: go-librespot daemon starting... Dec 15 20:11:05 volumio-hall go-librespot[25027]: time="2025-12-15T20:11:05+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:05 volumio-hall volumio[24856]: info: VolumeController:: Volume=undefined Mute =false Dec 15 20:11:05 volumio-hall volumio[24856]: info: CoreStateMachine::pushState Dec 15 20:11:05 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:05 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioPushState Dec 15 20:11:05 volumio-hall volumio[24856]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 15 20:11:05 volumio-hall volumio[24945]: Starting albumart workers Dec 15 20:11:05 volumio-hall volumio[24947]: Starting albumart workers Dec 15 20:11:05 volumio-hall volumio[24856]: info: MPD Permissions set Dec 15 20:11:05 volumio-hall volumio[24856]: info: MPD Permissions set Dec 15 20:11:05 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:11:05] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765809664 101 Dec 15 20:11:05 volumio-hall volumio[24942]: Starting albumart workers Dec 15 20:11:05 volumio-hall volumio[24856]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 4 Dec 15 20:11:06 volumio-hall go-librespot[25027]: time="2025-12-15T20:11:06+05:30" level=info msg="zeroconf server listening on port 36305" Dec 15 20:11:06 volumio-hall volumio[24856]: info: Spotify config file written Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 20:11:06 volumio-hall volumio[24856]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall sudo[25036]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall sudo[25036]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 15 20:11:06 volumio-hall systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 15 20:11:06 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:06 volumio-hall volumio[24856]: info: No need to fix Spotify hosts Dec 15 20:11:06 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:06 volumio-hall go-librespot[25045]: go-librespot daemon starting... Dec 15 20:11:06 volumio-hall sudo[25036]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=debug msg="app state loaded" Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:06 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:06 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 20:11:06 volumio-hall volumio[24856]: info: Received Get System Info Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 20:11:06 volumio-hall volumio[24856]: info: Discovery: Getting this device information Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:06 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:06 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:06 volumio-hall volumio[24856]: info: Listing playlists Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=info msg="zeroconf server listening on port 46397" Dec 15 20:11:06 volumio-hall volumio[24856]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=debug msg="obtained new client token: AADuPDfVGbIDaqhZsHJLWzJRfJhzdp9E/Kudy/Q8GJfzKgL5mqoJiCGnoOxgmdIXGwDF696gptlgQgU4iughj+YWg5yd+FLsljIAekaCy7b/oYXK1lvaVwHJv5zaxnxtWLkPGW87jKP3Y+cE2gWV7ASStG5zMLrWayUvrEajqcnk7B4QMw7/9jvT40ibIaAFLzYTTfRE0hpELznAJfYRZGPzt0d43ZjVFVM7L8nPaHma0/iSQ4eLzqENGA==" Dec 15 20:11:06 volumio-hall volumio[24856]: info: Volumio called home Dec 15 20:11:06 volumio-hall volumio[24856]: info: Starting Shairport Sync Dec 15 20:11:06 volumio-hall volumio[24856]: info: Starting Shairport Sync Dec 15 20:11:06 volumio-hall volumio[24856]: info: Starting Shairport Sync Dec 15 20:11:06 volumio-hall sudo[25072]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:11:06 volumio-hall sudo[25072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:06 volumio-hall sudo[25074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:11:06 volumio-hall systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:11:06 volumio-hall systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 20:11:06 volumio-hall systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:11:06 volumio-hall systemd[1]: shairport-sync.service: Consumed 1.660s CPU time. Dec 15 20:11:06 volumio-hall sudo[25074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:06 volumio-hall sudo[25078]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:11:06 volumio-hall sudo[25078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:06 volumio-hall systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=debug msg="completed keyexchange" Dec 15 20:11:06 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:06+05:30" level=debug msg="completed challenge" Dec 15 20:11:06 volumio-hall sudo[25072]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:06 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 20:11:06 volumio-hall systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 20:11:06 volumio-hall systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 20:11:06 volumio-hall systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:11:07 volumio-hall systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:11:07 volumio-hall sudo[25074]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:07 volumio-hall sudo[25078]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:07 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:07 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 20:11:07 volumio-hall volumio[24856]: info: Received Get System Info Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 20:11:07 volumio-hall volumio[24856]: info: Discovery: Getting this device information Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:07 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 20:11:07 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:07 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:07 volumio-hall volumio[24856]: info: Listing playlists Dec 15 20:11:07 volumio-hall volumio[24856]: info: Shairport-Sync Started Dec 15 20:11:07 volumio-hall volumio[24856]: Error adding Membership: Error: addMembership EINVAL Dec 15 20:11:07 volumio-hall volumio[24856]: info: Shairport-Sync Started Dec 15 20:11:07 volumio-hall volumio[24856]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 20:11:07 volumio-hall volumio[24856]: SPOTIFY: BQDysc9y-xYvE6VoB9ZFhe-7tuxU30w0tTM9HTSsPxr23btAg1YWr2gQ0HH0X4rwQdyhHLaqO-POwi36p1w7AxiKPCX-y8uz9yKG24THgnyPVNI9PVXC721LChF7OfmGFuN5XGcUMyEY1LLfVg9-T2XiasPaG4vsYvB8TmdbLAqKCXgRJvp-9lrPw7mdpAy9gmQlmz5ucdwPRYwj5tGsk-a6cfGGQ-BfaRPbVKnGd6XvHW9JX7IKiCjxdWKaTtO0PJG6z9RztvP2NH8r56vAwdAoGiDuGufR2m_J16njzerLDoSWkKjZeZx4HFke Dec 15 20:11:07 volumio-hall volumio[24856]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 20:11:07 volumio-hall volumio[24856]: info: New Spotify access token = BQDysc9y-xYvE6VoB9ZFhe-7tuxU30w0tTM9HTSsPxr23btAg1YWr2gQ0HH0X4rwQdyhHLaqO-POwi36p1w7AxiKPCX-y8uz9yKG24THgnyPVNI9PVXC721LChF7OfmGFuN5XGcUMyEY1LLfVg9-T2XiasPaG4vsYvB8TmdbLAqKCXgRJvp-9lrPw7mdpAy9gmQlmz5ucdwPRYwj5tGsk-a6cfGGQ-BfaRPbVKnGd6XvHW9JX7IKiCjxdWKaTtO0PJG6z9RztvP2NH8r56vAwdAoGiDuGufR2m_J16njzerLDoSWkKjZeZx4HFke Dec 15 20:11:07 volumio-hall volumio[24856]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 20:11:07 volumio-hall volumio[24856]: info: Shairport-Sync Started Dec 15 20:11:07 volumio-hall mpd[25022]: 2025-12-15T20:11:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 20:11:07 volumio-hall volumio[24856]: info: Cannot mount NAS AudioVideo at system boot, trial number 2 ,retrying in 5 seconds Dec 15 20:11:07 volumio-hall systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 20:11:07 volumio-hall sudo[24994]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:07 volumio-hall sudo[24982]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:07 volumio-hall volumio[24856]: info: Completed starting Core Plugins Dec 15 20:11:07 volumio-hall volumio[24856]: info: ------------------------------------------- Dec 15 20:11:07 volumio-hall volumio[24856]: info: ----- MyVolumio plugins startup ---- Dec 15 20:11:07 volumio-hall volumio[24856]: info: ------------------------------------------- Dec 15 20:11:07 volumio-hall volumio[24856]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 20:11:07 volumio-hall volumio[24856]: error: MPD error: The expression evaluated to a falsy value: Dec 15 20:11:07 volumio-hall volumio[24856]: assert.ok(self.idling) Dec 15 20:11:07 volumio-hall volumio[24856]: error: The expression evaluated to a falsy value: Dec 15 20:11:07 volumio-hall volumio[24856]: assert.ok(self.idling) Dec 15 20:11:07 volumio-hall volumio[24856]: info: MPD running with PID25022 Dec 15 20:11:07 volumio-hall volumio[24856]: ,establishing connection Dec 15 20:11:07 volumio-hall volumio[24856]: error: updateQueue error: null Dec 15 20:11:07 volumio-hall volumio[24856]: error: updateQueue error: null Dec 15 20:11:09 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:09+05:30" level=info msg="authenticated AP" username="31************************4y" Dec 15 20:11:09 volumio-hall go-librespot[25049]: time="2025-12-15T20:11:09+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 20:11:09 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:11:09 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:11:09 volumio-hall volumio[24856]: info: Discovery: adding 21d80c26-f81b-4ba7-b7e4-77d93d8b8552 Dec 15 20:11:09 volumio-hall volumio[24856]: info: Discovery: Found device Volumio-Zero Dec 15 20:11:09 volumio-hall volumio[24856]: info: Discovery: Connecting to remote: 192.168.0.154 Dec 15 20:11:09 volumio-hall volumio[24856]: info: Discovery: adding 1e7f4238-4a59-44f1-ae5d-e6bcede79cfb Dec 15 20:11:09 volumio-hall volumio[24856]: info: Discovery: Found device Volumio-Hall Dec 15 20:11:09 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:09 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:09 volumio-hall volumio[24856]: info: Discovery: this is already registered, 1e7f4238-4a59-44f1-ae5d-e6bcede79cfb Dec 15 20:11:09 volumio-hall volumio[24856]: info: Discovery: Found device Volumio-Hall Dec 15 20:11:09 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:09 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:09 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:09 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:09 volumio-hall volumio[24856]: info: Discovery: Connected to remote: 192.168.0.154 Dec 15 20:11:09 volumio-hall volumio[24856]: info: go-librespot daemon successfully initialized Dec 15 20:11:09 volumio-hall volumio[24856]: verbose: New Socket.io Connection to 192.168.0.144:3000 from 192.168.0.154 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 15 20:11:09 volumio-hall volumio[24856]: SPOTIFY: User informations: {"country":"IN","display_name":"31ounivl5lgdj7urtwg2tknrat4y","email":"post2skumar@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31ounivl5lgdj7urtwg2tknrat4y"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31ounivl5lgdj7urtwg2tknrat4y","id":"31ounivl5lgdj7urtwg2tknrat4y","images":[],"product":"premium","type":"user","uri":"spotify:user:31ounivl5lgdj7urtwg2tknrat4y"} Dec 15 20:11:09 volumio-hall volumio[24856]: info: Spotify Successfully logged in Dec 15 20:11:09 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:11:09 volumio-hall volumio[24856]: info: [1765809669896] CoreMusicLibrary::Adding element Spotify Dec 15 20:11:09 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:09 volumio-hall volumio[24856]: Cannot find translation for source Spotify Dec 15 20:11:10 volumio-hall volumio[24856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 15 20:11:10 volumio-hall volumio[24856]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:10 volumio-hall volumio[24856]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:10 volumio-hall sudo[25109]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 20:11:10 volumio-hall sudo[25109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:10 volumio-hall sudo[25112]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 20:11:10 volumio-hall sudo[25112]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:10 volumio-hall systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 20:11:10 volumio-hall systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 20:11:10 volumio-hall systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 20:11:10 volumio-hall systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 20:11:10 volumio-hall sudo[25109]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:10 volumio-hall mpd_monitor.sh[25114]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 20:11:10 volumio-hall volumio[24856]: info: Successfully started MPD Monitor Dec 15 20:11:10 volumio-hall systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 20:11:10 volumio-hall systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 20:11:10 volumio-hall systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 20:11:10 volumio-hall systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 20:11:10 volumio-hall sudo[25112]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:10 volumio-hall volumio[24856]: info: Successfully started MPD Monitor Dec 15 20:11:10 volumio-hall mpd_monitor.sh[25116]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 20:11:12 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 15 20:11:12 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:12 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:12 volumio-hall go-librespot[25120]: go-librespot daemon starting... Dec 15 20:11:12 volumio-hall volumio[24856]: info: Cannot mount NAS AudioVideo at system boot, trial number 3 ,retrying in 5 seconds Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=debug msg="app state loaded" Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:11:12 volumio-hall sudo[25142]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 20:11:12 volumio-hall sudo[25142]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:12 volumio-hall sudo[25142]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:12 volumio-hall sudo[25144]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 20:11:12 volumio-hall sudo[25144]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:12 volumio-hall sudo[25144]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:12 volumio-hall sudo[25148]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 20:11:12 volumio-hall sudo[25148]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:12 volumio-hall sudo[25148]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:12 volumio-hall volumio[24856]: info: Upmpdcli Daemon Started Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=info msg="zeroconf server listening on port 33335" Dec 15 20:11:12 volumio-hall volumio[24856]: info: Initializing connection to go-librespot Websocket Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=debug msg="new websocket client" Dec 15 20:11:12 volumio-hall volumio[24856]: info: Connection to go-librespot Websocket established Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=debug msg="obtained new client token: AAC5J0ExEngjdGMrA1vIEha1DqlVYV2LdH/cFs9tOAgic4PimJ/bC/R45Vwf+6aOthb9IsXaaYkWYlp6xvt16TPYz2dNlVBoEtforzBUv+OZXd8KOqgYf8g8q02nFBVBuxyGfq+nXG5TuJso8ihgyf4fxE9h5gf3IhB56v2z3jiH5rwbctOZX0Zj2yNlpp01rKbKisyYVj12YZSNTMiKYY1ewq1qQWikmXA572vimwNnIiO94HbjdYumVQ==" Dec 15 20:11:12 volumio-hall volumio[24856]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 20:11:12 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:12+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:11:13 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:13+05:30" level=debug msg="completed keyexchange" Dec 15 20:11:13 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:13+05:30" level=debug msg="completed challenge" Dec 15 20:11:13 volumio-hall go-librespot[25135]: time="2025-12-15T20:11:13+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 20:11:13 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:11:13 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:11:13 volumio-hall volumio[24856]: info: Connection to go-librespot Websocket closed Dec 15 20:11:15 volumio-hall volumio[24856]: Cannot compose Albumart path Dec 15 20:11:15 volumio-hall volumio[24856]: info: Getting Spotify volume Dec 15 20:11:15 volumio-hall volumio[24856]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 20:11:15 volumio-hall volumio[24856]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 20:11:15 volumio-hall volumio[24856]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 15 20:11:15 volumio-hall volumio[24856]: errno: -111, Dec 15 20:11:15 volumio-hall volumio[24856]: code: 'ECONNREFUSED', Dec 15 20:11:15 volumio-hall volumio[24856]: syscall: 'connect', Dec 15 20:11:15 volumio-hall volumio[24856]: address: '127.0.0.1', Dec 15 20:11:15 volumio-hall volumio[24856]: port: 9879, Dec 15 20:11:15 volumio-hall volumio[24856]: response: undefined Dec 15 20:11:15 volumio-hall volumio[24856]: } Dec 15 20:11:15 volumio-hall volumio[24856]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 20:11:16 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 20:11:16 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:16 volumio-hall sudo[25166]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 20:10' Dec 15 20:11:16 volumio-hall sudo[25166]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:16 volumio-hall nmbd[1099]: [2025/12/15 20:11:16.269508, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) Dec 15 20:11:16 volumio-hall nmbd[1099]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.0.144 for name WORKGROUP<1d>. Dec 15 20:11:16 volumio-hall nmbd[1099]: This response was from IP 192.168.0.110, reporting an IP address of 192.168.0.110. Dec 15 20:11:16 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:16 volumio-hall go-librespot[25165]: go-librespot daemon starting... Dec 15 20:11:16 volumio-hall go-librespot[25169]: time="2025-12-15T20:11:16+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:16 volumio-hall go-librespot[25169]: time="2025-12-15T20:11:16+05:30" level=debug msg="app state loaded" Dec 15 20:11:16 volumio-hall go-librespot[25169]: time="2025-12-15T20:11:16+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:11:16 volumio-hall sudo[25166]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:16 volumio-hall go-librespot[25169]: time="2025-12-15T20:11:16+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:11:16 volumio-hall go-librespot[25169]: time="2025-12-15T20:11:16+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:11:16 volumio-hall go-librespot[25169]: time="2025-12-15T20:11:16+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:11:16 volumio-hall go-librespot[25169]: time="2025-12-15T20:11:16+05:30" level=info msg="zeroconf server listening on port 44603" Dec 15 20:11:16 volumio-hall go-librespot[25169]: time="2025-12-15T20:11:16+05:30" level=debug msg="obtained new client token: AAC5FeBuBrFvy+WSib/rBkhXOOCjyLWRlek5U2M+19Hh5rJHBZrlisbWWFPN0xV6KD6UIag7sjfQl3cKPEfh+GPS5A1dRVo2SnbzeaA+35QQtIgozgODyHs4YXgOXd7hUbchkvoB7DZN8dfEASSSV8kd7HLqP+pjzXMGKOgv7VgwBDdFipob3m5iuXusZsvpQkXwnUPW3WzFSuxslMwfDjSRxk2hp5JkCBT14oSStuTxf2eB0po+AX0X4A==" Dec 15 20:11:16 volumio-hall go-librespot[25169]: time="2025-12-15T20:11:16+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:11:16 volumio-hall go-librespot[25169]: time="2025-12-15T20:11:16+05:30" level=debug msg="completed keyexchange" Dec 15 20:11:16 volumio-hall go-librespot[25169]: time="2025-12-15T20:11:16+05:30" level=debug msg="completed challenge" Dec 15 20:11:17 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:11:17] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 15 20:11:17 volumio-hall systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:11:17 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:11:17] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 15 20:11:17 volumio-hall systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 15 20:11:17 volumio-hall systemd[1]: volumio.service: Consumed 19.124s CPU time. Dec 15 20:11:17 volumio-hall systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 20:11:17 volumio-hall systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 20:11:17 volumio-hall systemd[1]: volumio.service: Scheduled restart job, restart counter is at 62. Dec 15 20:11:17 volumio-hall systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 20:11:17 volumio-hall systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 15 20:11:17 volumio-hall systemd[1]: volumio.service: Consumed 19.124s CPU time. Dec 15 20:11:17 volumio-hall systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 20:11:17 volumio-hall systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 20:11:19 volumio-hall volumio[25189]: info: ------------------------------------------- Dec 15 20:11:19 volumio-hall volumio[25189]: info: ----- Volumio3 ---- Dec 15 20:11:19 volumio-hall volumio[25189]: info: ------------------------------------------- Dec 15 20:11:19 volumio-hall volumio[25189]: info: ----- System startup ---- Dec 15 20:11:19 volumio-hall volumio[25189]: info: ------------------------------------------- Dec 15 20:11:19 volumio-hall go-librespot[25169]: time="2025-12-15T20:11:19+05:30" level=info msg="authenticated AP" username="31************************4y" Dec 15 20:11:19 volumio-hall volumio[25189]: info: MYVOLUMIO Environment detected Dec 15 20:11:19 volumio-hall volumio[25189]: info: Plugin folders cleanup Dec 15 20:11:19 volumio-hall volumio[25189]: info: Scanning into folder /volumio/app/plugins/ Dec 15 20:11:19 volumio-hall volumio[25189]: info: Scanning category audio_interface Dec 15 20:11:19 volumio-hall volumio[25189]: info: Scanning category miscellanea Dec 15 20:11:19 volumio-hall volumio[25189]: info: Scanning category music_service Dec 15 20:11:19 volumio-hall volumio[25189]: info: Scanning category plugins.json Dec 15 20:11:19 volumio-hall volumio[25189]: info: Scanning category system_controller Dec 15 20:11:19 volumio-hall volumio[25189]: info: Scanning category user_interface Dec 15 20:11:19 volumio-hall volumio[25189]: info: Scanning into folder /data/plugins/ Dec 15 20:11:19 volumio-hall volumio[25189]: info: Scanning category music_service Dec 15 20:11:19 volumio-hall volumio[25189]: info: Plugin folders cleanup completed Dec 15 20:11:19 volumio-hall volumio[25189]: info: ------------------------------------------- Dec 15 20:11:19 volumio-hall volumio[25189]: info: ----- Core plugins startup ---- Dec 15 20:11:19 volumio-hall volumio[25189]: info: ------------------------------------------- Dec 15 20:11:19 volumio-hall volumio[25189]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 20:11:19 volumio-hall volumio[25189]: info: Adding plugin upnp to MyMusic Plugins Dec 15 20:11:19 volumio-hall volumio[25189]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 20:11:19 volumio-hall volumio[25189]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 20:11:19 volumio-hall volumio[25189]: info: Loading plugins from folder /data/plugins/ Dec 15 20:11:19 volumio-hall volumio[25189]: info: Loading plugin "system"... Dec 15 20:11:19 volumio-hall volumio[25189]: info: Loading plugin "appearance"... Dec 15 20:11:20 volumio-hall go-librespot[25169]: time="2025-12-15T20:11:20+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 20:11:20 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:11:20 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:11:20 volumio-hall volumio[25189]: info: Loading plugin "network"... Dec 15 20:11:20 volumio-hall volumio[25189]: info: Refreshing Cached IP Addresses Dec 15 20:11:20 volumio-hall sudo[25217]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 20:11:20 volumio-hall sudo[25217]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:20 volumio-hall sudo[25219]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 20:11:20 volumio-hall sudo[25219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:20 volumio-hall volumio[25189]: info: Loading plugin "services"... Dec 15 20:11:20 volumio-hall sudo[25217]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:20 volumio-hall volumio[25189]: info: Loading plugin "alsa_controller"... Dec 15 20:11:20 volumio-hall sudo[25219]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:20 volumio-hall sudo[25226]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 15 20:11:20 volumio-hall sudo[25226]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:20 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:11:20 volumio-hall volumio[25189]: info: Loading plugin "wizard"... Dec 15 20:11:20 volumio-hall volumio[25189]: info: Loading plugin "networkfs"... Dec 15 20:11:20 volumio-hall volumio[25189]: info: Cannot mount NAS AudioVideo at system boot, trial number 1 ,retrying in 5 seconds Dec 15 20:11:20 volumio-hall volumio[25189]: info: Starting Udev Watcher for removable devices Dec 15 20:11:20 volumio-hall volumio[25189]: info: Ignoring mount for partition: boot Dec 15 20:11:20 volumio-hall volumio[25189]: info: Ignoring mount for partition: volumio Dec 15 20:11:20 volumio-hall volumio[25189]: info: Ignoring mount for partition: volumio_data Dec 15 20:11:20 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:11:20 volumio-hall volumio[25189]: info: Loading plugin "volumio_command_line_client"... Dec 15 20:11:20 volumio-hall volumio[25189]: info: Loading plugin "upnp"... Dec 15 20:11:20 volumio-hall volumio[25189]: info: [1765809680229] Starting Upmpd Daemon Dec 15 20:11:20 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:11:20 volumio-hall volumio[25189]: info: Loading plugin "my_music"... Dec 15 20:11:20 volumio-hall volumio[25189]: info: Loading plugin "mpd"... Dec 15 20:11:20 volumio-hall volumio[25189]: info: Loading plugin "upnp_browser"... Dec 15 20:11:21 volumio-hall volumio[25189]: info: Starting UPNP Browser Dec 15 20:11:21 volumio-hall volumio[25189]: info: Loading plugin "alarm-clock"... Dec 15 20:11:21 volumio-hall volumio[25189]: info: Loading plugin "airplay_emulation"... Dec 15 20:11:21 volumio-hall volumio[25189]: info: Starting Shairport Sync Dec 15 20:11:21 volumio-hall volumio[25189]: info: Loading plugin "last_100"... Dec 15 20:11:21 volumio-hall volumio[25189]: info: Loading plugin "webradio"... Dec 15 20:11:21 volumio-hall volumio[25189]: info: Loading plugin "i2s_dacs"... Dec 15 20:11:21 volumio-hall volumio[25189]: info: Loading plugin "volumiodiscovery"... Dec 15 20:11:21 volumio-hall volumio[25189]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 20:11:21 volumio-hall volumio[25189]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:11:21 volumio-hall volumio[25189]: *** WARNING *** For more information see Dec 15 20:11:21 volumio-hall volumio[25189]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 20:11:21 volumio-hall volumio[25189]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:11:21 volumio-hall volumio[25189]: *** WARNING *** For more information see Dec 15 20:11:21 volumio-hall node[25189]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 20:11:21 volumio-hall node[25189]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:11:21 volumio-hall node[25189]: *** WARNING *** For more information see Dec 15 20:11:21 volumio-hall node[25189]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 20:11:21 volumio-hall node[25189]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:11:21 volumio-hall node[25189]: *** WARNING *** For more information see Dec 15 20:11:21 volumio-hall volumio[25189]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 20:11:21 volumio-hall volumio[25189]: info: Discovery: Started advertising with name: Volumio-Hall Dec 15 20:11:21 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:11:21 volumio-hall volumio[25189]: info: Loading plugin "spop"... Dec 15 20:11:21 volumio-hall volumio[25189]: info: Loading plugin "outputs"... Dec 15 20:11:21 volumio-hall volumio[25189]: info: Loading plugin "albumart"... Dec 15 20:11:21 volumio-hall volumio[25189]: info: Plugin example_plugin is not enabled Dec 15 20:11:21 volumio-hall volumio[25189]: info: Loading plugin "inputs"... Dec 15 20:11:21 volumio-hall volumio[25189]: info: Loading plugin "updater_comm"... Dec 15 20:11:22 volumio-hall volumio[25189]: info: Plugin mpdemulation is not enabled Dec 15 20:11:22 volumio-hall volumio[25189]: info: Loading plugin "rest_api"... Dec 15 20:11:22 volumio-hall volumio[25189]: info: Loading plugin "websocket"... Dec 15 20:11:22 volumio-hall volumio[25189]: info: Starting Socket.io Server version 1.7.4 Dec 15 20:11:22 volumio-hall volumio[25189]: info: Loading i18n strings for locale en Dec 15 20:11:22 volumio-hall volumio[25189]: Updating browse sources language Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::initPlayerControls Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:11:22 volumio-hall volumio[25189]: Express server listening on port 3000 Dec 15 20:11:22 volumio-hall volumio[25189]: [Metrics] WebUI: 3s 392.98ms Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreStateMachine::resetVolumioState Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreStateMachine::getcurrentVolume Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 20:11:22 volumio-hall volumio[25189]: info: Volumio Network Manager: Network status updated: 1 Dec 15 20:11:22 volumio-hall volumio[25189]: verbose: New Socket.io Connection to 192.168.0.144:3000 from 192.168.0.154 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Dec 15 20:11:22 volumio-hall volumio[25189]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 15 20:11:22 volumio-hall volumio[25249]: Forking 3 albumart workers Dec 15 20:11:22 volumio-hall volumio[25189]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:22 volumio-hall volumio[25189]: info: Reloading queue from file Dec 15 20:11:22 volumio-hall volumio[25189]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 15 20:11:22 volumio-hall volumio[25189]: info: VolumeController:: Volume=undefined Mute =false Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreStateMachine::pushState Dec 15 20:11:22 volumio-hall volumio[25189]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioPushState Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreStateMachine::updateTrackBlock Dec 15 20:11:22 volumio-hall volumio[25189]: info: CorePlayQueue::getTrackBlock Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreStateMachine::setRepeat null single undefined Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreStateMachine::pushState Dec 15 20:11:22 volumio-hall volumio[25189]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioPushState Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreStateMachine::setRandom null Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreStateMachine::pushState Dec 15 20:11:22 volumio-hall volumio[25189]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioPushState Dec 15 20:11:22 volumio-hall volumio[25189]: info: Setting Device type: Raspberry PI Dec 15 20:11:22 volumio-hall volumio[25189]: info: Completed loading Core Plugins Dec 15 20:11:22 volumio-hall volumio[25189]: info: Preparing to generate the ALSA configuration file Dec 15 20:11:22 volumio-hall volumio[25189]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 15 20:11:22 volumio-hall volumio[25189]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03112 Dec 15 20:11:22 volumio-hall volumio[25189]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 15 20:11:22 volumio-hall volumio[25189]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 15 20:11:22 volumio-hall volumio[25189]: info: VolumeController:: Volume=undefined Mute =false Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreStateMachine::pushState Dec 15 20:11:22 volumio-hall volumio[25189]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioPushState Dec 15 20:11:22 volumio-hall volumio[25189]: info: Asound.conf file unchanged, so no further update is needed Dec 15 20:11:22 volumio-hall volumio[25189]: info: Output device has changed, restarting MPD Dec 15 20:11:22 volumio-hall volumio[25189]: info: Output device has changed, restarting Shairport Sync Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:22 volumio-hall volumio[25189]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:11:22 volumio-hall sudo[25307]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 20:11:22 volumio-hall sudo[25307]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:22 volumio-hall volumio[25189]: info: ___________ START PLUGINS ___________ Dec 15 20:11:22 volumio-hall sudo[25307]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:22 volumio-hall sudo[25309]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 20:11:22 volumio-hall sudo[25309]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:22 volumio-hall volumio[25189]: info: ControllerMpd::onStart: Initializing MPD Dec 15 20:11:22 volumio-hall volumio[25189]: info: Creating MPD Configuration file Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:11:22 volumio-hall volumio[25189]: info: [1765809682615] CoreMusicLibrary::Adding element Media Servers Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:22 volumio-hall volumio[25189]: info: UPNP Browser: Client initialized successfully Dec 15 20:11:22 volumio-hall systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 20:11:22 volumio-hall sudo[25318]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:22 volumio-hall sudo[25318]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:22 volumio-hall sudo[25318]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:22 volumio-hall sudo[25319]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 20:11:22 volumio-hall sudo[25319]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:22 volumio-hall systemd[1]: mpd.service: Deactivated successfully. Dec 15 20:11:22 volumio-hall systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 20:11:22 volumio-hall systemd[1]: mpd.service: Consumed 2.677s CPU time. Dec 15 20:11:22 volumio-hall volumio[25189]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:22 volumio-hall systemd[1]: mpd.socket: Deactivated successfully. Dec 15 20:11:22 volumio-hall systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 20:11:22 volumio-hall systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 20:11:22 volumio-hall sudo[25226]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:22 volumio-hall volumio[25189]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:11:22 volumio-hall volumio[25189]: info: [1765809682772] CoreMusicLibrary::Adding element Last_100 Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:11:22 volumio-hall volumio[25189]: info: [1765809682776] CoreMusicLibrary::Adding element Webradio Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:11:22 volumio-hall volumio[25189]: info: Initializing BBC Radios Dec 15 20:11:22 volumio-hall systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 20:11:22 volumio-hall systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 20:11:22 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:11:22] [connect] Successful connection Dec 15 20:11:22 volumio-hall systemd[1]: mpd.service: Deactivated successfully. Dec 15 20:11:22 volumio-hall systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 20:11:22 volumio-hall systemd[1]: mpd.socket: Deactivated successfully. Dec 15 20:11:22 volumio-hall systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 20:11:22 volumio-hall systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 20:11:22 volumio-hall systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 20:11:22 volumio-hall systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:22 volumio-hall volumio[25189]: info: Creating Spotify config file Dec 15 20:11:22 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall sudo[25344]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 20:11:23 volumio-hall sudo[25344]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 20:11:23 volumio-hall sudo[25344]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:23 volumio-hall volumio[25189]: info: Volumio Calling Home Dec 15 20:11:23 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 15 20:11:23 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:23 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:23 volumio-hall go-librespot[25351]: go-librespot daemon starting... Dec 15 20:11:23 volumio-hall go-librespot[25352]: time="2025-12-15T20:11:23+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:23 volumio-hall volumio[25189]: info: MPD Permissions set Dec 15 20:11:23 volumio-hall volumio[25189]: info: MPD Permissions set Dec 15 20:11:23 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:11:23] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765809682 101 Dec 15 20:11:23 volumio-hall volumio[25189]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 4 Dec 15 20:11:23 volumio-hall volumio[25189]: info: Spotify config file written Dec 15 20:11:23 volumio-hall volumio[25266]: Starting albumart workers Dec 15 20:11:23 volumio-hall go-librespot[25352]: time="2025-12-15T20:11:23+05:30" level=info msg="zeroconf server listening on port 46393" Dec 15 20:11:23 volumio-hall volumio[25189]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25268]: Starting albumart workers Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall sudo[25361]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 20:11:23 volumio-hall sudo[25361]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:23 volumio-hall volumio[25189]: info: No need to fix Spotify hosts Dec 15 20:11:23 volumio-hall systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 15 20:11:23 volumio-hall systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 15 20:11:23 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:23 volumio-hall volumio[25267]: Starting albumart workers Dec 15 20:11:23 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:23 volumio-hall go-librespot[25373]: go-librespot daemon starting... Dec 15 20:11:23 volumio-hall sudo[25361]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:23 volumio-hall go-librespot[25374]: time="2025-12-15T20:11:23+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:23 volumio-hall go-librespot[25374]: time="2025-12-15T20:11:23+05:30" level=debug msg="app state loaded" Dec 15 20:11:23 volumio-hall go-librespot[25374]: time="2025-12-15T20:11:23+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:11:23 volumio-hall volumio[25189]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Dec 15 20:11:23 volumio-hall volumio[25189]: info: Volumio called home Dec 15 20:11:23 volumio-hall volumio[25189]: info: Starting Shairport Sync Dec 15 20:11:23 volumio-hall volumio[25189]: info: Starting Shairport Sync Dec 15 20:11:23 volumio-hall volumio[25189]: info: Starting Shairport Sync Dec 15 20:11:23 volumio-hall sudo[25382]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:11:23 volumio-hall sudo[25384]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:11:23 volumio-hall sudo[25384]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:23 volumio-hall sudo[25385]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:11:23 volumio-hall sudo[25382]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:23 volumio-hall sudo[25385]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:23 volumio-hall systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 20:11:23 volumio-hall systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 20:11:23 volumio-hall systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:11:23 volumio-hall systemd[1]: shairport-sync.service: Consumed 1.675s CPU time. Dec 15 20:11:24 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 20:11:24 volumio-hall systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:11:24 volumio-hall go-librespot[25374]: time="2025-12-15T20:11:24+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 15 20:11:24 volumio-hall go-librespot[25374]: time="2025-12-15T20:11:24+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 15 20:11:24 volumio-hall go-librespot[25374]: time="2025-12-15T20:11:24+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 15 20:11:24 volumio-hall go-librespot[25374]: time="2025-12-15T20:11:24+05:30" level=info msg="zeroconf server listening on port 46483" Dec 15 20:11:24 volumio-hall sudo[25382]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:24 volumio-hall systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 20:11:24 volumio-hall systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 20:11:24 volumio-hall systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:11:24 volumio-hall systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:11:24 volumio-hall sudo[25384]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:24 volumio-hall volumio[25189]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 20:11:24 volumio-hall volumio[25189]: SPOTIFY: BQBdcJpIL5ed1kbIrKTKH7WeRzCn6EArYqEfxrtTh7Mo9lKSGh9OkuajN3NTpbWDj2Tq3axK_x4StfT8whOM-kcU-X5gU8PmQR7H7CiS8nErYapOTakVUxxSWUBeKrf4fD5sFKAbNxrTjR8jrFYiV4H8FJ7SHGLHXO5MN6DRmEJwQQaEUhElsSEys18vfvPRx70pt1dhkcbO9QypMxkgwvx43P9atnnaH0GbyM8haqy9EOd7fqrwLeFg6hfGe4jQ67NALWDNIBY4v2ocUHMUTZR3pGD0kEMpMfdcVjJZUcBlmpHsGpcIbdp_-Mnn Dec 15 20:11:24 volumio-hall volumio[25189]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 20:11:24 volumio-hall volumio[25189]: info: New Spotify access token = BQBdcJpIL5ed1kbIrKTKH7WeRzCn6EArYqEfxrtTh7Mo9lKSGh9OkuajN3NTpbWDj2Tq3axK_x4StfT8whOM-kcU-X5gU8PmQR7H7CiS8nErYapOTakVUxxSWUBeKrf4fD5sFKAbNxrTjR8jrFYiV4H8FJ7SHGLHXO5MN6DRmEJwQQaEUhElsSEys18vfvPRx70pt1dhkcbO9QypMxkgwvx43P9atnnaH0GbyM8haqy9EOd7fqrwLeFg6hfGe4jQ67NALWDNIBY4v2ocUHMUTZR3pGD0kEMpMfdcVjJZUcBlmpHsGpcIbdp_-Mnn Dec 15 20:11:24 volumio-hall volumio[25189]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 20:11:24 volumio-hall sudo[25385]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:24 volumio-hall go-librespot[25374]: time="2025-12-15T20:11:24+05:30" level=debug msg="obtained new client token: AACqvL8YC3PhZ/cUkAcKF1oTdyNgrSV3advGSwpn71EzHH+erwwHG1ormbH/ac3VpBq4ISYO+h/uObQRgQzjsExw2KTLJd/OaP7xaFpfTI35hsbSJ/vW7UY42Q89m2AmMjObZa9qhzj/TZEWFvd56hfmB+8QYPoTpLxidzegPCIvMwfjDi4a7zKQidii/Z0zwB1ezicbl2V6BaKX9kZLf+fH1ZiLrVd20mM6Rs25c0a41MFwKnTmqIg=" Dec 15 20:11:24 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 20:11:24 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:24 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:24 volumio-hall volumio[25189]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:24 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:24 volumio-hall volumio[25189]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:24 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 20:11:24 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 20:11:24 volumio-hall volumio[25189]: info: Received Get System Info Dec 15 20:11:24 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 20:11:24 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 20:11:24 volumio-hall volumio[25189]: info: Discovery: Getting this device information Dec 15 20:11:24 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:24 volumio-hall volumio[25189]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:24 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 20:11:24 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:24 volumio-hall volumio[25189]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:24 volumio-hall volumio[25189]: info: Listing playlists Dec 15 20:11:24 volumio-hall go-librespot[25374]: time="2025-12-15T20:11:24+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:11:24 volumio-hall volumio[25189]: info: Shairport-Sync Started Dec 15 20:11:24 volumio-hall volumio[25189]: Error adding Membership: Error: addMembership EINVAL Dec 15 20:11:24 volumio-hall volumio[25189]: info: Shairport-Sync Started Dec 15 20:11:24 volumio-hall volumio[25189]: info: Shairport-Sync Started Dec 15 20:11:24 volumio-hall go-librespot[25374]: time="2025-12-15T20:11:24+05:30" level=debug msg="completed keyexchange" Dec 15 20:11:24 volumio-hall go-librespot[25374]: time="2025-12-15T20:11:24+05:30" level=debug msg="completed challenge" Dec 15 20:11:25 volumio-hall go-librespot[25374]: time="2025-12-15T20:11:25+05:30" level=info msg="authenticated AP" username="31************************4y" Dec 15 20:11:25 volumio-hall mpd[25348]: 2025-12-15T20:11:25 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 20:11:25 volumio-hall volumio[25189]: info: Cannot mount NAS AudioVideo at system boot, trial number 2 ,retrying in 5 seconds Dec 15 20:11:25 volumio-hall systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 20:11:25 volumio-hall sudo[25319]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:25 volumio-hall sudo[25309]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:25 volumio-hall volumio[25189]: info: Completed starting Core Plugins Dec 15 20:11:25 volumio-hall volumio[25189]: info: ------------------------------------------- Dec 15 20:11:25 volumio-hall volumio[25189]: info: ----- MyVolumio plugins startup ---- Dec 15 20:11:25 volumio-hall volumio[25189]: info: ------------------------------------------- Dec 15 20:11:25 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 20:11:25 volumio-hall volumio[25189]: error: MPD error: The expression evaluated to a falsy value: Dec 15 20:11:25 volumio-hall volumio[25189]: assert.ok(self.idling) Dec 15 20:11:25 volumio-hall volumio[25189]: error: The expression evaluated to a falsy value: Dec 15 20:11:25 volumio-hall volumio[25189]: assert.ok(self.idling) Dec 15 20:11:25 volumio-hall volumio[25189]: info: MPD running with PID25348 Dec 15 20:11:25 volumio-hall volumio[25189]: ,establishing connection Dec 15 20:11:25 volumio-hall volumio[25189]: error: updateQueue error: null Dec 15 20:11:25 volumio-hall volumio[25189]: error: updateQueue error: null Dec 15 20:11:25 volumio-hall volumio[25189]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Dec 15 20:11:25 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 20:11:25 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 20:11:25 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:25 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:25 volumio-hall volumio[25189]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:25 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:25 volumio-hall volumio[25189]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:25 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 20:11:25 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 20:11:25 volumio-hall volumio[25189]: info: Received Get System Info Dec 15 20:11:25 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 20:11:25 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 20:11:25 volumio-hall volumio[25189]: info: Discovery: Getting this device information Dec 15 20:11:25 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:25 volumio-hall volumio[25189]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:25 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 20:11:25 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:25 volumio-hall volumio[25189]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:25 volumio-hall volumio[25189]: info: Listing playlists Dec 15 20:11:26 volumio-hall go-librespot[25374]: time="2025-12-15T20:11:26+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 20:11:26 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:11:26 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:11:26 volumio-hall volumio[25189]: info: go-librespot daemon successfully initialized Dec 15 20:11:28 volumio-hall sudo[25431]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 20:11:28 volumio-hall sudo[25431]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:28 volumio-hall sudo[25434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 20:11:28 volumio-hall sudo[25434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:28 volumio-hall systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 20:11:28 volumio-hall systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 20:11:28 volumio-hall systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 20:11:28 volumio-hall systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 20:11:28 volumio-hall sudo[25431]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:28 volumio-hall volumio[25189]: info: Successfully started MPD Monitor Dec 15 20:11:28 volumio-hall mpd_monitor.sh[25436]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 20:11:28 volumio-hall systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 20:11:28 volumio-hall systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 20:11:28 volumio-hall systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 20:11:28 volumio-hall systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 20:11:28 volumio-hall sudo[25434]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:28 volumio-hall mpd_monitor.sh[25439]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 20:11:28 volumio-hall volumio[25189]: info: Successfully started MPD Monitor Dec 15 20:11:29 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 15 20:11:29 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:29 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:29 volumio-hall go-librespot[25443]: go-librespot daemon starting... Dec 15 20:11:29 volumio-hall volumio[25189]: info: Initializing connection to go-librespot Websocket Dec 15 20:11:29 volumio-hall go-librespot[25444]: time="2025-12-15T20:11:29+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:29 volumio-hall go-librespot[25444]: time="2025-12-15T20:11:29+05:30" level=debug msg="app state loaded" Dec 15 20:11:29 volumio-hall go-librespot[25444]: time="2025-12-15T20:11:29+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:11:29 volumio-hall go-librespot[25444]: time="2025-12-15T20:11:29+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:11:29 volumio-hall go-librespot[25444]: time="2025-12-15T20:11:29+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:11:29 volumio-hall go-librespot[25444]: time="2025-12-15T20:11:29+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:11:29 volumio-hall go-librespot[25444]: time="2025-12-15T20:11:29+05:30" level=info msg="zeroconf server listening on port 45821" Dec 15 20:11:30 volumio-hall go-librespot[25444]: time="2025-12-15T20:11:30+05:30" level=debug msg="obtained new client token: AACDXTwbbULiKoifX8OWT+SQNnKMnGg02jJ0OpbpePqiA4/+unQ7L/aBjhHaXyuU1ZRD65ZJTLcK/8PbIQKYMSo/zZpa/tGzPbkL9Up6hXdA1bJ04biso/mqnZnd0LByoQ9UFCU+SgJcrK2bEkXqO94v1AYVf3d7aAVl34WjFUIM0e3RSv6w3oYjOpb8LIbcxl3qKLZN9Eq9sf7GhEcj/+x05430vd1e5bZZD+qI6a0n/1FgDfJeQ6c=" Dec 15 20:11:30 volumio-hall go-librespot[25444]: time="2025-12-15T20:11:30+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:11:30 volumio-hall volumio[25189]: info: Cannot mount NAS AudioVideo at system boot, trial number 3 ,retrying in 5 seconds Dec 15 20:11:30 volumio-hall sudo[25466]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 20:11:30 volumio-hall sudo[25466]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:30 volumio-hall sudo[25466]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:30 volumio-hall sudo[25468]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 20:11:30 volumio-hall sudo[25468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:30 volumio-hall sudo[25468]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:30 volumio-hall sudo[25471]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 20:11:30 volumio-hall sudo[25471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:30 volumio-hall go-librespot[25444]: time="2025-12-15T20:11:30+05:30" level=debug msg="completed keyexchange" Dec 15 20:11:30 volumio-hall sudo[25471]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:30 volumio-hall go-librespot[25444]: time="2025-12-15T20:11:30+05:30" level=debug msg="completed challenge" Dec 15 20:11:30 volumio-hall volumio[25189]: info: Upmpdcli Daemon Started Dec 15 20:11:30 volumio-hall go-librespot[25444]: time="2025-12-15T20:11:30+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 20:11:30 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:11:30 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:11:30 volumio-hall volumio[25189]: info: Discovery: adding 1e7f4238-4a59-44f1-ae5d-e6bcede79cfb Dec 15 20:11:30 volumio-hall volumio[25189]: info: Discovery: Found device Volumio-Hall Dec 15 20:11:30 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:30 volumio-hall volumio[25189]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:30 volumio-hall volumio[25189]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 20:11:30 volumio-hall volumio[25189]: verbose: New Socket.io Connection to 192.168.0.144:3000 from 192.168.0.154 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 15 20:11:31 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 15 20:11:31 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:31 volumio-hall volumio[25189]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:32 volumio-hall volumio[25189]: Cannot compose Albumart path Dec 15 20:11:33 volumio-hall volumio[25189]: info: Discovery: adding 21d80c26-f81b-4ba7-b7e4-77d93d8b8552 Dec 15 20:11:33 volumio-hall volumio[25189]: info: Discovery: Found device Volumio-Zero Dec 15 20:11:33 volumio-hall volumio[25189]: info: Discovery: Connecting to remote: 192.168.0.154 Dec 15 20:11:33 volumio-hall volumio[25189]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 20:11:33 volumio-hall volumio[25189]: info: Discovery: Connected to remote: 192.168.0.154 Dec 15 20:11:33 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:33 volumio-hall volumio[25189]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:33 volumio-hall volumio[25189]: SPOTIFY: User informations: {"country":"IN","display_name":"31ounivl5lgdj7urtwg2tknrat4y","email":"post2skumar@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31ounivl5lgdj7urtwg2tknrat4y"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31ounivl5lgdj7urtwg2tknrat4y","id":"31ounivl5lgdj7urtwg2tknrat4y","images":[],"product":"premium","type":"user","uri":"spotify:user:31ounivl5lgdj7urtwg2tknrat4y"} Dec 15 20:11:33 volumio-hall volumio[25189]: info: Spotify Successfully logged in Dec 15 20:11:33 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:11:33 volumio-hall volumio[25189]: info: [1765809693431] CoreMusicLibrary::Adding element Spotify Dec 15 20:11:33 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:33 volumio-hall volumio[25189]: Cannot find translation for source Spotify Dec 15 20:11:33 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 20:11:33 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:33 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:33 volumio-hall go-librespot[25474]: go-librespot daemon starting... Dec 15 20:11:33 volumio-hall go-librespot[25475]: time="2025-12-15T20:11:33+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:33 volumio-hall go-librespot[25475]: time="2025-12-15T20:11:33+05:30" level=debug msg="app state loaded" Dec 15 20:11:33 volumio-hall go-librespot[25475]: time="2025-12-15T20:11:33+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:11:33 volumio-hall go-librespot[25475]: time="2025-12-15T20:11:33+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:11:33 volumio-hall go-librespot[25475]: time="2025-12-15T20:11:33+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:11:33 volumio-hall go-librespot[25475]: time="2025-12-15T20:11:33+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:11:33 volumio-hall go-librespot[25475]: time="2025-12-15T20:11:33+05:30" level=info msg="zeroconf server listening on port 45269" Dec 15 20:11:33 volumio-hall go-librespot[25475]: time="2025-12-15T20:11:33+05:30" level=debug msg="obtained new client token: AAAHomqE3rE7SLTIpbJY1HRjSf8nDf1S3AJ4gw4FOnjvHhSR2pb+BttvYiOfr+9vOnX7NeJAH+O434mV6ogZOR+NsjA/Dzz2WQR2i0gZEQ1Q54wLaJQZo+kkxHdFSjwokbeEFAmF6miRYEpYsmrHT68YoZx93X/wAXE1AtKkk+ox27g66z7qqc1wPTsX/IcZKFg7R/vaHS9zc+Zrl/5NYa1bwehcOpaETbRfxrYJBvPQxNvvV2Ubr3dMVg==" Dec 15 20:11:33 volumio-hall go-librespot[25475]: time="2025-12-15T20:11:33+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:11:34 volumio-hall go-librespot[25475]: time="2025-12-15T20:11:34+05:30" level=debug msg="completed keyexchange" Dec 15 20:11:34 volumio-hall go-librespot[25475]: time="2025-12-15T20:11:34+05:30" level=debug msg="completed challenge" Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 20:11:34 volumio-hall volumio[25189]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 20:11:34 volumio-hall volumio[25189]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 20:11:34 volumio-hall volumio[25189]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 20:11:34 volumio-hall volumio[25189]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 20:11:34 volumio-hall volumio[25189]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 20:11:34 volumio-hall volumio[25189]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 20:11:34 volumio-hall volumio[25189]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 20:11:34 volumio-hall go-librespot[25475]: time="2025-12-15T20:11:34+05:30" level=info msg="authenticated AP" username="31************************4y" Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 20:11:34 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:34 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:34 volumio-hall volumio[25189]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 20:11:34 volumio-hall volumio[25189]: info: MyVolumio login type: Token Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 20:11:34 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 20:11:35 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 20:11:35 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 20:11:35 volumio-hall volumio[25189]: info: Streaming services startup Dec 15 20:11:35 volumio-hall volumio[25189]: info: Starting Streaming Daemon Dec 15 20:11:35 volumio-hall sudo[25484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 20:11:35 volumio-hall sudo[25484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:35 volumio-hall volumio[25189]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 20:11:35 volumio-hall sudo[25484]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:35 volumio-hall volumio[25189]: info: Cannot mount NAS AudioVideo at system boot, trial number 4 ,retrying in 5 seconds Dec 15 20:11:35 volumio-hall volumio[25189]: error: Cannot start Volumio Streaming Daemon Dec 15 20:11:35 volumio-hall volumio[25189]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 20:11:35 volumio-hall volumio[25189]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 20:11:35 volumio-hall volumio[25189]: info: Discovery: this is already registered, 1e7f4238-4a59-44f1-ae5d-e6bcede79cfb Dec 15 20:11:35 volumio-hall volumio[25189]: info: Discovery: Found device Volumio-Hall Dec 15 20:11:35 volumio-hall volumio[25189]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:35 volumio-hall volumio[25189]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:35 volumio-hall go-librespot[25475]: time="2025-12-15T20:11:35+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 20:11:35 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:11:35 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:11:36 volumio-hall volumio[25189]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 20:11:36 volumio-hall volumio[25189]: info: Initializing connection to go-librespot Websocket Dec 15 20:11:36 volumio-hall volumio[25189]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 20:11:36 volumio-hall volumio[25189]: info: MyVolumio token set successfully Dec 15 20:11:36 volumio-hall volumio[25189]: info: MYVOLUMIO: Adding device Dec 15 20:11:36 volumio-hall volumio[25189]: info: MYVOLUMIO: Evaluating Server Dec 15 20:11:37 volumio-hall volumio[25189]: info: MyVolumio status changed Dec 15 20:11:37 volumio-hall volumio[25189]: info: Streaming services startup Dec 15 20:11:37 volumio-hall volumio[25189]: info: Starting Streaming Daemon Dec 15 20:11:37 volumio-hall volumio[25189]: info: Removing browser output: myVolumio user plan is not superstar Dec 15 20:11:37 volumio-hall volumio[25189]: info: Removing audio output: Dec 15 20:11:37 volumio-hall volumio[25189]: info: Stoppping Tunnel 1 Dec 15 20:11:37 volumio-hall sudo[25511]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 20:11:37 volumio-hall sudo[25511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:37 volumio-hall sudo[25513]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 15 20:11:37 volumio-hall sudo[25513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:37 volumio-hall sudo[25511]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:37 volumio-hall volumio[25189]: error: Cannot start Volumio Streaming Daemon Dec 15 20:11:37 volumio-hall volumio[25189]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 20:11:37 volumio-hall volumio[25189]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 20:11:37 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:11:37 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:11:37 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:11:37 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:11:37 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:11:37 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:11:37 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:11:37 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:11:37 volumio-hall sudo[25513]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:37 volumio-hall volumio[25189]: info: Remote SSH Stopped Dec 15 20:11:37 volumio-hall volumio[25189]: info: Setting Geolocation for MyVolumio to as2 Dec 15 20:11:37 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:37 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:37 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:37 volumio-hall volumio[25189]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 15 20:11:38 volumio-hall volumio[25189]: info: Updating MyVolumio device info Dec 15 20:11:38 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:38 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:38 volumio-hall volumio[25189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:38 volumio-hall volumio[25189]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 15 20:11:38 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 15 20:11:38 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:39 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:39 volumio-hall go-librespot[25518]: go-librespot daemon starting... Dec 15 20:11:39 volumio-hall go-librespot[25519]: time="2025-12-15T20:11:39+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:39 volumio-hall go-librespot[25519]: time="2025-12-15T20:11:39+05:30" level=debug msg="app state loaded" Dec 15 20:11:39 volumio-hall go-librespot[25519]: time="2025-12-15T20:11:39+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:11:39 volumio-hall go-librespot[25519]: time="2025-12-15T20:11:39+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:11:39 volumio-hall go-librespot[25519]: time="2025-12-15T20:11:39+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:11:39 volumio-hall go-librespot[25519]: time="2025-12-15T20:11:39+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:11:39 volumio-hall go-librespot[25519]: time="2025-12-15T20:11:39+05:30" level=info msg="zeroconf server listening on port 33295" Dec 15 20:11:39 volumio-hall volumio[25189]: info: Initializing connection to go-librespot Websocket Dec 15 20:11:39 volumio-hall go-librespot[25519]: time="2025-12-15T20:11:39+05:30" level=debug msg="new websocket client" Dec 15 20:11:39 volumio-hall volumio[25189]: info: Connection to go-librespot Websocket established Dec 15 20:11:39 volumio-hall go-librespot[25519]: time="2025-12-15T20:11:39+05:30" level=debug msg="obtained new client token: AACafa5yNx1PQK0ZIVASsFRMHInJc+d7KB/C8pB/MkCfXF2aicrdNcDRoBXaN1X5UPk48lJvY+yDFdPkCSttoJcUGLrgWsQiMdhIp33NrjHzI9ITlAu/0IDux6DMDFNzqlb+/0PUAtsaR3mxddJdHk/PNohFz6x/pdtRwjYqnzzjFNIqr7xVK1cWtpD07JBryBmdlvhA8iSm9B3k8IWY9DfBmvDMt7Jou4/RNx2pVe0Anz3yTNf8qqHwSQ==" Dec 15 20:11:39 volumio-hall go-librespot[25519]: time="2025-12-15T20:11:39+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:11:39 volumio-hall go-librespot[25519]: time="2025-12-15T20:11:39+05:30" level=debug msg="completed keyexchange" Dec 15 20:11:39 volumio-hall go-librespot[25519]: time="2025-12-15T20:11:39+05:30" level=debug msg="completed challenge" Dec 15 20:11:39 volumio-hall go-librespot[25519]: time="2025-12-15T20:11:39+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 20:11:39 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:11:39 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:11:39 volumio-hall volumio[25189]: info: Connection to go-librespot Websocket closed Dec 15 20:11:40 volumio-hall volumio[25189]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Dec 15 20:11:41 volumio-hall volumio[25189]: info: MYVOLUMIO: Adding device Dec 15 20:11:41 volumio-hall volumio[25189]: info: MYVOLUMIO: Evaluating Server Dec 15 20:11:42 volumio-hall volumio[25189]: info: Getting Spotify volume Dec 15 20:11:42 volumio-hall volumio[25189]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 20:11:42 volumio-hall volumio[25189]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 20:11:42 volumio-hall volumio[25189]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 15 20:11:42 volumio-hall volumio[25189]: errno: -111, Dec 15 20:11:42 volumio-hall volumio[25189]: code: 'ECONNREFUSED', Dec 15 20:11:42 volumio-hall volumio[25189]: syscall: 'connect', Dec 15 20:11:42 volumio-hall volumio[25189]: address: '127.0.0.1', Dec 15 20:11:42 volumio-hall volumio[25189]: port: 9879, Dec 15 20:11:42 volumio-hall volumio[25189]: response: undefined Dec 15 20:11:42 volumio-hall volumio[25189]: } Dec 15 20:11:42 volumio-hall volumio[25189]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 20:11:42 volumio-hall sudo[25572]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 20:10' Dec 15 20:11:42 volumio-hall sudo[25572]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:42 volumio-hall sudo[25572]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:42 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:11:42] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 15 20:11:42 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:11:42] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 15 20:11:42 volumio-hall systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:11:42 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 15 20:11:42 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:42 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:42 volumio-hall go-librespot[25577]: go-librespot daemon starting... Dec 15 20:11:42 volumio-hall systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 15 20:11:42 volumio-hall systemd[1]: volumio.service: Consumed 21.283s CPU time. Dec 15 20:11:42 volumio-hall systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 20:11:42 volumio-hall go-librespot[25578]: time="2025-12-15T20:11:42+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:42 volumio-hall go-librespot[25578]: time="2025-12-15T20:11:42+05:30" level=debug msg="app state loaded" Dec 15 20:11:42 volumio-hall go-librespot[25578]: time="2025-12-15T20:11:42+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:11:42 volumio-hall systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 20:11:43 volumio-hall go-librespot[25578]: time="2025-12-15T20:11:43+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:11:43 volumio-hall go-librespot[25578]: time="2025-12-15T20:11:43+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:11:43 volumio-hall go-librespot[25578]: time="2025-12-15T20:11:43+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:11:43 volumio-hall go-librespot[25578]: time="2025-12-15T20:11:43+05:30" level=info msg="zeroconf server listening on port 37787" Dec 15 20:11:43 volumio-hall systemd[1]: volumio.service: Scheduled restart job, restart counter is at 63. Dec 15 20:11:43 volumio-hall systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 20:11:43 volumio-hall systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 15 20:11:43 volumio-hall systemd[1]: volumio.service: Consumed 21.283s CPU time. Dec 15 20:11:43 volumio-hall systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 20:11:43 volumio-hall systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 20:11:43 volumio-hall go-librespot[25578]: time="2025-12-15T20:11:43+05:30" level=debug msg="obtained new client token: AADiLaoLqbNNusdg3OPE/5UUvTbFesXcExPUhKCGpgjCWhZ8CVc0f2x4yVc4HzIDC1G4Bpv6n6eFCkoi7fYwQojDMpW+IinfClvNNi4xWFvyGTFsCtyXKzELR6ekIDZo+XBkMSVJQ2hIAVjrw1xLjNpeSQnD41FiwruR0PaNmWJLfGlQcKuQ45JpR2Wlm+GMk0u5t2AuiJiUr4X1SjnBSstzYi9IkMWfNqlbvyow3fnv/NY6xLXvVe4=" Dec 15 20:11:43 volumio-hall go-librespot[25578]: time="2025-12-15T20:11:43+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:11:43 volumio-hall go-librespot[25578]: time="2025-12-15T20:11:43+05:30" level=debug msg="completed keyexchange" Dec 15 20:11:43 volumio-hall go-librespot[25578]: time="2025-12-15T20:11:43+05:30" level=debug msg="completed challenge" Dec 15 20:11:44 volumio-hall go-librespot[25578]: time="2025-12-15T20:11:44+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 20:11:44 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:11:44 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:11:44 volumio-hall volumio[25592]: info: ------------------------------------------- Dec 15 20:11:44 volumio-hall volumio[25592]: info: ----- Volumio3 ---- Dec 15 20:11:44 volumio-hall volumio[25592]: info: ------------------------------------------- Dec 15 20:11:44 volumio-hall volumio[25592]: info: ----- System startup ---- Dec 15 20:11:44 volumio-hall volumio[25592]: info: ------------------------------------------- Dec 15 20:11:44 volumio-hall volumio[25592]: info: MYVOLUMIO Environment detected Dec 15 20:11:44 volumio-hall volumio[25592]: info: Plugin folders cleanup Dec 15 20:11:44 volumio-hall volumio[25592]: info: Scanning into folder /volumio/app/plugins/ Dec 15 20:11:44 volumio-hall volumio[25592]: info: Scanning category audio_interface Dec 15 20:11:44 volumio-hall volumio[25592]: info: Scanning category miscellanea Dec 15 20:11:44 volumio-hall volumio[25592]: info: Scanning category music_service Dec 15 20:11:44 volumio-hall volumio[25592]: info: Scanning category plugins.json Dec 15 20:11:44 volumio-hall volumio[25592]: info: Scanning category system_controller Dec 15 20:11:44 volumio-hall volumio[25592]: info: Scanning category user_interface Dec 15 20:11:44 volumio-hall volumio[25592]: info: Scanning into folder /data/plugins/ Dec 15 20:11:44 volumio-hall volumio[25592]: info: Scanning category music_service Dec 15 20:11:44 volumio-hall volumio[25592]: info: Plugin folders cleanup completed Dec 15 20:11:44 volumio-hall volumio[25592]: info: ------------------------------------------- Dec 15 20:11:44 volumio-hall volumio[25592]: info: ----- Core plugins startup ---- Dec 15 20:11:44 volumio-hall volumio[25592]: info: ------------------------------------------- Dec 15 20:11:44 volumio-hall volumio[25592]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 20:11:44 volumio-hall volumio[25592]: info: Adding plugin upnp to MyMusic Plugins Dec 15 20:11:44 volumio-hall volumio[25592]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 20:11:44 volumio-hall volumio[25592]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 20:11:44 volumio-hall volumio[25592]: info: Loading plugins from folder /data/plugins/ Dec 15 20:11:44 volumio-hall volumio[25592]: info: Loading plugin "system"... Dec 15 20:11:44 volumio-hall volumio[25592]: info: Loading plugin "appearance"... Dec 15 20:11:45 volumio-hall volumio[25592]: info: Loading plugin "network"... Dec 15 20:11:45 volumio-hall volumio[25592]: info: Refreshing Cached IP Addresses Dec 15 20:11:45 volumio-hall sudo[25620]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 20:11:45 volumio-hall sudo[25620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:45 volumio-hall volumio[25592]: info: Loading plugin "services"... Dec 15 20:11:45 volumio-hall sudo[25622]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 20:11:45 volumio-hall sudo[25622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:45 volumio-hall volumio[25592]: info: Loading plugin "alsa_controller"... Dec 15 20:11:45 volumio-hall sudo[25620]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:45 volumio-hall sudo[25622]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:45 volumio-hall sudo[25635]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 15 20:11:45 volumio-hall sudo[25635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:45 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:11:45 volumio-hall volumio[25592]: info: Loading plugin "wizard"... Dec 15 20:11:45 volumio-hall volumio[25592]: info: Loading plugin "networkfs"... Dec 15 20:11:45 volumio-hall volumio[25592]: info: Cannot mount NAS AudioVideo at system boot, trial number 1 ,retrying in 5 seconds Dec 15 20:11:45 volumio-hall volumio[25592]: info: Starting Udev Watcher for removable devices Dec 15 20:11:45 volumio-hall volumio[25592]: info: Ignoring mount for partition: boot Dec 15 20:11:45 volumio-hall volumio[25592]: info: Ignoring mount for partition: volumio Dec 15 20:11:45 volumio-hall volumio[25592]: info: Ignoring mount for partition: volumio_data Dec 15 20:11:45 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:11:45 volumio-hall volumio[25592]: info: Loading plugin "volumio_command_line_client"... Dec 15 20:11:45 volumio-hall volumio[25592]: info: Loading plugin "upnp"... Dec 15 20:11:45 volumio-hall volumio[25592]: info: [1765809705514] Starting Upmpd Daemon Dec 15 20:11:45 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:11:45 volumio-hall volumio[25592]: info: Loading plugin "my_music"... Dec 15 20:11:45 volumio-hall volumio[25592]: info: Loading plugin "mpd"... Dec 15 20:11:45 volumio-hall volumio[25592]: info: Loading plugin "upnp_browser"... Dec 15 20:11:46 volumio-hall volumio[25592]: info: Starting UPNP Browser Dec 15 20:11:46 volumio-hall volumio[25592]: info: Loading plugin "alarm-clock"... Dec 15 20:11:46 volumio-hall volumio[25592]: info: Loading plugin "airplay_emulation"... Dec 15 20:11:46 volumio-hall volumio[25592]: info: Starting Shairport Sync Dec 15 20:11:46 volumio-hall volumio[25592]: info: Loading plugin "last_100"... Dec 15 20:11:46 volumio-hall volumio[25592]: info: Loading plugin "webradio"... Dec 15 20:11:46 volumio-hall volumio[25592]: info: Loading plugin "i2s_dacs"... Dec 15 20:11:46 volumio-hall volumio[25592]: info: Loading plugin "volumiodiscovery"... Dec 15 20:11:46 volumio-hall volumio[25592]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 20:11:46 volumio-hall node[25592]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 20:11:46 volumio-hall volumio[25592]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:11:46 volumio-hall node[25592]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:11:46 volumio-hall volumio[25592]: *** WARNING *** For more information see Dec 15 20:11:46 volumio-hall node[25592]: *** WARNING *** For more information see Dec 15 20:11:46 volumio-hall volumio[25592]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 20:11:46 volumio-hall node[25592]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 20:11:46 volumio-hall volumio[25592]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:11:46 volumio-hall node[25592]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:11:46 volumio-hall volumio[25592]: *** WARNING *** For more information see Dec 15 20:11:46 volumio-hall node[25592]: *** WARNING *** For more information see Dec 15 20:11:46 volumio-hall volumio[25592]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 20:11:46 volumio-hall volumio[25592]: info: Discovery: Started advertising with name: Volumio-Hall Dec 15 20:11:46 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:11:46 volumio-hall volumio[25592]: info: Loading plugin "spop"... Dec 15 20:11:47 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 15 20:11:47 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:47 volumio-hall volumio[25592]: info: Loading plugin "outputs"... Dec 15 20:11:47 volumio-hall volumio[25592]: info: Loading plugin "albumart"... Dec 15 20:11:47 volumio-hall volumio[25592]: info: Plugin example_plugin is not enabled Dec 15 20:11:47 volumio-hall volumio[25592]: info: Loading plugin "inputs"... Dec 15 20:11:47 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:47 volumio-hall go-librespot[25652]: go-librespot daemon starting... Dec 15 20:11:47 volumio-hall volumio[25592]: info: Loading plugin "updater_comm"... Dec 15 20:11:47 volumio-hall go-librespot[25654]: time="2025-12-15T20:11:47+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:47 volumio-hall go-librespot[25654]: time="2025-12-15T20:11:47+05:30" level=debug msg="app state loaded" Dec 15 20:11:47 volumio-hall go-librespot[25654]: time="2025-12-15T20:11:47+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:11:47 volumio-hall volumio[25592]: info: Plugin mpdemulation is not enabled Dec 15 20:11:47 volumio-hall volumio[25592]: info: Loading plugin "rest_api"... Dec 15 20:11:47 volumio-hall volumio[25592]: info: Loading plugin "websocket"... Dec 15 20:11:47 volumio-hall volumio[25592]: info: Starting Socket.io Server version 1.7.4 Dec 15 20:11:47 volumio-hall volumio[25592]: info: Loading i18n strings for locale en Dec 15 20:11:47 volumio-hall volumio[25592]: Updating browse sources language Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::initPlayerControls Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:11:47 volumio-hall volumio[25592]: Express server listening on port 3000 Dec 15 20:11:47 volumio-hall volumio[25592]: [Metrics] WebUI: 3s 430.98ms Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreStateMachine::resetVolumioState Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreStateMachine::getcurrentVolume Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 20:11:47 volumio-hall go-librespot[25654]: time="2025-12-15T20:11:47+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:11:47 volumio-hall go-librespot[25654]: time="2025-12-15T20:11:47+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:11:47 volumio-hall go-librespot[25654]: time="2025-12-15T20:11:47+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:11:47 volumio-hall go-librespot[25654]: time="2025-12-15T20:11:47+05:30" level=info msg="zeroconf server listening on port 36255" Dec 15 20:11:47 volumio-hall volumio[25592]: info: Volumio Network Manager: Network status updated: 1 Dec 15 20:11:47 volumio-hall volumio[25653]: Forking 3 albumart workers Dec 15 20:11:47 volumio-hall go-librespot[25654]: time="2025-12-15T20:11:47+05:30" level=debug msg="obtained new client token: AAAmV1ja29ibsHS9Ee5+Vhh1RJH0ra9vkgXoYnEV7PxHnNV1S6RUi8RDP8s2XuXORdqJfNKvA/EG+RVjzcD7TEy4jyAeNdlNeyX9zFrVTE7y1KFXl40BS8Jj+roUvlr+auoTDhYwz1FF1NYDwjKBqzXQcxqmyiMBbH1XO/hhxOCzFmikBX1ta8k3T5pQKG+b0pFcOXTHUpSNvgxSXOQsENvaOc1jK51l16u7A4y376F3F2lmV1sZ6FsWgg==" Dec 15 20:11:47 volumio-hall volumio[25592]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Dec 15 20:11:47 volumio-hall volumio[25592]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 15 20:11:47 volumio-hall volumio[25592]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:47 volumio-hall volumio[25592]: info: Reloading queue from file Dec 15 20:11:47 volumio-hall volumio[25592]: info: VolumeController:: Volume=undefined Mute =false Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreStateMachine::pushState Dec 15 20:11:47 volumio-hall go-librespot[25654]: time="2025-12-15T20:11:47+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:11:47 volumio-hall volumio[25592]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioPushState Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreStateMachine::updateTrackBlock Dec 15 20:11:47 volumio-hall volumio[25592]: info: CorePlayQueue::getTrackBlock Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreStateMachine::setRepeat null single undefined Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreStateMachine::pushState Dec 15 20:11:47 volumio-hall volumio[25592]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioPushState Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreStateMachine::setRandom null Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreStateMachine::pushState Dec 15 20:11:47 volumio-hall volumio[25592]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioPushState Dec 15 20:11:47 volumio-hall volumio[25592]: info: Setting Device type: Raspberry PI Dec 15 20:11:47 volumio-hall volumio[25592]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 15 20:11:47 volumio-hall volumio[25592]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03112 Dec 15 20:11:47 volumio-hall volumio[25592]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 15 20:11:47 volumio-hall volumio[25592]: info: Completed loading Core Plugins Dec 15 20:11:47 volumio-hall volumio[25592]: info: Preparing to generate the ALSA configuration file Dec 15 20:11:47 volumio-hall volumio[25592]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 15 20:11:47 volumio-hall go-librespot[25654]: time="2025-12-15T20:11:47+05:30" level=debug msg="completed keyexchange" Dec 15 20:11:47 volumio-hall go-librespot[25654]: time="2025-12-15T20:11:47+05:30" level=debug msg="completed challenge" Dec 15 20:11:47 volumio-hall volumio[25592]: info: Asound.conf file unchanged, so no further update is needed Dec 15 20:11:47 volumio-hall volumio[25592]: info: Output device has changed, restarting MPD Dec 15 20:11:47 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:11:47] [connect] Successful connection Dec 15 20:11:47 volumio-hall volumio[25592]: info: Output device has changed, restarting Shairport Sync Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:47 volumio-hall sudo[25718]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 20:11:47 volumio-hall sudo[25718]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:47 volumio-hall sudo[25718]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:47 volumio-hall sudo[25720]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 20:11:47 volumio-hall sudo[25720]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:47 volumio-hall volumio[25592]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:11:47 volumio-hall volumio[25592]: info: ___________ START PLUGINS ___________ Dec 15 20:11:47 volumio-hall volumio[25592]: info: ControllerMpd::onStart: Initializing MPD Dec 15 20:11:47 volumio-hall volumio[25592]: info: Creating MPD Configuration file Dec 15 20:11:47 volumio-hall systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:11:47 volumio-hall volumio[25592]: info: [1765809707985] CoreMusicLibrary::Adding element Media Servers Dec 15 20:11:47 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:47 volumio-hall volumio[25592]: info: UPNP Browser: Client initialized successfully Dec 15 20:11:48 volumio-hall sudo[25728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 20:11:48 volumio-hall sudo[25728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:48 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:48 volumio-hall sudo[25730]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 20:11:48 volumio-hall sudo[25730]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:48 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:48 volumio-hall sudo[25728]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:48 volumio-hall systemd[1]: mpd.service: Deactivated successfully. Dec 15 20:11:48 volumio-hall sudo[25635]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:48 volumio-hall systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 20:11:48 volumio-hall systemd[1]: mpd.service: Consumed 2.542s CPU time. Dec 15 20:11:48 volumio-hall systemd[1]: mpd.socket: Deactivated successfully. Dec 15 20:11:48 volumio-hall volumio[25592]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:11:48 volumio-hall systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 20:11:48 volumio-hall systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 20:11:48 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:48 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:48 volumio-hall systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 20:11:48 volumio-hall systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 20:11:48 volumio-hall volumio[25592]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:11:48 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:11:48 volumio-hall volumio[25592]: info: [1765809708119] CoreMusicLibrary::Adding element Last_100 Dec 15 20:11:48 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:48 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:11:48 volumio-hall volumio[25592]: info: [1765809708126] CoreMusicLibrary::Adding element Webradio Dec 15 20:11:48 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:48 volumio-hall systemd[1]: mpd.service: Deactivated successfully. Dec 15 20:11:48 volumio-hall systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 20:11:48 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:11:48 volumio-hall systemd[1]: mpd.socket: Deactivated successfully. Dec 15 20:11:48 volumio-hall systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 20:11:48 volumio-hall systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 20:11:48 volumio-hall volumio[25592]: info: Initializing BBC Radios Dec 15 20:11:48 volumio-hall systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 20:11:48 volumio-hall systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 20:11:48 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:11:48 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:48 volumio-hall volumio[25592]: info: Creating Spotify config file Dec 15 20:11:48 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:48 volumio-hall sudo[25746]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 20:11:48 volumio-hall sudo[25746]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 20:11:48 volumio-hall sudo[25746]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:48 volumio-hall volumio[25592]: info: Volumio Calling Home Dec 15 20:11:48 volumio-hall volumio[25676]: Starting albumart workers Dec 15 20:11:48 volumio-hall volumio[25677]: Starting albumart workers Dec 15 20:11:48 volumio-hall volumio[25675]: Starting albumart workers Dec 15 20:11:48 volumio-hall volumio[25592]: info: VolumeController:: Volume=undefined Mute =false Dec 15 20:11:48 volumio-hall volumio[25592]: info: CoreStateMachine::pushState Dec 15 20:11:48 volumio-hall volumio[25592]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:48 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioPushState Dec 15 20:11:49 volumio-hall volumio[25592]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 15 20:11:49 volumio-hall volumio[25592]: info: MPD Permissions set Dec 15 20:11:49 volumio-hall volumio[25592]: info: MPD Permissions set Dec 15 20:11:49 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:11:49] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765809707 101 Dec 15 20:11:49 volumio-hall volumio[25592]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 4 Dec 15 20:11:49 volumio-hall volumio[25592]: info: Spotify config file written Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 20:11:49 volumio-hall volumio[25592]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall sudo[25767]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 20:11:49 volumio-hall sudo[25767]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 15 20:11:49 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:11:49 volumio-hall volumio[25592]: info: No need to fix Spotify hosts Dec 15 20:11:49 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:49 volumio-hall go-librespot[25776]: go-librespot daemon starting... Dec 15 20:11:49 volumio-hall sudo[25767]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:49 volumio-hall go-librespot[25786]: time="2025-12-15T20:11:49+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:49 volumio-hall go-librespot[25786]: time="2025-12-15T20:11:49+05:30" level=debug msg="app state loaded" Dec 15 20:11:49 volumio-hall go-librespot[25786]: time="2025-12-15T20:11:49+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:49 volumio-hall volumio[25592]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:49 volumio-hall volumio[25592]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 20:11:49 volumio-hall volumio[25592]: info: Received Get System Info Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 20:11:49 volumio-hall volumio[25592]: info: Discovery: Getting this device information Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:49 volumio-hall volumio[25592]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:49 volumio-hall volumio[25592]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:49 volumio-hall volumio[25592]: info: Listing playlists Dec 15 20:11:49 volumio-hall volumio[25592]: info: Starting Shairport Sync Dec 15 20:11:49 volumio-hall volumio[25592]: info: Starting Shairport Sync Dec 15 20:11:49 volumio-hall volumio[25592]: info: Starting Shairport Sync Dec 15 20:11:49 volumio-hall sudo[25801]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:11:49 volumio-hall sudo[25801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:49 volumio-hall go-librespot[25786]: time="2025-12-15T20:11:49+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:11:49 volumio-hall go-librespot[25786]: time="2025-12-15T20:11:49+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:11:49 volumio-hall go-librespot[25786]: time="2025-12-15T20:11:49+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:11:49 volumio-hall sudo[25805]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:11:49 volumio-hall go-librespot[25786]: time="2025-12-15T20:11:49+05:30" level=info msg="zeroconf server listening on port 44201" Dec 15 20:11:49 volumio-hall sudo[25805]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:49 volumio-hall systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 20:11:49 volumio-hall systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 20:11:49 volumio-hall sudo[25807]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:11:49 volumio-hall systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:11:49 volumio-hall systemd[1]: shairport-sync.service: Consumed 1.638s CPU time. Dec 15 20:11:49 volumio-hall sudo[25807]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:49 volumio-hall systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:11:49 volumio-hall sudo[25801]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:49 volumio-hall volumio[25592]: info: Discovery: adding 1e7f4238-4a59-44f1-ae5d-e6bcede79cfb Dec 15 20:11:49 volumio-hall volumio[25592]: info: Discovery: Found device Volumio-Hall Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:49 volumio-hall volumio[25592]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:49 volumio-hall systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 20:11:49 volumio-hall systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 20:11:49 volumio-hall go-librespot[25786]: time="2025-12-15T20:11:49+05:30" level=debug msg="obtained new client token: AACwClKk7TwZETwCb0LEt+LMWKeGTEkYhHSHMSXQtbvaSSwACnG55Gjp4At3vcDlTdxpWa+oujUluhPW1+OCa4Sg06/Xtg5PCDVlEOgv6ulZwoD2w+NKh7ZmhgBpHZpqUQE/pDMRflEgZmbQivkYMgJro6dO59L8xj5KYvL75Rq+z7p8tF0Vu6B2aCGUemGMBqf/ANBaWnZM7J+atJaxFxoODZ67aHTv03X6XdZcR2fRrTwzC3qDoFrSRQ==" Dec 15 20:11:49 volumio-hall systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:11:49 volumio-hall systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:11:49 volumio-hall sudo[25807]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:49 volumio-hall sudo[25805]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:49 volumio-hall volumio[25592]: info: Discovery: adding 21d80c26-f81b-4ba7-b7e4-77d93d8b8552 Dec 15 20:11:49 volumio-hall volumio[25592]: info: Discovery: Found device Volumio-Zero Dec 15 20:11:49 volumio-hall volumio[25592]: info: Discovery: Connecting to remote: 192.168.0.154 Dec 15 20:11:49 volumio-hall volumio[25592]: info: Discovery: this is already registered, 1e7f4238-4a59-44f1-ae5d-e6bcede79cfb Dec 15 20:11:49 volumio-hall volumio[25592]: info: Discovery: Found device Volumio-Hall Dec 15 20:11:49 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:49 volumio-hall volumio[25592]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:49 volumio-hall volumio[25592]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 20:11:49 volumio-hall volumio[25592]: SPOTIFY: BQCJ8y__UNahSkmgtVsbggqhVSCLQivMFiuv0zX1NAsscLX_KBavECO19-5zECdylo2UlUKkC5LSvaZvfLD_YqN6Dbib9_pFip13UHN7UkzrYrA8QXoljpX-YhTf0znvtH7ZM4bbPZlvG9yhawrEy2fDvlsjio-POeiP88g0kkaHIw62ftM-mi4VuvhPrhd3dXVQQNs8aLIqxTpqInRALpZVRZsY0Mnwy1gFgHI6HNfLPjgeTX955FAjsnxHIDrbx3NaFECT49B-OOf3XhrCA3xF3es5sOmyfd3mcKraBlv-kDosVmihEfzJIJr4 Dec 15 20:11:49 volumio-hall volumio[25592]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 20:11:49 volumio-hall volumio[25592]: info: New Spotify access token = BQCJ8y__UNahSkmgtVsbggqhVSCLQivMFiuv0zX1NAsscLX_KBavECO19-5zECdylo2UlUKkC5LSvaZvfLD_YqN6Dbib9_pFip13UHN7UkzrYrA8QXoljpX-YhTf0znvtH7ZM4bbPZlvG9yhawrEy2fDvlsjio-POeiP88g0kkaHIw62ftM-mi4VuvhPrhd3dXVQQNs8aLIqxTpqInRALpZVRZsY0Mnwy1gFgHI6HNfLPjgeTX955FAjsnxHIDrbx3NaFECT49B-OOf3XhrCA3xF3es5sOmyfd3mcKraBlv-kDosVmihEfzJIJr4 Dec 15 20:11:49 volumio-hall volumio[25592]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 20:11:49 volumio-hall go-librespot[25786]: time="2025-12-15T20:11:49+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:11:49 volumio-hall volumio[25592]: info: Shairport-Sync Started Dec 15 20:11:49 volumio-hall volumio[25592]: Error adding Membership: Error: addMembership EINVAL Dec 15 20:11:49 volumio-hall volumio[25592]: info: Shairport-Sync Started Dec 15 20:11:49 volumio-hall volumio[25592]: info: Shairport-Sync Started Dec 15 20:11:49 volumio-hall volumio[25592]: verbose: New Socket.io Connection to 192.168.0.144:3000 from 192.168.0.154 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 15 20:11:49 volumio-hall volumio[25592]: info: Discovery: Connected to remote: 192.168.0.154 Dec 15 20:11:50 volumio-hall go-librespot[25786]: time="2025-12-15T20:11:50+05:30" level=debug msg="completed keyexchange" Dec 15 20:11:50 volumio-hall go-librespot[25786]: time="2025-12-15T20:11:50+05:30" level=debug msg="completed challenge" Dec 15 20:11:50 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:50 volumio-hall volumio[25592]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:50 volumio-hall volumio[25592]: SPOTIFY: User informations: {"country":"IN","display_name":"31ounivl5lgdj7urtwg2tknrat4y","email":"post2skumar@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31ounivl5lgdj7urtwg2tknrat4y"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31ounivl5lgdj7urtwg2tknrat4y","id":"31ounivl5lgdj7urtwg2tknrat4y","images":[],"product":"premium","type":"user","uri":"spotify:user:31ounivl5lgdj7urtwg2tknrat4y"} Dec 15 20:11:50 volumio-hall volumio[25592]: info: Spotify Successfully logged in Dec 15 20:11:50 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:11:50 volumio-hall volumio[25592]: info: [1765809710152] CoreMusicLibrary::Adding element Spotify Dec 15 20:11:50 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:50 volumio-hall volumio[25592]: Cannot find translation for source Spotify Dec 15 20:11:50 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 15 20:11:50 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:50 volumio-hall volumio[25592]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:50 volumio-hall mpd[25760]: 2025-12-15T20:11:50 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 20:11:50 volumio-hall volumio[25592]: info: Cannot mount NAS AudioVideo at system boot, trial number 2 ,retrying in 5 seconds Dec 15 20:11:50 volumio-hall volumio[25592]: info: Volumio called home Dec 15 20:11:50 volumio-hall systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 20:11:50 volumio-hall sudo[25720]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:50 volumio-hall sudo[25730]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:50 volumio-hall volumio[25592]: info: Completed starting Core Plugins Dec 15 20:11:50 volumio-hall volumio[25592]: info: ------------------------------------------- Dec 15 20:11:50 volumio-hall volumio[25592]: info: ----- MyVolumio plugins startup ---- Dec 15 20:11:50 volumio-hall volumio[25592]: info: ------------------------------------------- Dec 15 20:11:50 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 20:11:50 volumio-hall volumio[25592]: error: MPD error: The expression evaluated to a falsy value: Dec 15 20:11:50 volumio-hall volumio[25592]: assert.ok(self.idling) Dec 15 20:11:50 volumio-hall volumio[25592]: error: The expression evaluated to a falsy value: Dec 15 20:11:50 volumio-hall volumio[25592]: assert.ok(self.idling) Dec 15 20:11:50 volumio-hall volumio[25592]: info: MPD running with PID25760 Dec 15 20:11:50 volumio-hall volumio[25592]: ,establishing connection Dec 15 20:11:50 volumio-hall volumio[25592]: error: updateQueue error: null Dec 15 20:11:50 volumio-hall volumio[25592]: error: updateQueue error: null Dec 15 20:11:50 volumio-hall volumio[25592]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Dec 15 20:11:50 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 20:11:50 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 20:11:50 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:11:50 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:50 volumio-hall volumio[25592]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:50 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:50 volumio-hall volumio[25592]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:50 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 20:11:50 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 20:11:50 volumio-hall volumio[25592]: info: Received Get System Info Dec 15 20:11:50 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 20:11:50 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 20:11:50 volumio-hall volumio[25592]: info: Discovery: Getting this device information Dec 15 20:11:50 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:50 volumio-hall volumio[25592]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:50 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 20:11:50 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioGetState Dec 15 20:11:50 volumio-hall volumio[25592]: info: CorePlayQueue::getTrack 0 Dec 15 20:11:50 volumio-hall volumio[25592]: info: Listing playlists Dec 15 20:11:51 volumio-hall go-librespot[25786]: time="2025-12-15T20:11:51+05:30" level=info msg="authenticated AP" username="31************************4y" Dec 15 20:11:52 volumio-hall volumio[25592]: info: go-librespot daemon successfully initialized Dec 15 20:11:53 volumio-hall sudo[25838]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 20:11:53 volumio-hall sudo[25838]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:53 volumio-hall sudo[25840]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 20:11:53 volumio-hall sudo[25840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:53 volumio-hall systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 20:11:53 volumio-hall systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 20:11:53 volumio-hall systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 20:11:53 volumio-hall systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 20:11:53 volumio-hall sudo[25840]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:53 volumio-hall sudo[25838]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:53 volumio-hall volumio[25592]: info: Successfully started MPD Monitor Dec 15 20:11:53 volumio-hall mpd_monitor.sh[25843]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 20:11:53 volumio-hall volumio[25592]: info: Successfully started MPD Monitor Dec 15 20:11:54 volumio-hall go-librespot[25786]: time="2025-12-15T20:11:54+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 20:11:54 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:11:54 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:11:55 volumio-hall volumio[25592]: info: Cannot mount NAS AudioVideo at system boot, trial number 3 ,retrying in 5 seconds Dec 15 20:11:55 volumio-hall sudo[25862]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 20:11:55 volumio-hall sudo[25862]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:55 volumio-hall sudo[25864]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 20:11:55 volumio-hall sudo[25864]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:55 volumio-hall sudo[25862]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:55 volumio-hall sudo[25864]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:55 volumio-hall sudo[25867]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 20:11:55 volumio-hall sudo[25867]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:11:55 volumio-hall sudo[25867]: pam_unix(sudo:session): session closed for user root Dec 15 20:11:55 volumio-hall volumio[25592]: info: Upmpdcli Daemon Started Dec 15 20:11:55 volumio-hall volumio[25592]: info: Initializing connection to go-librespot Websocket Dec 15 20:11:55 volumio-hall volumio[25592]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 20:11:55 volumio-hall volumio[25592]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 20:11:57 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 15 20:11:57 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:57 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:11:57 volumio-hall go-librespot[25870]: go-librespot daemon starting... Dec 15 20:11:57 volumio-hall go-librespot[25871]: time="2025-12-15T20:11:57+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:11:57 volumio-hall go-librespot[25871]: time="2025-12-15T20:11:57+05:30" level=debug msg="app state loaded" Dec 15 20:11:57 volumio-hall go-librespot[25871]: time="2025-12-15T20:11:57+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:11:57 volumio-hall go-librespot[25871]: time="2025-12-15T20:11:57+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:11:57 volumio-hall go-librespot[25871]: time="2025-12-15T20:11:57+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:11:57 volumio-hall go-librespot[25871]: time="2025-12-15T20:11:57+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:11:57 volumio-hall go-librespot[25871]: time="2025-12-15T20:11:57+05:30" level=info msg="zeroconf server listening on port 33249" Dec 15 20:11:57 volumio-hall go-librespot[25871]: time="2025-12-15T20:11:57+05:30" level=debug msg="obtained new client token: AABeIb6oyjtWaiw/Bs+5cb+mWxJ8bjpSCz69T1Z8uzRfFjvaaP8jawvtXiEc0xyrD4lOlKue85S3Z/ooaAqxLmlTumIMLOA6fvxA0DIOiDq3uHzSo/dsw/BmP4Psl0scSbAtwT5xGQBWUnH8EPmk0mJWepqhlIMwex2wGjQopGVufCERV/NnJ9TJDOMsbssLY61I9zDF8IEY9PPXUDjbK/r59Z4/9jeleQLDjUDgbd0hZoX1qix0NptDvA==" Dec 15 20:11:57 volumio-hall go-librespot[25871]: time="2025-12-15T20:11:57+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:11:57 volumio-hall go-librespot[25871]: time="2025-12-15T20:11:57+05:30" level=debug msg="completed keyexchange" Dec 15 20:11:57 volumio-hall go-librespot[25871]: time="2025-12-15T20:11:57+05:30" level=debug msg="completed challenge" Dec 15 20:11:58 volumio-hall volumio[25592]: Cannot compose Albumart path Dec 15 20:11:58 volumio-hall go-librespot[25871]: time="2025-12-15T20:11:58+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 20:11:58 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:11:58 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:11:58 volumio-hall volumio[25592]: info: Initializing connection to go-librespot Websocket Dec 15 20:11:58 volumio-hall volumio[25592]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 20:11:59 volumio-hall volumio[25592]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 20:11:59 volumio-hall volumio[25592]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 20:11:59 volumio-hall volumio[25592]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 20:11:59 volumio-hall volumio[25592]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 20:11:59 volumio-hall volumio[25592]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 20:11:59 volumio-hall volumio[25592]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 20:11:59 volumio-hall volumio[25592]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 20:11:59 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:59 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:11:59 volumio-hall volumio[25592]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 20:11:59 volumio-hall volumio[25592]: info: MyVolumio login type: Token Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 20:11:59 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 20:12:00 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 20:12:00 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 20:12:00 volumio-hall volumio[25592]: info: Streaming services startup Dec 15 20:12:00 volumio-hall volumio[25592]: info: Starting Streaming Daemon Dec 15 20:12:00 volumio-hall sudo[25880]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 20:12:00 volumio-hall sudo[25880]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:00 volumio-hall volumio[25592]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 20:12:00 volumio-hall sudo[25880]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:00 volumio-hall volumio[25592]: error: Cannot start Volumio Streaming Daemon Dec 15 20:12:00 volumio-hall volumio[25592]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 20:12:00 volumio-hall volumio[25592]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 20:12:00 volumio-hall volumio[25592]: info: Cannot mount NAS AudioVideo at system boot, trial number 4 ,retrying in 5 seconds Dec 15 20:12:01 volumio-hall volumio[25592]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 20:12:01 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 20:12:01 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:12:01 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:12:01 volumio-hall go-librespot[25886]: go-librespot daemon starting... Dec 15 20:12:01 volumio-hall go-librespot[25887]: time="2025-12-15T20:12:01+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:12:01 volumio-hall go-librespot[25887]: time="2025-12-15T20:12:01+05:30" level=debug msg="app state loaded" Dec 15 20:12:01 volumio-hall go-librespot[25887]: time="2025-12-15T20:12:01+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:12:01 volumio-hall volumio[25592]: info: Initializing connection to go-librespot Websocket Dec 15 20:12:01 volumio-hall go-librespot[25887]: time="2025-12-15T20:12:01+05:30" level=debug msg="new websocket client" Dec 15 20:12:01 volumio-hall volumio[25592]: info: Connection to go-librespot Websocket established Dec 15 20:12:01 volumio-hall go-librespot[25887]: time="2025-12-15T20:12:01+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Dec 15 20:12:01 volumio-hall go-librespot[25887]: time="2025-12-15T20:12:01+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Dec 15 20:12:01 volumio-hall go-librespot[25887]: time="2025-12-15T20:12:01+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Dec 15 20:12:01 volumio-hall go-librespot[25887]: time="2025-12-15T20:12:01+05:30" level=info msg="zeroconf server listening on port 36591" Dec 15 20:12:01 volumio-hall volumio[25592]: info: MyVolumio token set successfully Dec 15 20:12:01 volumio-hall volumio[25592]: info: MYVOLUMIO: Adding device Dec 15 20:12:01 volumio-hall volumio[25592]: info: MYVOLUMIO: Evaluating Server Dec 15 20:12:01 volumio-hall go-librespot[25887]: time="2025-12-15T20:12:01+05:30" level=debug msg="obtained new client token: AAA7JO6DHdATvOTKLJd1ZDe6NjcxI3+uuh+XU9KIEyAAJaM38jQ+Ywt7flESslUh8+Y/IewW2Efs6pbvZdYQgyfDo3LsmDpFNkiGfDNJP7IxyQIHqGUSzg2cMNactDrbG9La+VWp/j1hV47u6a+Q2FPWXNcQyyZLcOWw/3wLrLBHblTBlXwjNjtARcrEX2sMo/C/Jlt6EycGTdYSgbaaznh6175Mz+EGU2BKNIwDp3MWjPNvQbRH6eA55w==" Dec 15 20:12:01 volumio-hall go-librespot[25887]: time="2025-12-15T20:12:01+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:12:02 volumio-hall go-librespot[25887]: time="2025-12-15T20:12:02+05:30" level=debug msg="completed keyexchange" Dec 15 20:12:02 volumio-hall go-librespot[25887]: time="2025-12-15T20:12:02+05:30" level=debug msg="completed challenge" Dec 15 20:12:02 volumio-hall volumio[25592]: info: MyVolumio status changed Dec 15 20:12:02 volumio-hall volumio[25592]: info: Streaming services startup Dec 15 20:12:02 volumio-hall volumio[25592]: info: Starting Streaming Daemon Dec 15 20:12:02 volumio-hall volumio[25592]: info: Removing browser output: myVolumio user plan is not superstar Dec 15 20:12:02 volumio-hall volumio[25592]: info: Removing audio output: Dec 15 20:12:02 volumio-hall volumio[25592]: info: Stoppping Tunnel 1 Dec 15 20:12:02 volumio-hall sudo[25915]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 20:12:02 volumio-hall sudo[25915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:02 volumio-hall sudo[25917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 15 20:12:02 volumio-hall sudo[25917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:02 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:12:02 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:12:02 volumio-hall sudo[25915]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:02 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:12:02 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:12:02 volumio-hall volumio[25592]: error: Cannot start Volumio Streaming Daemon Dec 15 20:12:02 volumio-hall volumio[25592]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 20:12:02 volumio-hall volumio[25592]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 20:12:02 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:12:02 volumio-hall systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 15 20:12:02 volumio-hall sudo[25917]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:02 volumio-hall volumio[25592]: info: Remote SSH Stopped Dec 15 20:12:03 volumio-hall go-librespot[25887]: time="2025-12-15T20:12:03+05:30" level=info msg="authenticated AP" username="31************************4y" Dec 15 20:12:03 volumio-hall volumio[25592]: info: Setting Geolocation for MyVolumio to as2 Dec 15 20:12:03 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:12:03 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:12:03 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:12:03 volumio-hall volumio[25592]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 15 20:12:04 volumio-hall volumio[25592]: info: Updating MyVolumio device info Dec 15 20:12:04 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:12:04 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:12:04 volumio-hall volumio[25592]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:12:04 volumio-hall volumio[25592]: info: Getting Spotify volume Dec 15 20:12:04 volumio-hall volumio[25592]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 15 20:12:04 volumio-hall volumio[25592]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 15 20:12:04 volumio-hall volumio[25592]: info: CoreCommandRouter::volumioGetState Dec 15 20:12:04 volumio-hall volumio[25592]: info: CorePlayQueue::getTrack 0 Dec 15 20:12:05 volumio-hall go-librespot[25887]: time="2025-12-15T20:12:05+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 20:12:05 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:12:05 volumio-hall volumio[25592]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 20:12:05 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:12:05 volumio-hall volumio[25592]: Error: socket hang up Dec 15 20:12:05 volumio-hall volumio[25592]: at connResetException (node:internal/errors:720:14) Dec 15 20:12:05 volumio-hall volumio[25592]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 15 20:12:05 volumio-hall volumio[25592]: at Socket.emit (node:events:526:35) Dec 15 20:12:05 volumio-hall volumio[25592]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 15 20:12:05 volumio-hall volumio[25592]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 15 20:12:05 volumio-hall volumio[25592]: code: 'ECONNRESET', Dec 15 20:12:05 volumio-hall volumio[25592]: response: undefined Dec 15 20:12:05 volumio-hall volumio[25592]: } Dec 15 20:12:05 volumio-hall volumio[25592]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 20:12:05 volumio-hall sudo[25934]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 20:11' Dec 15 20:12:05 volumio-hall sudo[25934]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:05 volumio-hall sudo[25934]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:06 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:12:06] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 15 20:12:06 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:12:06] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 15 20:12:06 volumio-hall systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:12:06 volumio-hall systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 15 20:12:06 volumio-hall systemd[1]: volumio.service: Consumed 21.659s CPU time. Dec 15 20:12:06 volumio-hall systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 20:12:06 volumio-hall systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 20:12:06 volumio-hall systemd[1]: volumio.service: Scheduled restart job, restart counter is at 64. Dec 15 20:12:06 volumio-hall systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 20:12:06 volumio-hall systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 15 20:12:06 volumio-hall systemd[1]: volumio.service: Consumed 21.659s CPU time. Dec 15 20:12:06 volumio-hall systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 20:12:06 volumio-hall systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 20:12:07 volumio-hall volumio[25966]: info: ------------------------------------------- Dec 15 20:12:07 volumio-hall volumio[25966]: info: ----- Volumio3 ---- Dec 15 20:12:07 volumio-hall volumio[25966]: info: ------------------------------------------- Dec 15 20:12:07 volumio-hall volumio[25966]: info: ----- System startup ---- Dec 15 20:12:07 volumio-hall volumio[25966]: info: ------------------------------------------- Dec 15 20:12:08 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 15 20:12:08 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:12:08 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:12:08 volumio-hall volumio[25966]: info: MYVOLUMIO Environment detected Dec 15 20:12:08 volumio-hall go-librespot[25987]: go-librespot daemon starting... Dec 15 20:12:08 volumio-hall go-librespot[25991]: time="2025-12-15T20:12:08+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:12:08 volumio-hall go-librespot[25991]: time="2025-12-15T20:12:08+05:30" level=debug msg="app state loaded" Dec 15 20:12:08 volumio-hall go-librespot[25991]: time="2025-12-15T20:12:08+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:12:08 volumio-hall volumio[25966]: info: Plugin folders cleanup Dec 15 20:12:08 volumio-hall volumio[25966]: info: Scanning into folder /volumio/app/plugins/ Dec 15 20:12:08 volumio-hall volumio[25966]: info: Scanning category audio_interface Dec 15 20:12:08 volumio-hall volumio[25966]: info: Scanning category miscellanea Dec 15 20:12:08 volumio-hall volumio[25966]: info: Scanning category music_service Dec 15 20:12:08 volumio-hall volumio[25966]: info: Scanning category plugins.json Dec 15 20:12:08 volumio-hall volumio[25966]: info: Scanning category system_controller Dec 15 20:12:08 volumio-hall volumio[25966]: info: Scanning category user_interface Dec 15 20:12:08 volumio-hall volumio[25966]: info: Scanning into folder /data/plugins/ Dec 15 20:12:08 volumio-hall volumio[25966]: info: Scanning category music_service Dec 15 20:12:08 volumio-hall volumio[25966]: info: Plugin folders cleanup completed Dec 15 20:12:08 volumio-hall volumio[25966]: info: ------------------------------------------- Dec 15 20:12:08 volumio-hall volumio[25966]: info: ----- Core plugins startup ---- Dec 15 20:12:08 volumio-hall volumio[25966]: info: ------------------------------------------- Dec 15 20:12:08 volumio-hall volumio[25966]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 20:12:08 volumio-hall volumio[25966]: info: Adding plugin upnp to MyMusic Plugins Dec 15 20:12:08 volumio-hall volumio[25966]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 20:12:08 volumio-hall volumio[25966]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 20:12:08 volumio-hall volumio[25966]: info: Loading plugins from folder /data/plugins/ Dec 15 20:12:08 volumio-hall volumio[25966]: info: Loading plugin "system"... Dec 15 20:12:08 volumio-hall volumio[25966]: info: Loading plugin "appearance"... Dec 15 20:12:08 volumio-hall go-librespot[25991]: time="2025-12-15T20:12:08+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:12:08 volumio-hall go-librespot[25991]: time="2025-12-15T20:12:08+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:12:08 volumio-hall go-librespot[25991]: time="2025-12-15T20:12:08+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:12:08 volumio-hall go-librespot[25991]: time="2025-12-15T20:12:08+05:30" level=info msg="zeroconf server listening on port 41089" Dec 15 20:12:08 volumio-hall go-librespot[25991]: time="2025-12-15T20:12:08+05:30" level=debug msg="obtained new client token: AAA5/jz+DOqEt9x1XQPqi8nNWNjJmRYa4y0a981WuASeSDqkk5BionK3pe9MSPxw2yt7Zij40PPSxDUOrBxJqymhGzP4qNZ9QtVch+U9+zJPt96pMKQs7tNyLPFmWyDlf3dpIfDqSWpEB7I1Vl0cYkNUcZ4hCHixJIusHp/FSM4HMpD05hG2sc4qelOXxK/I7Id2guCgolY9uwvykB0J42/jjJCEJWWHGO0GwukcXSU5gmfujLydRtRE5w==" Dec 15 20:12:08 volumio-hall go-librespot[25991]: time="2025-12-15T20:12:08+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:12:08 volumio-hall go-librespot[25991]: time="2025-12-15T20:12:08+05:30" level=debug msg="completed keyexchange" Dec 15 20:12:08 volumio-hall go-librespot[25991]: time="2025-12-15T20:12:08+05:30" level=debug msg="completed challenge" Dec 15 20:12:08 volumio-hall volumio[25966]: info: Loading plugin "network"... Dec 15 20:12:08 volumio-hall volumio[25966]: info: Refreshing Cached IP Addresses Dec 15 20:12:08 volumio-hall sudo[26003]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 20:12:08 volumio-hall sudo[26003]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:08 volumio-hall sudo[26003]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:08 volumio-hall sudo[26005]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 20:12:08 volumio-hall sudo[26005]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:08 volumio-hall sudo[26005]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:08 volumio-hall volumio[25966]: info: Loading plugin "services"... Dec 15 20:12:08 volumio-hall volumio[25966]: info: Loading plugin "alsa_controller"... Dec 15 20:12:09 volumio-hall sudo[26014]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 15 20:12:09 volumio-hall sudo[26014]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:09 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:12:09 volumio-hall volumio[25966]: info: Loading plugin "wizard"... Dec 15 20:12:09 volumio-hall volumio[25966]: info: Loading plugin "networkfs"... Dec 15 20:12:09 volumio-hall volumio[25966]: info: Cannot mount NAS AudioVideo at system boot, trial number 1 ,retrying in 5 seconds Dec 15 20:12:09 volumio-hall volumio[25966]: info: Starting Udev Watcher for removable devices Dec 15 20:12:09 volumio-hall volumio[25966]: info: Ignoring mount for partition: boot Dec 15 20:12:09 volumio-hall volumio[25966]: info: Ignoring mount for partition: volumio Dec 15 20:12:09 volumio-hall volumio[25966]: info: Ignoring mount for partition: volumio_data Dec 15 20:12:09 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:12:09 volumio-hall volumio[25966]: info: Loading plugin "volumio_command_line_client"... Dec 15 20:12:09 volumio-hall volumio[25966]: info: Loading plugin "upnp"... Dec 15 20:12:09 volumio-hall volumio[25966]: info: [1765809729089] Starting Upmpd Daemon Dec 15 20:12:09 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:12:09 volumio-hall volumio[25966]: info: Loading plugin "my_music"... Dec 15 20:12:09 volumio-hall volumio[25966]: info: Loading plugin "mpd"... Dec 15 20:12:09 volumio-hall volumio[25966]: info: Loading plugin "upnp_browser"... Dec 15 20:12:09 volumio-hall go-librespot[25991]: time="2025-12-15T20:12:09+05:30" level=info msg="authenticated AP" username="31************************4y" Dec 15 20:12:10 volumio-hall volumio[25966]: info: Starting UPNP Browser Dec 15 20:12:10 volumio-hall volumio[25966]: info: Loading plugin "alarm-clock"... Dec 15 20:12:10 volumio-hall volumio[25966]: info: Loading plugin "airplay_emulation"... Dec 15 20:12:10 volumio-hall volumio[25966]: info: Starting Shairport Sync Dec 15 20:12:10 volumio-hall volumio[25966]: info: Loading plugin "last_100"... Dec 15 20:12:10 volumio-hall volumio[25966]: info: Loading plugin "webradio"... Dec 15 20:12:10 volumio-hall volumio[25966]: info: Loading plugin "i2s_dacs"... Dec 15 20:12:10 volumio-hall volumio[25966]: info: Loading plugin "volumiodiscovery"... Dec 15 20:12:10 volumio-hall go-librespot[25991]: time="2025-12-15T20:12:10+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 20:12:10 volumio-hall volumio[25966]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 20:12:10 volumio-hall volumio[25966]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:12:10 volumio-hall volumio[25966]: *** WARNING *** For more information see Dec 15 20:12:10 volumio-hall volumio[25966]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 20:12:10 volumio-hall volumio[25966]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:12:10 volumio-hall volumio[25966]: *** WARNING *** For more information see Dec 15 20:12:10 volumio-hall volumio[25966]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 20:12:10 volumio-hall node[25966]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 20:12:10 volumio-hall node[25966]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:12:10 volumio-hall node[25966]: *** WARNING *** For more information see Dec 15 20:12:10 volumio-hall node[25966]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 15 20:12:10 volumio-hall node[25966]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 20:12:10 volumio-hall node[25966]: *** WARNING *** For more information see Dec 15 20:12:10 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:12:10 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:12:10 volumio-hall volumio[25966]: info: Discovery: Started advertising with name: Volumio-Hall Dec 15 20:12:10 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 20:12:10 volumio-hall volumio[25966]: info: Loading plugin "spop"... Dec 15 20:12:10 volumio-hall volumio[25966]: info: Loading plugin "outputs"... Dec 15 20:12:10 volumio-hall volumio[25966]: info: Loading plugin "albumart"... Dec 15 20:12:10 volumio-hall volumio[25966]: info: Plugin example_plugin is not enabled Dec 15 20:12:10 volumio-hall volumio[25966]: info: Loading plugin "inputs"... Dec 15 20:12:10 volumio-hall volumio[25966]: info: Loading plugin "updater_comm"... Dec 15 20:12:10 volumio-hall volumio[25966]: info: Plugin mpdemulation is not enabled Dec 15 20:12:10 volumio-hall volumio[25966]: info: Loading plugin "rest_api"... Dec 15 20:12:10 volumio-hall volumio[25966]: info: Loading plugin "websocket"... Dec 15 20:12:10 volumio-hall volumio[25966]: info: Starting Socket.io Server version 1.7.4 Dec 15 20:12:10 volumio-hall volumio[25966]: info: Loading i18n strings for locale en Dec 15 20:12:10 volumio-hall volumio[25966]: Updating browse sources language Dec 15 20:12:10 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::initPlayerControls Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:12:11 volumio-hall volumio[25966]: Express server listening on port 3000 Dec 15 20:12:11 volumio-hall volumio[25966]: [Metrics] WebUI: 3s 480.54ms Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreStateMachine::resetVolumioState Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreStateMachine::getcurrentVolume Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 20:12:11 volumio-hall volumio[25966]: info: Volumio Network Manager: Network status updated: 1 Dec 15 20:12:11 volumio-hall volumio[26036]: Forking 3 albumart workers Dec 15 20:12:11 volumio-hall volumio[25966]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Dec 15 20:12:11 volumio-hall volumio[25966]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 15 20:12:11 volumio-hall volumio[25966]: verbose: New Socket.io Connection to 192.168.0.144:3000 from 192.168.0.154 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:12:11 volumio-hall volumio[25966]: info: Reloading queue from file Dec 15 20:12:11 volumio-hall volumio[25966]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Dec 15 20:12:11 volumio-hall volumio[25966]: info: VolumeController:: Volume=undefined Mute =false Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreStateMachine::pushState Dec 15 20:12:11 volumio-hall volumio[25966]: info: CorePlayQueue::getTrack 0 Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioPushState Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreStateMachine::updateTrackBlock Dec 15 20:12:11 volumio-hall volumio[25966]: info: CorePlayQueue::getTrackBlock Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreStateMachine::setRepeat null single undefined Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreStateMachine::pushState Dec 15 20:12:11 volumio-hall volumio[25966]: info: CorePlayQueue::getTrack 0 Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioPushState Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreStateMachine::setRandom null Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreStateMachine::pushState Dec 15 20:12:11 volumio-hall volumio[25966]: info: CorePlayQueue::getTrack 0 Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioPushState Dec 15 20:12:11 volumio-hall volumio[25966]: info: Setting Device type: Raspberry PI Dec 15 20:12:11 volumio-hall volumio[25966]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Dec 15 20:12:11 volumio-hall volumio[25966]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03112 Dec 15 20:12:11 volumio-hall volumio[25966]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Dec 15 20:12:11 volumio-hall volumio[25966]: info: Completed loading Core Plugins Dec 15 20:12:11 volumio-hall volumio[25966]: info: Preparing to generate the ALSA configuration file Dec 15 20:12:11 volumio-hall volumio[25966]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Dec 15 20:12:11 volumio-hall volumio[25966]: info: VolumeController:: Volume=undefined Mute =false Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreStateMachine::pushState Dec 15 20:12:11 volumio-hall volumio[25966]: info: CorePlayQueue::getTrack 0 Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioPushState Dec 15 20:12:11 volumio-hall volumio[25966]: info: Asound.conf file unchanged, so no further update is needed Dec 15 20:12:11 volumio-hall volumio[25966]: info: Output device has changed, restarting MPD Dec 15 20:12:11 volumio-hall volumio[25966]: info: Output device has changed, restarting Shairport Sync Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:12:11 volumio-hall sudo[26093]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 20:12:11 volumio-hall sudo[26093]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:11 volumio-hall sudo[26093]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:11 volumio-hall sudo[26095]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 20:12:11 volumio-hall sudo[26095]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:11 volumio-hall volumio[25966]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:12:11 volumio-hall volumio[25966]: info: ___________ START PLUGINS ___________ Dec 15 20:12:11 volumio-hall volumio[25966]: info: ControllerMpd::onStart: Initializing MPD Dec 15 20:12:11 volumio-hall volumio[25966]: info: Creating MPD Configuration file Dec 15 20:12:11 volumio-hall systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 20:12:11 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:12:11] [connect] Successful connection Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:12:11 volumio-hall volumio[25966]: info: [1765809731554] CoreMusicLibrary::Adding element Media Servers Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:12:11 volumio-hall sudo[26103]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 20:12:11 volumio-hall sudo[26105]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 20:12:11 volumio-hall sudo[26103]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:11 volumio-hall sudo[26105]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:11 volumio-hall volumio[25966]: info: UPNP Browser: Client initialized successfully Dec 15 20:12:11 volumio-hall sudo[26103]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:11 volumio-hall systemd[1]: mpd.service: Deactivated successfully. Dec 15 20:12:11 volumio-hall systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 20:12:11 volumio-hall systemd[1]: mpd.service: Consumed 2.563s CPU time. Dec 15 20:12:11 volumio-hall systemd[1]: mpd.socket: Deactivated successfully. Dec 15 20:12:11 volumio-hall systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 20:12:11 volumio-hall systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 20:12:11 volumio-hall sudo[26014]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:12:11 volumio-hall volumio[25966]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:12:11 volumio-hall systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 20:12:11 volumio-hall systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 20:12:11 volumio-hall volumio[25966]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:12:11 volumio-hall volumio[25966]: info: [1765809731690] CoreMusicLibrary::Adding element Last_100 Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:12:11 volumio-hall volumio[25966]: info: [1765809731697] CoreMusicLibrary::Adding element Webradio Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:12:11 volumio-hall volumio[25966]: info: Initializing BBC Radios Dec 15 20:12:11 volumio-hall systemd[1]: mpd.service: Deactivated successfully. Dec 15 20:12:11 volumio-hall systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 20:12:11 volumio-hall systemd[1]: mpd.socket: Deactivated successfully. Dec 15 20:12:11 volumio-hall systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 20:12:11 volumio-hall systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 20:12:11 volumio-hall systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 20:12:11 volumio-hall systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:12:11 volumio-hall volumio[25966]: info: Creating Spotify config file Dec 15 20:12:11 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:11 volumio-hall sudo[26124]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 20:12:11 volumio-hall sudo[26124]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 20:12:11 volumio-hall sudo[26124]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:12 volumio-hall volumio[26050]: Starting albumart workers Dec 15 20:12:12 volumio-hall volumio[25966]: info: Volumio Calling Home Dec 15 20:12:12 volumio-hall volumio[26051]: Starting albumart workers Dec 15 20:12:12 volumio-hall volumio[26052]: Starting albumart workers Dec 15 20:12:12 volumio-hall volumio[25966]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Dec 15 20:12:12 volumio-hall volumio[25966]: info: MPD Permissions set Dec 15 20:12:12 volumio-hall volumio[25966]: info: MPD Permissions set Dec 15 20:12:12 volumio-hall volumio-remote-updater[711]: [2025-12-15 20:12:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765809731 101 Dec 15 20:12:12 volumio-hall volumio[25966]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 5 Dec 15 20:12:12 volumio-hall volumio[25966]: info: Spotify config file written Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 20:12:12 volumio-hall volumio[25966]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:12:12 volumio-hall sudo[26141]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall sudo[26141]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 20:12:12 volumio-hall volumio[25966]: info: No need to fix Spotify hosts Dec 15 20:12:12 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:12:12 volumio-hall go-librespot[26153]: go-librespot daemon starting... Dec 15 20:12:12 volumio-hall sudo[26141]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:12 volumio-hall go-librespot[26154]: time="2025-12-15T20:12:12+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:12:12 volumio-hall go-librespot[26154]: time="2025-12-15T20:12:12+05:30" level=debug msg="app state loaded" Dec 15 20:12:12 volumio-hall go-librespot[26154]: time="2025-12-15T20:12:12+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioGetState Dec 15 20:12:12 volumio-hall volumio[25966]: info: CorePlayQueue::getTrack 0 Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioGetState Dec 15 20:12:12 volumio-hall volumio[25966]: info: CorePlayQueue::getTrack 0 Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 20:12:12 volumio-hall volumio[25966]: info: Received Get System Info Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 20:12:12 volumio-hall volumio[25966]: info: Discovery: Getting this device information Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioGetState Dec 15 20:12:12 volumio-hall volumio[25966]: info: CorePlayQueue::getTrack 0 Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 20:12:12 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioGetState Dec 15 20:12:12 volumio-hall volumio[25966]: info: CorePlayQueue::getTrack 0 Dec 15 20:12:12 volumio-hall volumio[25966]: info: Listing playlists Dec 15 20:12:13 volumio-hall volumio[25966]: info: Volumio called home Dec 15 20:12:13 volumio-hall volumio[25966]: info: Starting Shairport Sync Dec 15 20:12:13 volumio-hall volumio[25966]: info: Starting Shairport Sync Dec 15 20:12:13 volumio-hall volumio[25966]: info: Starting Shairport Sync Dec 15 20:12:13 volumio-hall go-librespot[26154]: time="2025-12-15T20:12:13+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:12:13 volumio-hall go-librespot[26154]: time="2025-12-15T20:12:13+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:12:13 volumio-hall go-librespot[26154]: time="2025-12-15T20:12:13+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:12:13 volumio-hall go-librespot[26154]: time="2025-12-15T20:12:13+05:30" level=info msg="zeroconf server listening on port 35449" Dec 15 20:12:13 volumio-hall sudo[26172]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:12:13 volumio-hall sudo[26172]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:13 volumio-hall sudo[26169]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:12:13 volumio-hall sudo[26169]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:13 volumio-hall sudo[26173]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Dec 15 20:12:13 volumio-hall sudo[26173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:13 volumio-hall systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 20:12:13 volumio-hall systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 20:12:13 volumio-hall systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:12:13 volumio-hall systemd[1]: shairport-sync.service: Consumed 1.700s CPU time. Dec 15 20:12:13 volumio-hall volumio[25966]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 20:12:13 volumio-hall volumio[25966]: SPOTIFY: BQBBGglbRMf6epa-LZtxlUor_3jZQlrg8gBz1WZtBZrBBDEjcdmzm0eepsXfjt8vDzOqPB9-8lNIkdawq2wIU64yzIy0cgJVHCNO4efPxAy3AKdb6VJJHQM4ZtqYbRuLL-8vq21G0woMbiRHFG_8zACSSGf6kbCZxzI3IEWaRphNupmMp-XDDzF_efo6JviqoPiszJ245CyYa3ywKBrnzRN2hOaCVyv5i8UDbwT967pAyRiznbFz4IfJmd_xg8LUTQ1Y1b1siOdVeBpM_0YUZ4Ab9sT44-8WvjRAUyiOTOfVw4r8fBP54pVgzus- Dec 15 20:12:13 volumio-hall volumio[25966]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 20:12:13 volumio-hall volumio[25966]: info: New Spotify access token = BQBBGglbRMf6epa-LZtxlUor_3jZQlrg8gBz1WZtBZrBBDEjcdmzm0eepsXfjt8vDzOqPB9-8lNIkdawq2wIU64yzIy0cgJVHCNO4efPxAy3AKdb6VJJHQM4ZtqYbRuLL-8vq21G0woMbiRHFG_8zACSSGf6kbCZxzI3IEWaRphNupmMp-XDDzF_efo6JviqoPiszJ245CyYa3ywKBrnzRN2hOaCVyv5i8UDbwT967pAyRiznbFz4IfJmd_xg8LUTQ1Y1b1siOdVeBpM_0YUZ4Ab9sT44-8WvjRAUyiOTOfVw4r8fBP54pVgzus- Dec 15 20:12:13 volumio-hall volumio[25966]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 20:12:13 volumio-hall systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:12:13 volumio-hall sudo[26169]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:13 volumio-hall go-librespot[26154]: time="2025-12-15T20:12:13+05:30" level=debug msg="obtained new client token: AACBLImuHnvEfcCDgYwP4GneEaG1jHBv7GyI0ixFcWYp8XqWDYwGovbHnb7R94JkILG8arCgeb1n1FOQNvL+mpJNXn4HpbO/19TyuzxGa4zCODJaMwk+5ga45DFMtf4dYlIxaH3+3TxaM1TqAC4zFmQYJOcx18YFHroAVXeSrJlLoDJ2iRFKKoq+1nKAHyIroYm8H3zuGsAKphMrDu0sxIhXx+eEt+BWhmKGUp1SQHfIr4BVCKX1Yv8=" Dec 15 20:12:13 volumio-hall systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Dec 15 20:12:13 volumio-hall systemd[1]: shairport-sync.service: Deactivated successfully. Dec 15 20:12:13 volumio-hall systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:12:13 volumio-hall systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Dec 15 20:12:13 volumio-hall sudo[26172]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:13 volumio-hall go-librespot[26154]: time="2025-12-15T20:12:13+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:12:13 volumio-hall sudo[26173]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:13 volumio-hall volumio[25966]: info: Shairport-Sync Started Dec 15 20:12:13 volumio-hall volumio[25966]: Error adding Membership: Error: addMembership EINVAL Dec 15 20:12:13 volumio-hall volumio[25966]: info: Shairport-Sync Started Dec 15 20:12:13 volumio-hall go-librespot[26154]: time="2025-12-15T20:12:13+05:30" level=debug msg="completed keyexchange" Dec 15 20:12:13 volumio-hall go-librespot[26154]: time="2025-12-15T20:12:13+05:30" level=debug msg="completed challenge" Dec 15 20:12:13 volumio-hall volumio[25966]: info: Shairport-Sync Started Dec 15 20:12:13 volumio-hall mpd[26136]: 2025-12-15T20:12:13 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 20:12:14 volumio-hall volumio[25966]: info: Cannot mount NAS AudioVideo at system boot, trial number 2 ,retrying in 5 seconds Dec 15 20:12:14 volumio-hall systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 20:12:14 volumio-hall sudo[26105]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:14 volumio-hall sudo[26095]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:14 volumio-hall volumio[25966]: info: Completed starting Core Plugins Dec 15 20:12:14 volumio-hall volumio[25966]: info: ------------------------------------------- Dec 15 20:12:14 volumio-hall volumio[25966]: info: ----- MyVolumio plugins startup ---- Dec 15 20:12:14 volumio-hall volumio[25966]: info: ------------------------------------------- Dec 15 20:12:14 volumio-hall volumio[25966]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 20:12:14 volumio-hall volumio[25966]: error: MPD error: The expression evaluated to a falsy value: Dec 15 20:12:14 volumio-hall volumio[25966]: assert.ok(self.idling) Dec 15 20:12:14 volumio-hall volumio[25966]: error: The expression evaluated to a falsy value: Dec 15 20:12:14 volumio-hall volumio[25966]: assert.ok(self.idling) Dec 15 20:12:14 volumio-hall volumio[25966]: verbose: New Socket.io Connection to 192.168.0.144 from 192.168.0.172 UA: Mozilla/5.0 (X11; CrOS x86_64 14541.0.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Dec 15 20:12:14 volumio-hall volumio[25966]: info: MPD running with PID26136 Dec 15 20:12:14 volumio-hall volumio[25966]: ,establishing connection Dec 15 20:12:14 volumio-hall volumio[25966]: error: updateQueue error: null Dec 15 20:12:14 volumio-hall volumio[25966]: error: updateQueue error: null Dec 15 20:12:14 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 15 20:12:14 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 20:12:14 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:12:14 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioGetState Dec 15 20:12:14 volumio-hall volumio[25966]: info: CorePlayQueue::getTrack 0 Dec 15 20:12:14 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioGetState Dec 15 20:12:14 volumio-hall volumio[25966]: info: CorePlayQueue::getTrack 0 Dec 15 20:12:14 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 15 20:12:14 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 20:12:14 volumio-hall volumio[25966]: info: Received Get System Info Dec 15 20:12:14 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 15 20:12:14 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 15 20:12:14 volumio-hall volumio[25966]: info: Discovery: Getting this device information Dec 15 20:12:14 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioGetState Dec 15 20:12:14 volumio-hall volumio[25966]: info: CorePlayQueue::getTrack 0 Dec 15 20:12:14 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 15 20:12:14 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioGetState Dec 15 20:12:14 volumio-hall volumio[25966]: info: CorePlayQueue::getTrack 0 Dec 15 20:12:14 volumio-hall volumio[25966]: info: Listing playlists Dec 15 20:12:14 volumio-hall go-librespot[26154]: time="2025-12-15T20:12:14+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 20:12:14 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:12:14 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:12:16 volumio-hall volumio[25966]: info: Discovery: adding 21d80c26-f81b-4ba7-b7e4-77d93d8b8552 Dec 15 20:12:16 volumio-hall volumio[25966]: info: Discovery: Found device Volumio-Zero Dec 15 20:12:16 volumio-hall volumio[25966]: info: Discovery: Connecting to remote: 192.168.0.154 Dec 15 20:12:16 volumio-hall volumio[25966]: info: Discovery: adding 1e7f4238-4a59-44f1-ae5d-e6bcede79cfb Dec 15 20:12:16 volumio-hall volumio[25966]: info: Discovery: Found device Volumio-Hall Dec 15 20:12:16 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioGetState Dec 15 20:12:16 volumio-hall volumio[25966]: info: CorePlayQueue::getTrack 0 Dec 15 20:12:16 volumio-hall volumio[25966]: info: go-librespot daemon successfully initialized Dec 15 20:12:16 volumio-hall volumio[25966]: info: Discovery: this is already registered, 1e7f4238-4a59-44f1-ae5d-e6bcede79cfb Dec 15 20:12:16 volumio-hall volumio[25966]: info: Discovery: Found device Volumio-Hall Dec 15 20:12:16 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioGetState Dec 15 20:12:16 volumio-hall volumio[25966]: info: CorePlayQueue::getTrack 0 Dec 15 20:12:16 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioGetState Dec 15 20:12:16 volumio-hall volumio[25966]: info: CorePlayQueue::getTrack 0 Dec 15 20:12:16 volumio-hall volumio[25966]: info: Discovery: Connected to remote: 192.168.0.154 Dec 15 20:12:16 volumio-hall volumio[25966]: verbose: New Socket.io Connection to 192.168.0.144:3000 from 192.168.0.154 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Dec 15 20:12:16 volumio-hall volumio[25966]: SPOTIFY: User informations: {"country":"IN","display_name":"31ounivl5lgdj7urtwg2tknrat4y","email":"post2skumar@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31ounivl5lgdj7urtwg2tknrat4y"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31ounivl5lgdj7urtwg2tknrat4y","id":"31ounivl5lgdj7urtwg2tknrat4y","images":[],"product":"premium","type":"user","uri":"spotify:user:31ounivl5lgdj7urtwg2tknrat4y"} Dec 15 20:12:16 volumio-hall volumio[25966]: info: Spotify Successfully logged in Dec 15 20:12:16 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 20:12:16 volumio-hall volumio[25966]: info: [1765809736189] CoreMusicLibrary::Adding element Spotify Dec 15 20:12:16 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 20:12:16 volumio-hall volumio[25966]: Cannot find translation for source Spotify Dec 15 20:12:16 volumio-hall volumio[25966]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Dec 15 20:12:16 volumio-hall volumio[25966]: info: CoreCommandRouter::volumioGetState Dec 15 20:12:16 volumio-hall volumio[25966]: info: CorePlayQueue::getTrack 0 Dec 15 20:12:17 volumio-hall sudo[26227]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 20:12:17 volumio-hall sudo[26227]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:17 volumio-hall sudo[26229]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 20:12:17 volumio-hall sudo[26229]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:17 volumio-hall systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 20:12:17 volumio-hall systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 20:12:17 volumio-hall systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 20:12:17 volumio-hall systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 20:12:17 volumio-hall sudo[26227]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:17 volumio-hall mpd_monitor.sh[26232]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 20:12:17 volumio-hall volumio[25966]: info: Successfully started MPD Monitor Dec 15 20:12:17 volumio-hall systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 20:12:17 volumio-hall systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 20:12:17 volumio-hall systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 20:12:17 volumio-hall systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 20:12:17 volumio-hall sudo[26229]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:17 volumio-hall mpd_monitor.sh[26234]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 20:12:17 volumio-hall volumio[25966]: info: Successfully started MPD Monitor Dec 15 20:12:17 volumio-hall systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 15 20:12:17 volumio-hall systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:12:17 volumio-hall systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 20:12:17 volumio-hall go-librespot[26238]: go-librespot daemon starting... Dec 15 20:12:17 volumio-hall go-librespot[26239]: time="2025-12-15T20:12:17+05:30" level=info msg="running go-librespot 0.4.0" Dec 15 20:12:17 volumio-hall go-librespot[26239]: time="2025-12-15T20:12:17+05:30" level=debug msg="app state loaded" Dec 15 20:12:17 volumio-hall go-librespot[26239]: time="2025-12-15T20:12:17+05:30" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 20:12:17 volumio-hall go-librespot[26239]: time="2025-12-15T20:12:17+05:30" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 20:12:17 volumio-hall go-librespot[26239]: time="2025-12-15T20:12:17+05:30" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Dec 15 20:12:17 volumio-hall go-librespot[26239]: time="2025-12-15T20:12:17+05:30" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Dec 15 20:12:17 volumio-hall go-librespot[26239]: time="2025-12-15T20:12:17+05:30" level=info msg="zeroconf server listening on port 37659" Dec 15 20:12:18 volumio-hall go-librespot[26239]: time="2025-12-15T20:12:18+05:30" level=debug msg="obtained new client token: AAAKLR2BQMsyjy/Ermq0CC9EtEGW8vfro3Ac8WFxiszUcceSROEVz31CythfiC1QzYeDcXKPUM7WSPAQaP2F3xf+UrVrZpBdK0npGv0U4RGmZwlpbkkiKxbNDWkrBZFBMqwhRESQ2Hipz+UF4Lp5A/K1QcldgzOtIo7XmnaCBn+yXfR7OpMLRBe8bcL5E/0PRarcW84Gybz4F7qAXp04N5Vj53/AAozcnS+VVoYquPcqYpgwR486JMI=" Dec 15 20:12:18 volumio-hall go-librespot[26239]: time="2025-12-15T20:12:18+05:30" level=debug msg="connected to ap-gae2.spotify.com:4070" Dec 15 20:12:18 volumio-hall go-librespot[26239]: time="2025-12-15T20:12:18+05:30" level=debug msg="completed keyexchange" Dec 15 20:12:18 volumio-hall go-librespot[26239]: time="2025-12-15T20:12:18+05:30" level=debug msg="completed challenge" Dec 15 20:12:19 volumio-hall volumio[25966]: info: Initializing connection to go-librespot Websocket Dec 15 20:12:19 volumio-hall go-librespot[26239]: time="2025-12-15T20:12:19+05:30" level=debug msg="new websocket client" Dec 15 20:12:19 volumio-hall volumio[25966]: info: Connection to go-librespot Websocket established Dec 15 20:12:19 volumio-hall volumio[25966]: info: Cannot mount NAS AudioVideo at system boot, trial number 3 ,retrying in 5 seconds Dec 15 20:12:19 volumio-hall sudo[26261]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 20:12:19 volumio-hall sudo[26261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:19 volumio-hall sudo[26263]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 20:12:19 volumio-hall sudo[26261]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:19 volumio-hall sudo[26263]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:19 volumio-hall sudo[26263]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:19 volumio-hall sudo[26267]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 20:12:19 volumio-hall sudo[26267]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 20:12:19 volumio-hall sudo[26267]: pam_unix(sudo:session): session closed for user root Dec 15 20:12:19 volumio-hall volumio[25966]: info: Upmpdcli Daemon Started Dec 15 20:12:19 volumio-hall volumio[25966]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 20:12:19 volumio-hall go-librespot[26239]: time="2025-12-15T20:12:19+05:30" level=info msg="authenticated AP" username="31************************4y" Dec 15 20:12:21 volumio-hall go-librespot[26239]: time="2025-12-15T20:12:21+05:30" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 20:12:21 volumio-hall systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 20:12:21 volumio-hall systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 20:12:21 volumio-hall volumio[25966]: Cannot compose Albumart path Dec 15 20:12:21 volumio-hall volumio[25966]: info: Connection to go-librespot Websocket closed Dec 15 20:12:22 volumio-hall volumio[25966]: info: Getting Spotify volume Dec 15 20:12:22 volumio-hall volumio[25966]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 20:12:22 volumio-hall volumio[25966]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 20:12:22 volumio-hall volumio[25966]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 15 20:12:22 volumio-hall volumio[25966]: errno: -111, Dec 15 20:12:22 volumio-hall volumio[25966]: code: 'ECONNREFUSED', Dec 15 20:12:22 volumio-hall volumio[25966]: syscall: 'connect', Dec 15 20:12:22 volumio-hall volumio[25966]: address: '127.0.0.1', Dec 15 20:12:22 volumio-hall volumio[25966]: port: 9879, Dec 15 20:12:22 volumio-hall volumio[25966]: response: undefined Dec 15 20:12:22 volumio-hall volumio[25966]: } Dec 15 20:12:22 volumio-hall volumio[25966]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 20:12:22 volumio-hall sudo[26283]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 20:11' Dec 15 20:12:22 volumio-hall sudo[26283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"