-- Logs begin at Thu 2025-02-06 19:09:45 UTC, end at Wed 2025-04-23 17:14:34 UTC. -- Apr 23 17:13:00 neumann volumio-remote-updater[512]: [2025-04-23 17:13:00] [connect] Successful connection Apr 23 17:13:00 neumann volumio[833]: info: Loading plugin "services"... Apr 23 17:13:00 neumann sudo[1030]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 23 17:13:00 neumann sudo[1032]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 23 17:13:00 neumann volumio[833]: info: Loading plugin "alsa_controller"... Apr 23 17:13:00 neumann sudo[1030]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:13:00 neumann sudo[1032]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:13:00 neumann sudo[1032]: pam_unix(sudo:session): session closed for user root Apr 23 17:13:00 neumann sudo[1030]: pam_unix(sudo:session): session closed for user root Apr 23 17:13:00 neumann sudo[1037]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 23 17:13:00 neumann sudo[1037]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:13:01 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 23 17:13:01 neumann volumio[833]: info: Loading plugin "wizard"... Apr 23 17:13:01 neumann volumio[833]: info: Loading plugin "networkfs"... Apr 23 17:13:01 neumann volumio[833]: info: Starting Udev Watcher for removable devices Apr 23 17:13:01 neumann volumio[833]: info: Ignoring mount for partition: boot Apr 23 17:13:01 neumann volumio[833]: info: Ignoring mount for partition: volumio Apr 23 17:13:01 neumann volumio[833]: info: Ignoring mount for partition: volumio_data Apr 23 17:13:01 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 23 17:13:01 neumann volumio[833]: info: Loading plugin "volumio_command_line_client"... Apr 23 17:13:01 neumann volumio[833]: info: Loading plugin "upnp"... Apr 23 17:13:01 neumann volumio[833]: info: [1745428381570] Starting Upmpd Daemon Apr 23 17:13:01 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 23 17:13:01 neumann volumio[833]: info: Loading plugin "my_music"... Apr 23 17:13:01 neumann sudo[1037]: pam_unix(sudo:session): session closed for user root Apr 23 17:13:01 neumann volumio[833]: info: Loading plugin "mpd"... Apr 23 17:13:03 neumann volumio[833]: info: Loading plugin "upnp_browser"... Apr 23 17:13:05 neumann volumio[833]: info: Loading plugin "alarm-clock"... Apr 23 17:13:06 neumann volumio[833]: info: Loading plugin "airplay_emulation"... Apr 23 17:13:06 neumann volumio[833]: info: Starting Shairport Sync Apr 23 17:13:06 neumann volumio[833]: info: Loading plugin "last_100"... Apr 23 17:13:06 neumann volumio[833]: info: Loading plugin "webradio"... Apr 23 17:13:06 neumann volumio[833]: info: Loading plugin "i2s_dacs"... Apr 23 17:13:06 neumann volumio[833]: info: Loading plugin "volumiodiscovery"... Apr 23 17:13:06 neumann volumio[833]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 23 17:13:06 neumann volumio[833]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 23 17:13:06 neumann volumio[833]: *** WARNING *** For more information see Apr 23 17:13:06 neumann volumio[833]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 23 17:13:06 neumann volumio[833]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 23 17:13:06 neumann volumio[833]: *** WARNING *** For more information see Apr 23 17:13:06 neumann node[833]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 23 17:13:06 neumann node[833]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 23 17:13:06 neumann node[833]: *** WARNING *** For more information see Apr 23 17:13:06 neumann node[833]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 23 17:13:06 neumann node[833]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 23 17:13:06 neumann node[833]: *** WARNING *** For more information see Apr 23 17:13:07 neumann volumio[833]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 23 17:13:07 neumann volumio[833]: info: Discovery: Started advertising with name: neumann Apr 23 17:13:07 neumann systemd[1]: systemd-timedated.service: Succeeded. Apr 23 17:13:07 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 23 17:13:07 neumann volumio[833]: info: Loading plugin "spop"... Apr 23 17:13:09 neumann ntpd[550]: Soliciting pool server 217.196.145.42 Apr 23 17:13:10 neumann ntpd[550]: Soliciting pool server 162.159.200.123 Apr 23 17:13:10 neumann ntpd[550]: Soliciting pool server 151.236.30.71 Apr 23 17:13:11 neumann ntpd[550]: Soliciting pool server 146.255.56.84 Apr 23 17:13:11 neumann ntpd[550]: Soliciting pool server 178.251.64.52 Apr 23 17:13:11 neumann ntpd[550]: Soliciting pool server 152.53.132.244 Apr 23 17:13:12 neumann ntpd[550]: Soliciting pool server 86.59.80.170 Apr 23 17:13:12 neumann ntpd[550]: Soliciting pool server 185.242.177.6 Apr 23 17:13:12 neumann ntpd[550]: Soliciting pool server 162.159.200.1 Apr 23 17:13:12 neumann ntpd[550]: Soliciting pool server 152.53.45.248 Apr 23 17:13:13 neumann ntpd[550]: Soliciting pool server 37.252.189.117 Apr 23 17:13:13 neumann ntpd[550]: Soliciting pool server 62.40.143.228 Apr 23 17:13:13 neumann ntpd[550]: Soliciting pool server 152.53.15.127 Apr 23 17:13:14 neumann volumio[833]: info: Loading plugin "outputs"... Apr 23 17:13:14 neumann volumio[833]: info: Loading plugin "albumart"... Apr 23 17:13:14 neumann volumio[833]: info: Plugin example_plugin is not enabled Apr 23 17:13:14 neumann volumio[833]: info: Loading plugin "inputs"... Apr 23 17:13:14 neumann volumio[833]: info: Loading plugin "updater_comm"... Apr 23 17:13:14 neumann ntpd[550]: Soliciting pool server 46.102.157.67 Apr 23 17:13:14 neumann ntpd[550]: Soliciting pool server 2001:628:21f0:80::80:29 Apr 23 17:13:15 neumann volumio-remote-updater[512]: [2025-04-23 17:13:15] [connect] Successful connection Apr 23 17:13:16 neumann volumio[833]: info: Plugin mpdemulation is not enabled Apr 23 17:13:16 neumann volumio[833]: info: Loading plugin "rest_api"... Apr 23 17:13:16 neumann volumio[833]: info: Loading plugin "websocket"... Apr 23 17:13:16 neumann volumio[833]: info: Starting Socket.io Server version 2.3.0 Apr 23 17:13:16 neumann volumio[833]: info: Loading i18n strings for locale en Apr 23 17:13:16 neumann volumio[833]: Updating browse sources language Apr 23 17:13:16 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 23 17:13:17 neumann volumio[833]: Forking 1 albumart workers Apr 23 17:13:20 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 23 17:13:20 neumann volumio[833]: info: CoreCommandRouter::initPlayerControls Apr 23 17:13:20 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 17:13:20 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 17:13:20 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 17:13:21 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 23 17:13:21 neumann volumio[833]: Express server listening on port 3000 Apr 23 17:13:21 neumann volumio[833]: [Metrics] WebUI: 36s 126.69ms Apr 23 17:13:21 neumann volumio[833]: info: CoreStateMachine::resetVolumioState Apr 23 17:13:21 neumann volumio[833]: info: CoreStateMachine::getcurrentVolume Apr 23 17:13:21 neumann volumio[833]: info: CoreCommandRouter::volumioRetrievevolume Apr 23 17:13:21 neumann sudo[1099]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 23 17:13:21 neumann sudo[1099]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:13:22 neumann sudo[1099]: pam_unix(sudo:session): session closed for user root Apr 23 17:13:22 neumann sudo[1101]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 23 17:13:22 neumann sudo[1101]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:13:22 neumann sudo[1101]: pam_unix(sudo:session): session closed for user root Apr 23 17:13:22 neumann volumio[833]: info: Volumio Network Manager: Network status updated: 2 Apr 23 17:13:23 neumann volumio[833]: info: VolumeController:: Volume=14 Mute =false Apr 23 17:13:23 neumann volumio[833]: info: CoreStateMachine::pushState Apr 23 17:13:23 neumann volumio[833]: info: CorePlayQueue::getTrack 0 Apr 23 17:13:23 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 23 17:13:23 neumann volumio[833]: info: CoreCommandRouter::volumioPushState Apr 23 17:13:23 neumann volumio[833]: info: CoreStateMachine::updateTrackBlock Apr 23 17:13:23 neumann volumio[833]: info: CorePlayQueue::getTrackBlock Apr 23 17:13:23 neumann volumio[833]: info: CoreCommandRouter::volumioRetrievevolume Apr 23 17:13:24 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 17:13:24 neumann volumio[833]: info: Reloading queue from file Apr 23 17:13:24 neumann volumio[833]: info: CoreStateMachine::setRepeat null single undefined Apr 23 17:13:24 neumann volumio[833]: info: CoreStateMachine::pushState Apr 23 17:13:24 neumann volumio[833]: info: CorePlayQueue::getTrack 0 Apr 23 17:13:24 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 23 17:13:24 neumann volumio[833]: info: CoreCommandRouter::volumioPushState Apr 23 17:13:24 neumann volumio[833]: info: CoreStateMachine::setRandom null Apr 23 17:13:24 neumann volumio[833]: info: CoreStateMachine::pushState Apr 23 17:13:24 neumann volumio[833]: info: CorePlayQueue::getTrack 0 Apr 23 17:13:24 neumann volumio[833]: info: CoreCommandRouter::volumioPushState Apr 23 17:13:24 neumann volumio[833]: info: Setting Device type: Raspberry PI Apr 23 17:13:24 neumann volumio[833]: info: Completed loading Core Plugins Apr 23 17:13:24 neumann volumio[833]: info: Preparing to generate the ALSA configuration file Apr 23 17:13:25 neumann volumio[833]: info: Discovery: adding b969c959-f9bf-4ae5-83e4-0f6ac1181553 Apr 23 17:13:25 neumann volumio[833]: info: Discovery: Found device neumann Apr 23 17:13:25 neumann volumio[833]: info: CoreCommandRouter::volumioGetState Apr 23 17:13:25 neumann volumio[833]: info: CorePlayQueue::getTrack 0 Apr 23 17:13:25 neumann volumio[833]: info: Asound.conf file unchanged, so no further update is needed Apr 23 17:13:25 neumann volumio[833]: info: Output device has changed, restarting MPD Apr 23 17:13:25 neumann sudo[1132]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 23 17:13:25 neumann sudo[1132]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:13:25 neumann systemd[1]: Started UPnP Renderer front-end to MPD. Apr 23 17:13:25 neumann volumio[833]: info: Output device has changed, restarting Shairport Sync Apr 23 17:13:25 neumann sudo[1132]: pam_unix(sudo:session): session closed for user root Apr 23 17:13:25 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 17:13:25 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 17:13:25 neumann sudo[1135]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 23 17:13:25 neumann sudo[1135]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:13:25 neumann sudo[1138]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 23 17:13:25 neumann sudo[1138]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:13:26 neumann sudo[1135]: pam_unix(sudo:session): session closed for user root Apr 23 17:13:26 neumann systemd[1]: Stopping Music Player Daemon... Apr 23 17:13:26 neumann systemd[1]: mpd.service: Succeeded. Apr 23 17:13:26 neumann systemd[1]: Stopped Music Player Daemon. Apr 23 17:13:26 neumann systemd[1]: Starting Music Player Daemon... Apr 23 17:13:26 neumann volumio[833]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 23 17:13:26 neumann volumio[833]: info: ___________ START PLUGINS ___________ Apr 23 17:13:26 neumann volumio[833]: info: ControllerMpd::onStart: Initializing MPD Apr 23 17:13:26 neumann volumio[833]: info: Creating MPD Configuration file Apr 23 17:13:27 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 23 17:13:27 neumann volumio[833]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 23 17:13:27 neumann volumio[833]: info: [1745428407307] CoreMusicLibrary::Adding element Media Servers Apr 23 17:13:27 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 23 17:13:27 neumann sudo[1144]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 23 17:13:27 neumann sudo[1144]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:13:27 neumann sudo[1144]: pam_unix(sudo:session): session closed for user root Apr 23 17:13:27 neumann sudo[1146]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 23 17:13:27 neumann sudo[1146]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:13:27 neumann sudo[1146]: pam_unix(sudo:session): session closed for user root Apr 23 17:13:27 neumann sudo[1148]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 23 17:13:27 neumann sudo[1148]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:13:28 neumann systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 23 17:13:28 neumann systemd[1]: mpd.service: Succeeded. Apr 23 17:13:28 neumann systemd[1]: Stopped Music Player Daemon. Apr 23 17:13:28 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 17:13:28 neumann systemd[1]: Starting Music Player Daemon... Apr 23 17:13:28 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 17:13:28 neumann volumio[833]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 23 17:13:28 neumann sudo[1153]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 23 17:13:28 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 17:13:28 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 17:13:28 neumann sudo[1153]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:13:28 neumann sudo[1153]: pam_unix(sudo:session): session closed for user root Apr 23 17:13:29 neumann volumio[833]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 23 17:13:29 neumann volumio[833]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 23 17:13:29 neumann volumio[833]: info: [1745428409323] CoreMusicLibrary::Adding element Last_100 Apr 23 17:13:29 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 23 17:13:29 neumann volumio[833]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 23 17:13:29 neumann volumio[833]: info: [1745428409375] CoreMusicLibrary::Adding element Webradio Apr 23 17:13:29 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 23 17:13:29 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 23 17:13:29 neumann volumio[833]: info: Initializing BBC Radios Apr 23 17:13:29 neumann volumio[833]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Apr 23 17:13:29 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 17:13:30 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 23 17:13:30 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 17:13:30 neumann volumio[833]: info: Creating Spotify config file Apr 23 17:13:30 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 17:13:31 neumann volumio[833]: Starting albumart workers Apr 23 17:13:31 neumann volumio[833]: info: Volumio Calling Home Apr 23 17:13:32 neumann volumio-remote-updater[512]: [2025-04-23 17:13:32] [connect] Successful connection Apr 23 17:13:34 neumann systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 23 17:13:34 neumann systemd[1]: mpd.service: Failed with result 'protocol'. Apr 23 17:13:34 neumann systemd[1]: Failed to start Music Player Daemon. Apr 23 17:13:34 neumann sudo[1138]: pam_unix(sudo:session): session closed for user root Apr 23 17:13:34 neumann sudo[1148]: pam_unix(sudo:session): session closed for user root Apr 23 17:13:34 neumann systemd[1]: Starting Music Player Daemon... Apr 23 17:13:35 neumann sudo[1187]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 23 17:13:35 neumann sudo[1187]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:13:35 neumann sudo[1187]: pam_unix(sudo:session): session closed for user root Apr 23 17:13:35 neumann volumio[833]: error: Cannot start MPD on system Start: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service Apr 23 17:13:35 neumann volumio[833]: Job for mpd.service failed because the service did not take the steps required by its unit configuration. Apr 23 17:13:35 neumann volumio[833]: See "systemctl status mpd.service" and "journalctl -xe" for details. Apr 23 17:13:35 neumann volumio[833]: info: Completed starting Core Plugins Apr 23 17:13:35 neumann volumio[833]: info: ------------------------------------------- Apr 23 17:13:35 neumann volumio[833]: info: ----- MyVolumio plugins startup ---- Apr 23 17:13:35 neumann volumio[833]: info: ------------------------------------------- Apr 23 17:13:35 neumann volumio[833]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 23 17:13:35 neumann volumio[833]: info: MPD Permissions set Apr 23 17:13:35 neumann volumio[833]: info: Cannot restart MPD: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service Apr 23 17:13:35 neumann volumio[833]: Job for mpd.service failed because the service did not take the steps required by its unit configuration. Apr 23 17:13:35 neumann volumio[833]: See "systemctl status mpd.service" and "journalctl -xe" for details. Apr 23 17:13:35 neumann volumio[833]: info: MPD Permissions set Apr 23 17:13:35 neumann volumio[833]: info: Upmpdcli Daemon Started Apr 23 17:13:35 neumann volumio[833]: info: VolumeController:: Volume=14 Mute =false Apr 23 17:13:35 neumann volumio[833]: info: CoreStateMachine::pushState Apr 23 17:13:35 neumann volumio[833]: info: CorePlayQueue::getTrack 0 Apr 23 17:13:35 neumann volumio[833]: info: CoreCommandRouter::volumioPushState Apr 23 17:13:36 neumann volumio-remote-updater[512]: [2025-04-23 17:13:36] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1745428412 101 Apr 23 17:13:36 neumann volumio[833]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Apr 23 17:13:36 neumann volumio[833]: info: Volumio called home Apr 23 17:13:36 neumann volumio[833]: info: Spotify config file written Apr 23 17:13:37 neumann sudo[1197]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 23 17:13:37 neumann sudo[1197]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:13:37 neumann systemd[1]: Started go-librespot Daemon. Apr 23 17:13:37 neumann go-librespot[1199]: Librespot-go daemon starting... Apr 23 17:13:37 neumann sudo[1197]: pam_unix(sudo:session): session closed for user root Apr 23 17:13:38 neumann go-librespot[1199]: time="2025-04-23T17:13:38Z" level=info msg="generated new device id: 59d38d52fb3569c7f9e70c47bc1dadadad01053f" Apr 23 17:13:38 neumann go-librespot[1199]: time="2025-04-23T17:13:38Z" level=debug msg="stored credentials found for brbd2k" Apr 23 17:13:38 neumann volumio[833]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Apr 23 17:13:39 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 17:13:39 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 17:13:39 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 17:13:39 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 17:13:39 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 17:13:40 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 17:13:40 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 17:13:40 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 17:13:40 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 17:13:40 neumann volumio[833]: info: No need to fix Spotify hosts Apr 23 17:13:41 neumann go-librespot[1199]: time="2025-04-23T17:13:41Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 23 17:13:41 neumann go-librespot[1199]: time="2025-04-23T17:13:41Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 23 17:13:41 neumann go-librespot[1199]: time="2025-04-23T17:13:41Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 23 17:13:41 neumann go-librespot[1199]: time="2025-04-23T17:13:41Z" level=debug msg="zeroconf server listening on port 35613" Apr 23 17:13:41 neumann go-librespot[1199]: time="2025-04-23T17:13:41Z" level=debug msg="obtained new client token: AADI03TTHW5nOkaaGu/a9XL5okxsfK1qQH5DzCK4cwoE36OXqgCA6FOuF8G9ozuIiOFbmn3ENw8r+NKzKI8SFVNqJRNYDUUB4OstSYmy1W3MYY2qQ2JKLkO6gGJ+3H9KPvSMiz3yYLm2xeWNHQIypSc2BwCL09+lJPiAEAYGM5MHiWGGxff6UQWu1+atMp7vwMnEotTjNdgJfLz0s9aXexIrQNig3rF3iVVX/C7U+dae4vtdgMy/Eqcd7zA=" Apr 23 17:13:41 neumann go-librespot[1199]: time="2025-04-23T17:13:41Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 23 17:13:42 neumann go-librespot[1199]: time="2025-04-23T17:13:42Z" level=debug msg="completed keyexchange" Apr 23 17:13:42 neumann go-librespot[1199]: time="2025-04-23T17:13:42Z" level=debug msg="completed challenge" Apr 23 17:13:42 neumann go-librespot[1199]: time="2025-04-23T17:13:42Z" level=debug msg="authenticated as brbd2k" Apr 23 17:13:43 neumann go-librespot[1199]: time="2025-04-23T17:13:43Z" level=debug msg="authenticated as brbd2k" Apr 23 17:13:43 neumann go-librespot[1199]: time="2025-04-23T17:13:43Z" level=debug msg="dealer connection opened" Apr 23 17:13:43 neumann go-librespot[1199]: time="2025-04-23T17:13:43Z" level=debug msg="initializing zeroconf session, username: brbd2k" Apr 23 17:13:43 neumann go-librespot[1199]: time="2025-04-23T17:13:43Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 23 17:13:43 neumann go-librespot[1199]: time="2025-04-23T17:13:43Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 23 17:13:43 neumann go-librespot[1199]: time="2025-04-23T17:13:43Z" level=debug msg="received connection id: MWY2NDJlYzMtMzQxZi00YWVjLWE1Y2UtMjM3YmQ3YzFkZjVkK2RlYWxlcit0Y3A6Ly8wYWNhNThhMC5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArQTNBNENEMkYxNEZFODVEQTlERTYyNTVBQjgzRUYzMUI3M0YzNkI3NDkxOThEMDhBMEMxRTc2QzdDQUU0N0ZEQQ==" Apr 23 17:13:43 neumann go-librespot[1199]: time="2025-04-23T17:13:43Z" level=debug msg="put connect state because NEW_DEVICE" Apr 23 17:13:43 neumann go-librespot[1199]: time="2025-04-23T17:13:43Z" level=debug msg="autoplay enabled: false" Apr 23 17:13:43 neumann go-librespot[1199]: time="2025-04-23T17:13:43Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 23 17:13:43 neumann go-librespot[1199]: time="2025-04-23T17:13:43Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 23 17:13:43 neumann go-librespot[1199]: time="2025-04-23T17:13:43Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 23 17:13:43 neumann volumio[833]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 23 17:13:43 neumann volumio[833]: SPOTIFY: BQCKbnjZtt4jmDxkJnRrqmzcLLFEXvM7Y6Vk3FF-4LSyjxFqqwu5RVtBXIu6TcLdq-7aoS4zuzl6U8AL4kfNnUd_mlujdnuzIJkgRhjgbn5fkefel3eONkBVe8z1MPsbkldHxMEFLQqe2I_js7ZJwOo-n7_o4gFPb66xP_Vlb_o2XeknJJDwsJiyrYbQYeTcRY3IeGyJ6OGbYdzPDa3QFY09AMlKgHbkBYgVl6j5eLYJb_C0lgnIJiOTlJQRRzGZ57dJKtXM22oIUCiCxg Apr 23 17:13:43 neumann volumio[833]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 23 17:13:43 neumann volumio[833]: info: New Spotify access token = BQCKbnjZtt4jmDxkJnRrqmzcLLFEXvM7Y6Vk3FF-4LSyjxFqqwu5RVtBXIu6TcLdq-7aoS4zuzl6U8AL4kfNnUd_mlujdnuzIJkgRhjgbn5fkefel3eONkBVe8z1MPsbkldHxMEFLQqe2I_js7ZJwOo-n7_o4gFPb66xP_Vlb_o2XeknJJDwsJiyrYbQYeTcRY3IeGyJ6OGbYdzPDa3QFY09AMlKgHbkBYgVl6j5eLYJb_C0lgnIJiOTlJQRRzGZ57dJKtXM22oIUCiCxg Apr 23 17:13:43 neumann volumio[833]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 23 17:13:44 neumann volumio[833]: info: Starting Shairport Sync Apr 23 17:13:44 neumann volumio[833]: info: Starting Shairport Sync Apr 23 17:13:44 neumann volumio[833]: info: Starting Shairport Sync Apr 23 17:13:45 neumann sudo[1223]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 23 17:13:45 neumann sudo[1223]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:13:45 neumann sudo[1225]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 23 17:13:45 neumann sudo[1225]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:13:45 neumann systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 23 17:13:45 neumann systemd[1]: shairport-sync.service: Succeeded. Apr 23 17:13:45 neumann systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 23 17:13:45 neumann systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 23 17:13:46 neumann sudo[1223]: pam_unix(sudo:session): session closed for user root Apr 23 17:13:46 neumann volumio[833]: info: CoreCommandRouter::volumioGetState Apr 23 17:13:46 neumann sudo[1234]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 23 17:13:46 neumann systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 23 17:13:46 neumann volumio[833]: info: CorePlayQueue::getTrack 0 Apr 23 17:13:46 neumann systemd[1]: shairport-sync.service: Succeeded. Apr 23 17:13:46 neumann sudo[1234]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:13:46 neumann systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 23 17:13:46 neumann systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 23 17:13:46 neumann sudo[1225]: pam_unix(sudo:session): session closed for user root Apr 23 17:13:46 neumann volumio[833]: info: go-librespot daemon successfully initialized Apr 23 17:13:47 neumann systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 23 17:13:47 neumann systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Apr 23 17:13:47 neumann systemd[1]: shairport-sync.service: Succeeded. Apr 23 17:13:47 neumann systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 23 17:13:47 neumann systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 23 17:13:47 neumann sudo[1234]: pam_unix(sudo:session): session closed for user root Apr 23 17:13:47 neumann volumio[833]: info: Shairport-Sync Started Apr 23 17:13:47 neumann volumio[833]: Error adding Membership: Error: addMembership EINVAL Apr 23 17:13:47 neumann volumio[833]: info: Shairport-Sync Started Apr 23 17:13:47 neumann volumio[833]: info: Shairport-Sync Started Apr 23 17:13:48 neumann volumio[833]: SPOTIFY: User informations: {"country":"AT","display_name":"brbd2k","email":"sam.aahani@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/brbd2k"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/brbd2k","id":"brbd2k","images":[],"product":"premium","type":"user","uri":"spotify:user:brbd2k"} Apr 23 17:13:48 neumann volumio[833]: info: Spotify Successfully logged in Apr 23 17:13:48 neumann volumio[833]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 23 17:13:48 neumann volumio[833]: info: [1745428428419] CoreMusicLibrary::Adding element Spotify Apr 23 17:13:48 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 23 17:13:48 neumann volumio[833]: Cannot find translation for source Spotify Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 23 17:13:48 neumann volumio[833]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 23 17:13:48 neumann volumio[833]: info: Adding plugin bluetooth to MyMusic Plugins Apr 23 17:13:48 neumann volumio[833]: info: Adding plugin multiroom to MyMusic Plugins Apr 23 17:13:48 neumann volumio[833]: info: Adding plugin metavolumio to MyMusic Plugins Apr 23 17:13:48 neumann volumio[833]: info: Adding plugin cd_controller to MyMusic Plugins Apr 23 17:13:48 neumann volumio[833]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 23 17:13:48 neumann volumio[833]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 23 17:13:49 neumann volumio[833]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 23 17:13:51 neumann mpd[1195]: Apr 23 17:13 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 23 17:13:51 neumann systemd[1]: Started Music Player Daemon. Apr 23 17:13:51 neumann mpd_monitor.sh[382]: MPD restarted due to no mpc output. Apr 23 17:13:55 neumann volumio[833]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 23 17:13:55 neumann volumio[833]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 23 17:13:55 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 17:13:55 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 17:13:55 neumann volumio[833]: info: Starting MyVolumio Remote Streaming Endpoints Apr 23 17:13:55 neumann volumio[833]: info: MyVolumio login type: Token Apr 23 17:13:55 neumann volumio[833]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 23 17:13:55 neumann volumio[833]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 23 17:14:01 neumann volumio[833]: info: Starting Streaming Service Transparent Proxy Apr 23 17:14:01 neumann volumio[833]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 23 17:14:01 neumann volumio[833]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 23 17:14:01 neumann volumio[833]: info: Streaming services startup Apr 23 17:14:01 neumann volumio[833]: info: Starting Streaming Daemon Apr 23 17:14:01 neumann sudo[1316]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 23 17:14:01 neumann sudo[1316]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 23 17:14:02 neumann volumio[833]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 23 17:14:02 neumann sudo[1316]: pam_unix(sudo:session): session closed for user root Apr 23 17:14:02 neumann volumio[833]: /usr/bin/md5sum: /sys/class/net/eth0/address: No such file or directory Apr 23 17:14:02 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 17:14:02 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 23 17:14:02 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 17:14:02 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 23 17:14:02 neumann volumio[833]: info: Initializing connection to go-librespot Websocket Apr 23 17:14:03 neumann volumio[833]: Upnp client error: Error: This socket has been ended by the other party Apr 23 17:14:03 neumann volumio[833]: error: MPD error: The expression evaluated to a falsy value: Apr 23 17:14:03 neumann volumio[833]: assert.ok(self.idling) Apr 23 17:14:03 neumann volumio[833]: error: The expression evaluated to a falsy value: Apr 23 17:14:03 neumann volumio[833]: assert.ok(self.idling) Apr 23 17:14:03 neumann volumio[833]: Upnp client error: Error: This socket has been ended by the other party Apr 23 17:14:03 neumann volumio[833]: Upnp client error: Error: This socket has been ended by the other party Apr 23 17:14:03 neumann volumio[833]: error: Cannot start Volumio Streaming Daemon Apr 23 17:14:03 neumann volumio[833]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 23 17:14:03 neumann volumio[833]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 23 17:14:04 neumann volumio[833]: error: updateQueue error: null Apr 23 17:14:04 neumann volumio[833]: error: An error occurred while listing Spotify featured playlists Error: Client network socket disconnected before secure TLS connection was established Apr 23 17:14:04 neumann volumio[833]: info: An error occurred while getting Spotify ROOT Discover Folders: Apr 23 17:14:04 neumann volumio[833]: error: An error occurred while listing Spotify new albums Error: Client network socket disconnected before secure TLS connection was established Apr 23 17:14:04 neumann volumio[833]: error: An error occurred while listing Spotify categories Error: Client network socket disconnected before secure TLS connection was established Apr 23 17:14:04 neumann go-librespot[1199]: time="2025-04-23T17:14:04Z" level=debug msg="new websocket client" Apr 23 17:14:04 neumann volumio[833]: info: Connection to go-librespot Websocket established Apr 23 17:14:05 neumann go-librespot[1199]: time="2025-04-23T17:14:05Z" level=error msg="failed receiving dealer message" error="failed to get reader: received close frame: status = StatusGoingAway and reason = \"\"" Apr 23 17:14:05 neumann go-librespot[1199]: time="2025-04-23T17:14:05Z" level=error msg="failed receiving packet" error="failed reading packet header: read tcp 192.168.0.151:43754->34.158.1.133:4070: use of closed network connection" Apr 23 17:14:05 neumann volumio[833]: error: MyVolumio Custom Token format not valid, refreshing it Apr 23 17:14:05 neumann go-librespot[1199]: time="2025-04-23T17:14:05Z" level=debug msg="obtained new client token: AADZCA9DAI+bJKqbIYAunVdj01VPCE34AWThWotuSRV0CibeR5OjZ3FSYZM8Vnwhy6eSsaxiMTcG3kEycPGHIwuasgxiXhdpMpCZrjrun65OT8ekgQ19+3iqPAQVQNHLokzzwdwZxB/nwJcrck3mCDTIu3giN50JSLtBFKwNh0nkRu6gziue/iWap3m9nsgOGCxtK5xt7QpU3qpeZyPY/0Ui01DRAEMIfnbao1q6R24lt3JOwi0FwNwX" Apr 23 17:14:05 neumann go-librespot[1199]: time="2025-04-23T17:14:05Z" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 23 17:14:05 neumann go-librespot[1199]: time="2025-04-23T17:14:05Z" level=debug msg="completed keyexchange" Apr 23 17:14:05 neumann go-librespot[1199]: time="2025-04-23T17:14:05Z" level=debug msg="completed challenge" Apr 23 17:14:05 neumann go-librespot[1199]: time="2025-04-23T17:14:05Z" level=debug msg="authenticated as 1149385926" Apr 23 17:14:05 neumann volumio[1137]: Generating RSA private key, 4096 bit long modulus (2 primes) Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="authenticated as 1149385926" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="dealer connection opened" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=info msg="accepted zeroconf user 1149385926 from iPhone" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="received connection id: Y2JmNWRkMWItZjJlZi00NzllLWE1ODctNmRmYjU2NGJjYTg4K2RlYWxlcit0Y3A6Ly8wYWNhNTg0MS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNDg0RjVDMTIwQ0YyQTcyQUM1QTU3OEQwN0ZDNDk4RTAzMkUwMUZFMEE5RTExMTdGN0UyRjQ1RDI4RTQ1QTk4NQ==" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="put connect state because NEW_DEVICE" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="autoplay enabled: false" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="handling transfer player command from ea4e31e744051af4a05808a322ace83580dee340" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="resolved context of track" uri="spotify:playlist:0dZwJAM4pPfP4mQ9J2VlDV" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=trace msg="fetched new page 0 with 151 items (list: 151)" uri="spotify:playlist:0dZwJAM4pPfP4mQ9J2VlDV" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="loading track (paused: false, position: 139402ms)" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=trace msg="emitting websocket event: will_play" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 3254" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="selected format OGG_VORBIS_320 (332d589785be4ee3d3c5d362ba0a52d7b963cf37)" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:06 neumann go-librespot[1199]: time="2025-04-23T17:14:06Z" level=debug msg="requested aes key for file 332d589785be4ee3d3c5d362ba0a52d7b963cf37, gid: 4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:07 neumann go-librespot[1199]: time="2025-04-23T17:14:07Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2071" Apr 23 17:14:07 neumann volumio-remote-updater[512]: No test mode Apr 23 17:14:07 neumann volumio-remote-updater[512]: No alpha test mode Apr 23 17:14:07 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 23 17:14:08 neumann go-librespot[1199]: time="2025-04-23T17:14:08Z" level=debug msg="fetched first chunk of 20, total size is 10111216 bytes" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:08 neumann go-librespot[1199]: time="2025-04-23T17:14:08Z" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Apr 23 17:14:09 neumann volumio[833]: info: Getting Spotify volume Apr 23 17:14:10 neumann volumio[833]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4b6zASM8nsUj4d493qWC1F","play_origin":"playlist/ondemand"}} Apr 23 17:14:10 neumann volumio[833]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

    • Improved translations


NEW ADDITIONS

 

    • Update to TIDAL Connect
    • Add Install-to-disk option for the new RPi5 HW revisions 

 

","title":"Update v3.799","updateavailable":true} Apr 23 17:14:10 neumann go-librespot[1199]: time="2025-04-23T17:14:10Z" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:12 neumann go-librespot[1199]: time="2025-04-23T17:14:12Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 250" Apr 23 17:14:12 neumann go-librespot[1199]: time="2025-04-23T17:14:12Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 3227" Apr 23 17:14:12 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 23 17:14:13 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 23 17:14:13 neumann go-librespot[1199]: time="2025-04-23T17:14:13Z" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:13 neumann volumio[833]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 23 17:14:13 neumann go-librespot[1199]: time="2025-04-23T17:14:13Z" level=debug msg="fetched chunk 11/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:13 neumann go-librespot[1199]: time="2025-04-23T17:14:13Z" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:13 neumann go-librespot[1199]: time="2025-04-23T17:14:13Z" level=debug msg="fetched chunk 9/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:13 neumann go-librespot[1199]: time="2025-04-23T17:14:13Z" level=debug msg="fetched chunk 10/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:13 neumann volumio[833]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Apr 23 17:14:13 neumann go-librespot[1199]: time="2025-04-23T17:14:13Z" level=debug msg="fetched chunk 12/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:14 neumann go-librespot[1199]: time="2025-04-23T17:14:14Z" level=trace msg="seek to 139402ms (diff: 64ms, samples: 6147628, bytes: 5106266)" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:14 neumann volumio[833]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Apr 23 17:14:14 neumann go-librespot[1199]: time="2025-04-23T17:14:14Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Apr 23 17:14:14 neumann go-librespot[1199]: time="2025-04-23T17:14:14Z" level=debug msg="created new output device" Apr 23 17:14:14 neumann go-librespot[1199]: time="2025-04-23T17:14:14Z" level=info msg="loaded track \"Nocturnes, Op. 32: No. 1 in B Major\" (paused: false, position: 139402ms, duration: 275826ms, prefetched: false)" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:14 neumann go-librespot[1199]: time="2025-04-23T17:14:14Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 17:14:14 neumann go-librespot[1199]: time="2025-04-23T17:14:14Z" level=trace msg="scheduling prefetch in 106s" Apr 23 17:14:14 neumann go-librespot[1199]: time="2025-04-23T17:14:14Z" level=trace msg="emitting websocket event: metadata" Apr 23 17:14:14 neumann go-librespot[1199]: time="2025-04-23T17:14:14Z" level=trace msg="emitting websocket event: active" Apr 23 17:14:14 neumann go-librespot[1199]: time="2025-04-23T17:14:14Z" level=debug msg="sending successful reply for dealer request" Apr 23 17:14:14 neumann volumio[833]: info: MyVolumio login type: Token Apr 23 17:14:14 neumann go-librespot[1199]: time="2025-04-23T17:14:14Z" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=trace msg="emitting websocket event: playing" Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=debug msg="handling pause player command from ea4e31e744051af4a05808a322ace83580dee340" Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 3254" Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=debug msg="pause track at 139601ms" Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=debug msg="sending successful reply for dealer request" Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2071" Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=trace msg="emitting websocket event: paused" Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=debug msg="handling transfer player command from ea4e31e744051af4a05808a322ace83580dee340" Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=debug msg="resolved context of track" uri="spotify:playlist:0dZwJAM4pPfP4mQ9J2VlDV" Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=trace msg="fetched new page 0 with 151 items (list: 151)" uri="spotify:playlist:0dZwJAM4pPfP4mQ9J2VlDV" Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=debug msg="loading track (paused: false, position: 147017ms)" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=trace msg="emitting websocket event: will_play" Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=debug msg="selected format OGG_VORBIS_320 (332d589785be4ee3d3c5d362ba0a52d7b963cf37)" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:15 neumann volumio[833]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Apr 23 17:14:15 neumann go-librespot[1199]: time="2025-04-23T17:14:15Z" level=debug msg="requested aes key for file 332d589785be4ee3d3c5d362ba0a52d7b963cf37, gid: 4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:16 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 17:14:16 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 17:14:16 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 23 17:14:16 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 23 17:14:16 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 23 17:14:16 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 23 17:14:16 neumann volumio[833]: info: CoreCommandRouter::volumioGetBrowseSources Apr 23 17:14:16 neumann volumio[833]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 23 17:14:16 neumann volumio[833]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4b6zASM8nsUj4d493qWC1F","name":"Nocturnes, Op. 32: No. 1 in B Major","artist_names":["Frédéric Chopin","Arthur Rubinstein"],"album_name":"The Original Jacket Collection - Rubinstein Plays Chopin","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0226b4106d7f1ed39dcfb52763","position":139402,"duration":275826,"release_date":"year:1946","track_number":9,"disc_number":1}} Apr 23 17:14:16 neumann volumio[833]: SPOTIFY: received: {"type":"active","data":null} Apr 23 17:14:16 neumann volumio[833]: info: Aligning Spotify Volume to Volumio Volume Apr 23 17:14:16 neumann volumio[833]: info: CoreCommandRouter::volumioGetState Apr 23 17:14:16 neumann volumio[833]: info: CorePlayQueue::getTrack 0 Apr 23 17:14:16 neumann volumio[833]: info: Setting Spotify Volume from Volumio: 14 Apr 23 17:14:16 neumann go-librespot[1199]: time="2025-04-23T17:14:16Z" level=debug msg="fetched first chunk of 20, total size is 10111216 bytes" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:16 neumann go-librespot[1199]: time="2025-04-23T17:14:16Z" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Apr 23 17:14:16 neumann volumio[833]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4b6zASM8nsUj4d493qWC1F","play_origin":"playlist/ondemand"}} Apr 23 17:14:16 neumann volumio[833]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 23 17:14:17 neumann volumio[833]: TypeError: Cannot read property 'service' of undefined Apr 23 17:14:17 neumann volumio[833]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) Apr 23 17:14:17 neumann volumio[833]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:263:18) Apr 23 17:14:17 neumann volumio[833]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Apr 23 17:14:17 neumann volumio[833]: at WebSocket.emit (events.js:315:20) Apr 23 17:14:17 neumann volumio[833]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Apr 23 17:14:17 neumann volumio[833]: at Receiver.emit (events.js:315:20) Apr 23 17:14:17 neumann volumio[833]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Apr 23 17:14:17 neumann volumio[833]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Apr 23 17:14:17 neumann volumio[833]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Apr 23 17:14:17 neumann volumio[833]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Apr 23 17:14:17 neumann volumio[833]: at writeOrBuffer (internal/streams/writable.js:358:12) Apr 23 17:14:17 neumann volumio[833]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Apr 23 17:14:17 neumann volumio[833]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Apr 23 17:14:17 neumann volumio[833]: at Socket.emit (events.js:315:20) Apr 23 17:14:17 neumann volumio[833]: at addChunk (internal/streams/readable.js:309:12) Apr 23 17:14:17 neumann volumio[833]: at readableAddChunk (internal/streams/readable.js:284:9) Apr 23 17:14:17 neumann volumio[833]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 23 17:14:18 neumann go-librespot[1199]: time="2025-04-23T17:14:18Z" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:19 neumann go-librespot[1199]: time="2025-04-23T17:14:19Z" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:21 neumann go-librespot[1199]: time="2025-04-23T17:14:21Z" level=debug msg="fetched chunk 13/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:21 neumann go-librespot[1199]: time="2025-04-23T17:14:21Z" level=debug msg="fetched chunk 12/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:21 neumann go-librespot[1199]: time="2025-04-23T17:14:21Z" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:21 neumann go-librespot[1199]: time="2025-04-23T17:14:21Z" level=debug msg="fetched chunk 11/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:21 neumann go-librespot[1199]: time="2025-04-23T17:14:21Z" level=debug msg="fetched chunk 10/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:21 neumann go-librespot[1199]: time="2025-04-23T17:14:21Z" level=trace msg="seek to 147017ms (diff: 66ms, samples: 6483449, bytes: 5386494)" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:22 neumann go-librespot[1199]: time="2025-04-23T17:14:22Z" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Apr 23 17:14:22 neumann go-librespot[1199]: time="2025-04-23T17:14:22Z" level=info msg="loaded track \"Nocturnes, Op. 32: No. 1 in B Major\" (paused: false, position: 147017ms, duration: 275826ms, prefetched: false)" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:22 neumann go-librespot[1199]: time="2025-04-23T17:14:22Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 17:14:22 neumann go-librespot[1199]: time="2025-04-23T17:14:22Z" level=trace msg="scheduling prefetch in 99s" Apr 23 17:14:22 neumann go-librespot[1199]: time="2025-04-23T17:14:22Z" level=trace msg="emitting websocket event: metadata" Apr 23 17:14:22 neumann go-librespot[1199]: time="2025-04-23T17:14:22Z" level=trace msg="emitting websocket event: active" Apr 23 17:14:22 neumann go-librespot[1199]: time="2025-04-23T17:14:22Z" level=debug msg="sending successful reply for dealer request" Apr 23 17:14:22 neumann go-librespot[1199]: time="2025-04-23T17:14:22Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 17:14:22 neumann go-librespot[1199]: time="2025-04-23T17:14:22Z" level=trace msg="emitting websocket event: playing" Apr 23 17:14:22 neumann go-librespot[1199]: time="2025-04-23T17:14:22Z" level=debug msg="handling transfer player command from ea4e31e744051af4a05808a322ace83580dee340" Apr 23 17:14:22 neumann go-librespot[1199]: time="2025-04-23T17:14:22Z" level=debug msg="resolved context of track" uri="spotify:playlist:0dZwJAM4pPfP4mQ9J2VlDV" Apr 23 17:14:22 neumann go-librespot[1199]: time="2025-04-23T17:14:22Z" level=trace msg="fetched new page 0 with 41 items (list: 41)" uri="spotify:playlist:0dZwJAM4pPfP4mQ9J2VlDV" Apr 23 17:14:22 neumann go-librespot[1199]: time="2025-04-23T17:14:22Z" level=debug msg="loading track (paused: false, position: 153881ms)" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:22 neumann go-librespot[1199]: time="2025-04-23T17:14:22Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 17:14:22 neumann go-librespot[1199]: time="2025-04-23T17:14:22Z" level=trace msg="emitting websocket event: will_play" Apr 23 17:14:22 neumann go-librespot[1199]: time="2025-04-23T17:14:22Z" level=debug msg="selected format OGG_VORBIS_320 (332d589785be4ee3d3c5d362ba0a52d7b963cf37)" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:22 neumann go-librespot[1199]: time="2025-04-23T17:14:22Z" level=debug msg="requested aes key for file 332d589785be4ee3d3c5d362ba0a52d7b963cf37, gid: 4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:23 neumann go-librespot[1199]: time="2025-04-23T17:14:23Z" level=debug msg="fetched first chunk of 20, total size is 10111216 bytes" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:23 neumann go-librespot[1199]: time="2025-04-23T17:14:23Z" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Apr 23 17:14:25 neumann go-librespot[1199]: time="2025-04-23T17:14:25Z" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:28 neumann go-librespot[1199]: time="2025-04-23T17:14:28Z" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:29 neumann go-librespot[1199]: time="2025-04-23T17:14:29Z" level=debug msg="fetched chunk 10/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:29 neumann go-librespot[1199]: time="2025-04-23T17:14:29Z" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:29 neumann go-librespot[1199]: time="2025-04-23T17:14:29Z" level=trace msg="seek to 153881ms (diff: 97ms, samples: 6786152, bytes: 5636827)" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:29 neumann go-librespot[1199]: time="2025-04-23T17:14:29Z" level=info msg="loaded track \"Nocturnes, Op. 32: No. 1 in B Major\" (paused: false, position: 153881ms, duration: 275826ms, prefetched: false)" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:29 neumann go-librespot[1199]: time="2025-04-23T17:14:29Z" level=debug msg="fetched chunk 12/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:29 neumann go-librespot[1199]: time="2025-04-23T17:14:29Z" level=debug msg="fetched chunk 11/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:29 neumann go-librespot[1199]: time="2025-04-23T17:14:29Z" level=debug msg="fetched chunk 13/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:29 neumann go-librespot[1199]: time="2025-04-23T17:14:29Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 17:14:29 neumann go-librespot[1199]: time="2025-04-23T17:14:29Z" level=trace msg="scheduling prefetch in 92s" Apr 23 17:14:29 neumann go-librespot[1199]: time="2025-04-23T17:14:29Z" level=trace msg="emitting websocket event: metadata" Apr 23 17:14:29 neumann go-librespot[1199]: time="2025-04-23T17:14:29Z" level=trace msg="emitting websocket event: active" Apr 23 17:14:29 neumann go-librespot[1199]: time="2025-04-23T17:14:29Z" level=debug msg="sending successful reply for dealer request" Apr 23 17:14:30 neumann go-librespot[1199]: time="2025-04-23T17:14:30Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 17:14:30 neumann go-librespot[1199]: time="2025-04-23T17:14:30Z" level=trace msg="emitting websocket event: playing" Apr 23 17:14:31 neumann volumio-remote-updater[512]: [2025-04-23 17:14:31] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] Apr 23 17:14:32 neumann volumio[833]: STREAMING PROXY: Starting server on port 3245 Apr 23 17:14:32 neumann volumio[833]: Node JS runtime: 14 Apr 23 17:14:34 neumann go-librespot[1199]: time="2025-04-23T17:14:34Z" level=debug msg="fetched chunk 14/19, size: 524288" uri="spotify:track:4b6zASM8nsUj4d493qWC1F" Apr 23 17:14:34 neumann sudo[1404]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-23 17:13 Apr 23 17:14:34 neumann sudo[1404]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"