-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sun 2025-05-04 19:52:33 CEST. -- May 04 19:52:13 stereoanlage systemd-timedated[978]: Changed local time to Sun May 4 19:52:13 2025 May 04 19:52:13 stereoanlage sudo[962]: pam_unix(sudo:session): session closed for user root May 04 19:52:13 stereoanlage volumio-time-update[673]: volumio-time-update-util: System time updated successfully. May 04 19:52:13 stereoanlage systemd[1]: Started Volumio Time Update Utility. May 04 19:52:13 stereoanlage systemd[1]: Starting Daily apt download activities... May 04 19:52:13 stereoanlage bthelper[784]: Changing power off succeeded May 04 19:52:13 stereoanlage bthelper[784]: [CHG] Controller B8:27:EB:36:6B:DD Class: 0x0000041c May 04 19:52:13 stereoanlage bthelper[784]: Changing power on succeeded May 04 19:52:14 stereoanlage ntpd[799]: Listen normally on 3 eth0 192.168.178.37:123 May 04 19:52:14 stereoanlage ntpd[799]: Listen normally on 4 wlan0 192.168.211.1:123 May 04 19:52:14 stereoanlage ntpd[799]: new interface(s) found: waking up resolver May 04 19:52:14 stereoanlage nmbd[788]: [2025/05/04 19:52:14.741163, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 04 19:52:14 stereoanlage nmbd[788]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections May 04 19:52:14 stereoanlage systemd[1]: Started Samba NMB Daemon. May 04 19:52:14 stereoanlage systemd[1]: Starting Samba Winbind Daemon... May 04 19:52:15 stereoanlage winbindd[1011]: [2025/05/04 19:52:15.359503, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) May 04 19:52:15 stereoanlage winbindd[1011]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 May 04 19:52:15 stereoanlage systemd[1]: Started Samba Winbind Daemon. May 04 19:52:15 stereoanlage winbindd[1011]: [2025/05/04 19:52:15.400034, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 04 19:52:15 stereoanlage winbindd[1011]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections May 04 19:52:15 stereoanlage systemd[1]: Starting Samba SMB Daemon... May 04 19:52:16 stereoanlage smbd[1016]: [2025/05/04 19:52:16.049591, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 04 19:52:16 stereoanlage systemd[1]: Started Samba SMB Daemon. May 04 19:52:16 stereoanlage smbd[1016]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections May 04 19:52:16 stereoanlage systemd[1]: Reached target Multi-User System. May 04 19:52:16 stereoanlage systemd[1]: Reached target Graphical Interface. May 04 19:52:16 stereoanlage systemd[1]: Starting Update UTMP about System Runlevel Changes... May 04 19:52:16 stereoanlage systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. May 04 19:52:16 stereoanlage systemd[1]: Started Update UTMP about System Runlevel Changes. May 04 19:52:16 stereoanlage volumio[965]: info: ------------------------------------------- May 04 19:52:16 stereoanlage volumio[965]: info: ----- Volumio3 ---- May 04 19:52:16 stereoanlage volumio[965]: info: ------------------------------------------- May 04 19:52:16 stereoanlage volumio[965]: info: ----- System startup ---- May 04 19:52:16 stereoanlage volumio[965]: info: ------------------------------------------- May 04 19:52:16 stereoanlage systemd[1]: apt-daily.service: Succeeded. May 04 19:52:16 stereoanlage systemd[1]: Started Daily apt download activities. May 04 19:52:17 stereoanlage systemd[1]: Starting Daily apt upgrade and clean activities... May 04 19:52:18 stereoanlage volumio[965]: info: MYVOLUMIO Environment detected May 04 19:52:18 stereoanlage volumio[965]: info: Plugin folders cleanup May 04 19:52:18 stereoanlage volumio[965]: info: Scanning into folder /volumio/app/plugins/ May 04 19:52:18 stereoanlage volumio[965]: info: Scanning category audio_interface May 04 19:52:18 stereoanlage volumio[965]: info: Scanning category miscellanea May 04 19:52:18 stereoanlage volumio[965]: info: Scanning category music_service May 04 19:52:18 stereoanlage volumio[965]: info: Scanning category plugins.json May 04 19:52:18 stereoanlage volumio[965]: info: Scanning category system_controller May 04 19:52:18 stereoanlage volumio[965]: info: Scanning category user_interface May 04 19:52:18 stereoanlage volumio[965]: info: Scanning into folder /data/plugins/ May 04 19:52:18 stereoanlage volumio[965]: info: Scanning category music_service May 04 19:52:18 stereoanlage volumio[965]: info: Plugin folders cleanup completed May 04 19:52:18 stereoanlage volumio[965]: info: ------------------------------------------- May 04 19:52:18 stereoanlage volumio[965]: info: ----- Core plugins startup ---- May 04 19:52:18 stereoanlage volumio[965]: info: ------------------------------------------- May 04 19:52:18 stereoanlage volumio[965]: info: Loading plugins from folder /volumio/app/plugins/ May 04 19:52:18 stereoanlage volumio[965]: info: Adding plugin upnp to MyMusic Plugins May 04 19:52:18 stereoanlage volumio[965]: info: Adding plugin airplay_emulation to MyMusic Plugins May 04 19:52:18 stereoanlage volumio[965]: info: Adding plugin upnp_browser to MyMusic Plugins May 04 19:52:18 stereoanlage volumio[965]: info: Loading plugins from folder /data/plugins/ May 04 19:52:18 stereoanlage volumio[965]: info: Loading plugin "system"... May 04 19:52:18 stereoanlage volumio[965]: info: Loading plugin "appearance"... May 04 19:52:18 stereoanlage systemd[1]: apt-daily-upgrade.service: Succeeded. May 04 19:52:18 stereoanlage systemd[1]: Started Daily apt upgrade and clean activities. May 04 19:52:18 stereoanlage systemd[1]: Startup finished in 13.962s (kernel) + 17.205s (userspace) = 31.168s. May 04 19:52:19 stereoanlage volumio[965]: info: Loading plugin "network"... May 04 19:52:19 stereoanlage volumio[965]: info: Refreshing Cached IP Addresses May 04 19:52:19 stereoanlage sudo[1116]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 04 19:52:19 stereoanlage sudo[1116]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 19:52:19 stereoanlage sudo[1116]: pam_unix(sudo:session): session closed for user root May 04 19:52:19 stereoanlage sudo[1118]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 04 19:52:19 stereoanlage sudo[1118]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 19:52:20 stereoanlage sudo[1118]: pam_unix(sudo:session): session closed for user root May 04 19:52:20 stereoanlage volumio[965]: info: Loading plugin "services"... May 04 19:52:20 stereoanlage volumio[965]: info: Loading plugin "alsa_controller"... May 04 19:52:20 stereoanlage sudo[1127]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 04 19:52:20 stereoanlage sudo[1127]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 19:52:20 stereoanlage volumio-remote-updater[699]: [2025-05-04 19:52:20] [connect] Successful connection May 04 19:52:20 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 04 19:52:20 stereoanlage volumio[965]: info: Loading plugin "wizard"... May 04 19:52:20 stereoanlage volumio[965]: info: Loading plugin "networkfs"... May 04 19:52:20 stereoanlage sudo[1144]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=music,password=synMusic0815,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.178.31/music\\Losless /mnt/NAS/FLACs May 04 19:52:20 stereoanlage sudo[1144]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 19:52:20 stereoanlage volumio[965]: info: Starting Udev Watcher for removable devices May 04 19:52:20 stereoanlage sudo[1146]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=music,password=synMusic0815,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.178.31/music\\Diverse /mnt/NAS/MP3s May 04 19:52:20 stereoanlage sudo[1146]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 19:52:20 stereoanlage sudo[1149]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=music,password=synMusic0815,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.178.31/music\\Sampler /mnt/NAS/Sampler May 04 19:52:20 stereoanlage sudo[1149]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 19:52:20 stereoanlage volumio[965]: info: Ignoring mount for partition: boot May 04 19:52:20 stereoanlage volumio[965]: info: Ignoring mount for partition: volumio May 04 19:52:20 stereoanlage volumio[965]: info: Ignoring mount for partition: volumio_data May 04 19:52:20 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 04 19:52:20 stereoanlage volumio[965]: info: Loading plugin "volumio_command_line_client"... May 04 19:52:20 stereoanlage volumio[965]: info: Loading plugin "upnp"... May 04 19:52:20 stereoanlage volumio[965]: info: [1746381140344] Starting Upmpd Daemon May 04 19:52:20 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 04 19:52:20 stereoanlage volumio[965]: info: Loading plugin "my_music"... May 04 19:52:20 stereoanlage volumio[965]: info: Loading plugin "mpd"... May 04 19:52:20 stereoanlage kernel: Key type cifs.spnego registered May 04 19:52:20 stereoanlage kernel: Key type cifs.idmap registered May 04 19:52:20 stereoanlage kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. May 04 19:52:20 stereoanlage kernel: CIFS: Attempting to mount //192.168.178.31/music/Sampler May 04 19:52:20 stereoanlage kernel: cryptd: max_cpu_qlen set to 1000 May 04 19:52:20 stereoanlage sudo[1127]: pam_unix(sudo:session): session closed for user root May 04 19:52:20 stereoanlage volumio[965]: info: Loading plugin "upnp_browser"... May 04 19:52:21 stereoanlage kernel: CIFS: Attempting to mount //192.168.178.31/music/Losless May 04 19:52:21 stereoanlage sudo[1149]: pam_unix(sudo:session): session closed for user root May 04 19:52:21 stereoanlage sudo[1144]: pam_unix(sudo:session): session closed for user root May 04 19:52:21 stereoanlage kernel: CIFS: Attempting to mount //192.168.178.31/music/Diverse May 04 19:52:21 stereoanlage sudo[1146]: pam_unix(sudo:session): session closed for user root May 04 19:52:21 stereoanlage volumio[965]: info: Loading plugin "alarm-clock"... May 04 19:52:21 stereoanlage volumio[965]: info: Plugin airplay_emulation is not enabled May 04 19:52:21 stereoanlage volumio[965]: info: Loading plugin "last_100"... May 04 19:52:21 stereoanlage volumio[965]: info: Loading plugin "webradio"... May 04 19:52:21 stereoanlage volumio[965]: info: Loading plugin "i2s_dacs"... May 04 19:52:21 stereoanlage volumio[965]: info: Loading plugin "volumiodiscovery"... May 04 19:52:21 stereoanlage volumio[965]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 04 19:52:21 stereoanlage volumio[965]: *** WARNING *** Please fix your application to use the native API of Avahi! May 04 19:52:21 stereoanlage volumio[965]: *** WARNING *** For more information see May 04 19:52:21 stereoanlage node[965]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 04 19:52:21 stereoanlage volumio[965]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 04 19:52:21 stereoanlage volumio[965]: *** WARNING *** Please fix your application to use the native API of Avahi! May 04 19:52:21 stereoanlage volumio[965]: *** WARNING *** For more information see May 04 19:52:21 stereoanlage node[965]: *** WARNING *** Please fix your application to use the native API of Avahi! May 04 19:52:21 stereoanlage node[965]: *** WARNING *** For more information see May 04 19:52:21 stereoanlage node[965]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 04 19:52:21 stereoanlage node[965]: *** WARNING *** Please fix your application to use the native API of Avahi! May 04 19:52:21 stereoanlage node[965]: *** WARNING *** For more information see May 04 19:52:21 stereoanlage volumio[965]: info: Applying required configuration parameters for plugin volumiodiscovery May 04 19:52:21 stereoanlage volumio[965]: info: Discovery: Started advertising with name: Stereoanlage May 04 19:52:21 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 04 19:52:21 stereoanlage volumio[965]: info: Loading plugin "spop"... May 04 19:52:23 stereoanlage volumio[965]: info: Loading plugin "outputs"... May 04 19:52:23 stereoanlage volumio[965]: info: Loading plugin "albumart"... May 04 19:52:23 stereoanlage volumio[965]: info: Plugin example_plugin is not enabled May 04 19:52:23 stereoanlage volumio[965]: info: Loading plugin "inputs"... May 04 19:52:23 stereoanlage volumio[965]: info: Loading plugin "updater_comm"... May 04 19:52:24 stereoanlage volumio[965]: info: Plugin mpdemulation is not enabled May 04 19:52:24 stereoanlage volumio[965]: info: Loading plugin "rest_api"... May 04 19:52:24 stereoanlage volumio[965]: info: Loading plugin "websocket"... May 04 19:52:24 stereoanlage volumio[965]: info: Starting Socket.io Server version 2.3.0 May 04 19:52:24 stereoanlage volumio[965]: info: Loading i18n strings for locale de May 04 19:52:24 stereoanlage volumio[965]: Updating browse sources language May 04 19:52:24 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 19:52:24 stereoanlage volumio[965]: Forking 3 albumart workers May 04 19:52:24 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 04 19:52:24 stereoanlage volumio[965]: info: CoreCommandRouter::initPlayerControls May 04 19:52:24 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:24 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:24 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:24 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:24 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:24 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:24 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:24 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:24 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 04 19:52:24 stereoanlage volumio[965]: Express server listening on port 3000 May 04 19:52:24 stereoanlage volumio[965]: [Metrics] WebUI: 9s 27.65ms May 04 19:52:24 stereoanlage volumio[965]: info: CoreStateMachine::resetVolumioState May 04 19:52:24 stereoanlage volumio[965]: info: CoreStateMachine::getcurrentVolume May 04 19:52:24 stereoanlage volumio[965]: info: CoreCommandRouter::volumioRetrievevolume May 04 19:52:24 stereoanlage volumio[965]: info: Volumio Network Manager: Network status updated: 1 May 04 19:52:24 stereoanlage volumio-remote-updater[699]: [2025-05-04 19:52:24] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1746381140 101 May 04 19:52:24 stereoanlage volumio[965]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 May 04 19:52:24 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 04 19:52:24 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 04 19:52:24 stereoanlage volumio[965]: info: Discovery: Getting this device information May 04 19:52:24 stereoanlage volumio[965]: info: CoreCommandRouter::volumioGetState May 04 19:52:24 stereoanlage volumio[965]: info: CorePlayQueue::getTrack 0 May 04 19:52:24 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 04 19:52:24 stereoanlage volumio[965]: info: Reloading queue from file May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 19:52:25 stereoanlage volumio[965]: info: VolumeController:: Volume=40 Mute =false May 04 19:52:25 stereoanlage volumio[965]: info: CoreStateMachine::pushState May 04 19:52:25 stereoanlage volumio[965]: info: CorePlayQueue::getTrack 0 May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::volumioPushState May 04 19:52:25 stereoanlage volumio[965]: info: CoreStateMachine::updateTrackBlock May 04 19:52:25 stereoanlage volumio[965]: info: CorePlayQueue::getTrackBlock May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::volumioRetrievevolume May 04 19:52:25 stereoanlage volumio[965]: info: CoreStateMachine::setRepeat false single undefined May 04 19:52:25 stereoanlage volumio[965]: info: CoreStateMachine::pushState May 04 19:52:25 stereoanlage volumio[965]: info: CorePlayQueue::getTrack 0 May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::volumioPushState May 04 19:52:25 stereoanlage volumio[965]: info: CoreStateMachine::setRandom null May 04 19:52:25 stereoanlage volumio[965]: info: CoreStateMachine::pushState May 04 19:52:25 stereoanlage volumio[965]: info: CorePlayQueue::getTrack 0 May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::volumioPushState May 04 19:52:25 stereoanlage volumio[965]: info: Setting Device type: Raspberry PI May 04 19:52:25 stereoanlage volumio[965]: info: Completed loading Core Plugins May 04 19:52:25 stereoanlage volumio[965]: info: Preparing to generate the ALSA configuration file May 04 19:52:25 stereoanlage volumio[965]: info: Asound.conf file unchanged, so no further update is needed May 04 19:52:25 stereoanlage volumio[965]: info: Output device has changed, restarting MPD May 04 19:52:25 stereoanlage volumio[965]: info: ___________ START PLUGINS ___________ May 04 19:52:25 stereoanlage volumio[965]: info: ControllerMpd::onStart: Initializing MPD May 04 19:52:25 stereoanlage sudo[1240]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 04 19:52:25 stereoanlage volumio[965]: info: Creating MPD Configuration file May 04 19:52:25 stereoanlage sudo[1240]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 19:52:25 stereoanlage sudo[1242]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 04 19:52:25 stereoanlage sudo[1242]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 19:52:25 stereoanlage sudo[1240]: pam_unix(sudo:session): session closed for user root May 04 19:52:25 stereoanlage volumio[965]: Starting albumart workers May 04 19:52:25 stereoanlage volumio[965]: Starting albumart workers May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 19:52:25 stereoanlage systemd[1]: Stopping Music Player Daemon... May 04 19:52:25 stereoanlage volumio[965]: info: [1746381145333] CoreMusicLibrary::Adding element Medienserver May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 19:52:25 stereoanlage volumio[965]: Starting albumart workers May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 19:52:25 stereoanlage volumio[965]: info: [1746381145374] CoreMusicLibrary::Adding element Last_100 May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 19:52:25 stereoanlage sudo[1246]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 04 19:52:25 stereoanlage sudo[1246]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 19:52:25 stereoanlage sudo[1248]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 19:52:25 stereoanlage volumio[965]: info: [1746381145383] CoreMusicLibrary::Adding element Webradio May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 19:52:25 stereoanlage sudo[1248]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 19:52:25 stereoanlage sudo[1246]: pam_unix(sudo:session): session closed for user root May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 04 19:52:25 stereoanlage volumio[965]: info: Initializing BBC Radios May 04 19:52:25 stereoanlage systemd[1]: mpd.service: Succeeded. May 04 19:52:25 stereoanlage systemd[1]: Stopped Music Player Daemon. May 04 19:52:25 stereoanlage systemd[1]: Starting Music Player Daemon... May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 19:52:25 stereoanlage volumio[965]: info: Creating Spotify config file May 04 19:52:25 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:25 stereoanlage sudo[1253]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 04 19:52:25 stereoanlage sudo[1253]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 19:52:25 stereoanlage sudo[1253]: pam_unix(sudo:session): session closed for user root May 04 19:52:25 stereoanlage volumio[965]: info: Volumio Calling Home May 04 19:52:26 stereoanlage volumio[965]: info: Discovery: adding 43a0dd76-32ee-46d1-99a3-2cc217fa3f43 May 04 19:52:26 stereoanlage volumio[965]: info: Discovery: Found device Stereoanlage May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::volumioGetState May 04 19:52:26 stereoanlage volumio[965]: info: CorePlayQueue::getTrack 0 May 04 19:52:26 stereoanlage volumio[965]: info: Discovery: this is already registered, 43a0dd76-32ee-46d1-99a3-2cc217fa3f43 May 04 19:52:26 stereoanlage volumio[965]: info: Discovery: Found device Stereoanlage May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::volumioGetState May 04 19:52:26 stereoanlage volumio[965]: info: CorePlayQueue::getTrack 0 May 04 19:52:26 stereoanlage volumio[965]: info: MPD Permissions set May 04 19:52:26 stereoanlage volumio[965]: info: MPD Permissions set May 04 19:52:26 stereoanlage volumio[965]: info: VolumeController:: Volume=40 Mute =false May 04 19:52:26 stereoanlage volumio[965]: info: CoreStateMachine::pushState May 04 19:52:26 stereoanlage volumio[965]: info: CorePlayQueue::getTrack 0 May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::volumioPushState May 04 19:52:26 stereoanlage volumio[965]: info: Spotify config file written May 04 19:52:26 stereoanlage sudo[1285]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 04 19:52:26 stereoanlage sudo[1285]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 19:52:26 stereoanlage volumio[965]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:26 stereoanlage systemd[1]: Started go-librespot Daemon. May 04 19:52:26 stereoanlage go-librespot[1294]: Librespot-go daemon starting... May 04 19:52:26 stereoanlage sudo[1285]: pam_unix(sudo:session): session closed for user root May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 19:52:26 stereoanlage volumio[965]: info: Volumio called home May 04 19:52:26 stereoanlage volumio[965]: info: CoreCommandRouter::volumioGetState May 04 19:52:26 stereoanlage volumio[965]: info: CorePlayQueue::getTrack 0 May 04 19:52:26 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:26+02:00" level=info msg="generated new device id: 7fe41377fab3339c2faa36f83a88de56b0c2a91c" May 04 19:52:26 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:26+02:00" level=debug msg="stored credentials found for bokelt" May 04 19:52:27 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:27+02:00" 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-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 04 19:52:27 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:27+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 04 19:52:27 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:27+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 04 19:52:27 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:27+02:00" level=debug msg="zeroconf server listening on port 36857" May 04 19:52:27 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:27+02:00" level=debug msg="obtained new client token: AACD9ruYj6vMuneavRKqqByspgCT0tatg+Dl8Ml+P9emrYLZXyHxZvHqsTCc7mo6c2VzHMiPeuEpsl9tXPUAR9eD/uDb5Fa9TCw0l8UMHtIrRLDaEOk7lPaBqy/dEFr4NEqqRh0Tky0IkznT/mdhtaj8byYq5s3yz04m7lVeZVPu/Ne6wNor8+lKtki8e6et/Lm9EgSJ2kwP0n3y1EsR3edWPcKHO8c/sB21M+W+t5Wb2HSbV1vgmBQLPVE=" May 04 19:52:27 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:27+02:00" level=debug msg="completed keyexchange" May 04 19:52:27 stereoanlage mpd[1263]: May 04 19:52 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 04 19:52:27 stereoanlage systemd[1]: Started Music Player Daemon. May 04 19:52:27 stereoanlage sudo[1248]: pam_unix(sudo:session): session closed for user root May 04 19:52:27 stereoanlage sudo[1242]: pam_unix(sudo:session): session closed for user root May 04 19:52:27 stereoanlage volumio[965]: info: Completed starting Core Plugins May 04 19:52:27 stereoanlage volumio[965]: info: ------------------------------------------- May 04 19:52:27 stereoanlage volumio[965]: info: ----- MyVolumio plugins startup ---- May 04 19:52:27 stereoanlage volumio[965]: info: ------------------------------------------- May 04 19:52:27 stereoanlage volumio[965]: info: [MyVolumio PluginManager] Fetching plans data.... May 04 19:52:27 stereoanlage volumio[965]: error: MPD error: The expression evaluated to a falsy value: May 04 19:52:27 stereoanlage volumio[965]: assert.ok(self.idling) May 04 19:52:27 stereoanlage volumio[965]: error: The expression evaluated to a falsy value: May 04 19:52:27 stereoanlage volumio[965]: assert.ok(self.idling) May 04 19:52:27 stereoanlage volumio[965]: info: MPD running with PID1263 May 04 19:52:27 stereoanlage volumio[965]: ,establishing connection May 04 19:52:27 stereoanlage volumio[965]: error: MPD error: The expression evaluated to a falsy value: May 04 19:52:27 stereoanlage volumio[965]: assert.ok(self.idling) May 04 19:52:27 stereoanlage volumio[965]: error: The expression evaluated to a falsy value: May 04 19:52:27 stereoanlage volumio[965]: assert.ok(self.idling) May 04 19:52:27 stereoanlage volumio[965]: error: updateQueue error: null May 04 19:52:28 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:28+02:00" level=debug msg="completed challenge" May 04 19:52:28 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:28+02:00" level=debug msg="authenticated as bokelt" May 04 19:52:28 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:28+02:00" level=debug msg="authenticated as bokelt" May 04 19:52:28 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:28+02:00" level=debug msg="dealer connection opened" May 04 19:52:28 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:28+02:00" level=debug msg="initializing zeroconf session, username: bokelt" May 04 19:52:28 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:28+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 04 19:52:28 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:28+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 04 19:52:28 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:28+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 04 19:52:28 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:28+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 04 19:52:28 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:28+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 04 19:52:28 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:28+02:00" level=debug msg="autoplay enabled: false" May 04 19:52:28 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:28+02:00" level=debug msg="received connection id: OTMzODZkOWEtNzBhNS00NGRmLTg5ZjItMGZmMTQ4OTAyNGI0K2RlYWxlcit0Y3A6Ly8wYWNhNTkzZi5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNzUwODA3NDQyOUE2MTA1OUQzNzQ5RkIxOENFNTQ0NDVBQUVCMUQ3MEMwOTQ0NkM2N0JCRjE4MTdDQUZCODVFNQ==" May 04 19:52:28 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:28+02:00" level=debug msg="put connect state because NEW_DEVICE" May 04 19:52:29 stereoanlage volumio[965]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 04 19:52:29 stereoanlage volumio[965]: SPOTIFY: BQDJ9KD2WYvwC8IrGi2YkqyvZOILZjIjYQz85PixIvVKZ3X8s9JnVP42NXarku168UiLsx_We7TVGKXnQ-ZjN9E0NBjk6ATehnihST4dXLU0kDUbL-fZlNQP2vwW1XVA8izOOK6NPyGbM0V1TSV0d20UpSgOxNhiumGhBO0bVfty1_27Hbrpn9-UnR77_zBoP6GViL_FmUQW-U6yMmnxCQA_tWwazLFVbcU7nXl1c45N6gbPOTSTRypD2r5QS727vmtQmG8RLx8YZ3rViA May 04 19:52:29 stereoanlage volumio[965]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 04 19:52:29 stereoanlage volumio[965]: info: New Spotify access token = BQDJ9KD2WYvwC8IrGi2YkqyvZOILZjIjYQz85PixIvVKZ3X8s9JnVP42NXarku168UiLsx_We7TVGKXnQ-ZjN9E0NBjk6ATehnihST4dXLU0kDUbL-fZlNQP2vwW1XVA8izOOK6NPyGbM0V1TSV0d20UpSgOxNhiumGhBO0bVfty1_27Hbrpn9-UnR77_zBoP6GViL_FmUQW-U6yMmnxCQA_tWwazLFVbcU7nXl1c45N6gbPOTSTRypD2r5QS727vmtQmG8RLx8YZ3rViA May 04 19:52:29 stereoanlage volumio[965]: info: Spotify credentials grant success - running version from March 24, 2019 May 04 19:52:29 stereoanlage volumio[965]: SPOTIFY: User informations: {"country":"DE","display_name":"bokelt","email":"christoph.eiting@gmx.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/bokelt"},"followers":{"href":null,"total":4},"href":"https://api.spotify.com/v1/users/bokelt","id":"bokelt","images":[],"product":"premium","type":"user","uri":"spotify:user:bokelt"} May 04 19:52:29 stereoanlage volumio[965]: info: Spotify Successfully logged in May 04 19:52:29 stereoanlage volumio[965]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 19:52:29 stereoanlage volumio[965]: info: [1746381149167] CoreMusicLibrary::Adding element Spotify May 04 19:52:29 stereoanlage volumio[965]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 19:52:29 stereoanlage volumio[965]: Cannot find translation for source Spotify May 04 19:52:29 stereoanlage volumio[965]: info: go-librespot daemon successfully initialized May 04 19:52:30 stereoanlage sudo[1330]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 04 19:52:30 stereoanlage sudo[1330]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 19:52:30 stereoanlage sudo[1330]: pam_unix(sudo:session): session closed for user root May 04 19:52:30 stereoanlage sudo[1332]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 04 19:52:30 stereoanlage sudo[1332]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 19:52:30 stereoanlage sudo[1332]: pam_unix(sudo:session): session closed for user root May 04 19:52:30 stereoanlage sudo[1336]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 04 19:52:30 stereoanlage sudo[1336]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 19:52:30 stereoanlage systemd[1]: Started UPnP Renderer front-end to MPD. May 04 19:52:30 stereoanlage sudo[1336]: pam_unix(sudo:session): session closed for user root May 04 19:52:30 stereoanlage volumio[965]: info: Upmpdcli Daemon Started May 04 19:52:30 stereoanlage volumio[1338]: Generating RSA private key, 4096 bit long modulus (2 primes) May 04 19:52:30 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:30+02:00" level=debug msg="handling transfer player command from 0768a46744e6f645a6a9bf86fc45cff997dd5bde" May 04 19:52:31 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:31+02:00" level=debug msg="resolved context of track" uri="spotify:album:3jlE37AdgcZbfsfyMutyCE" May 04 19:52:31 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:31+02:00" level=trace msg="fetched new page 0 with 10 items (list: 10)" uri="spotify:album:3jlE37AdgcZbfsfyMutyCE" May 04 19:52:31 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:31+02:00" level=debug msg="loading track (paused: true, position: 222611ms)" uri="spotify:track:74xPArLv8AUYyD2E8MDi6w" May 04 19:52:31 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:31+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 19:52:31 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:31+02:00" level=trace msg="emitting websocket event: will_play" May 04 19:52:31 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:31+02:00" level=debug msg="selected format OGG_VORBIS_320 (b78d1df177650b6df082f8b4cd8bec736f249941)" uri="spotify:track:74xPArLv8AUYyD2E8MDi6w" May 04 19:52:31 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:31+02:00" level=debug msg="requested aes key for file b78d1df177650b6df082f8b4cd8bec736f249941, gid: 74xPArLv8AUYyD2E8MDi6w" May 04 19:52:31 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:31+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" May 04 19:52:31 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:31+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1329" May 04 19:52:31 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:31+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1111" May 04 19:52:31 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:31+02:00" level=debug msg="fetched first chunk of 21, total size is 10591114 bytes" uri="spotify:track:74xPArLv8AUYyD2E8MDi6w" May 04 19:52:31 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:31+02:00" level=debug msg="fetched chunk 1/20, size: 524288" uri="spotify:track:74xPArLv8AUYyD2E8MDi6w" May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=debug msg="fetched chunk 3/20, size: 524288" uri="spotify:track:74xPArLv8AUYyD2E8MDi6w" May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=debug msg="fetched chunk 18/20, size: 524288" uri="spotify:track:74xPArLv8AUYyD2E8MDi6w" May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=debug msg="fetched chunk 2/20, size: 524288" uri="spotify:track:74xPArLv8AUYyD2E8MDi6w" May 04 19:52:32 stereoanlage volumio[965]: info: Initializing connection to go-librespot Websocket May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=debug msg="new websocket client" May 04 19:52:32 stereoanlage volumio[965]: info: Connection to go-librespot Websocket established May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=debug msg="fetched chunk 16/20, size: 524288" uri="spotify:track:74xPArLv8AUYyD2E8MDi6w" May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=trace msg="seek to 222611ms (diff: 93ms, samples: 9817145, bytes: 8767135)" uri="spotify:track:74xPArLv8AUYyD2E8MDi6w" May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=debug msg="fetched chunk 19/20, size: 524288" uri="spotify:track:74xPArLv8AUYyD2E8MDi6w" May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" 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" May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=debug msg="created new output device" May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=info msg="loaded track \"LA\" (paused: true, position: 222611ms, duration: 271960ms, prefetched: false)" uri="spotify:track:74xPArLv8AUYyD2E8MDi6w" May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=trace msg="emitting websocket event: metadata" May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=trace msg="emitting websocket event: active" May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=debug msg="sending successful reply for dealer request" May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 04 19:52:32 stereoanlage volumio[965]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:74xPArLv8AUYyD2E8MDi6w","name":"LA","artist_names":["London Grammar"],"album_name":"The Greatest Love","album_cover_url":"https://i.scdn.co/image/ab67616d00001e026652aef466dc62bb14a53052","position":222611,"duration":271960,"release_date":"year:2024 month:9 day:13","track_number":4,"disc_number":1}} May 04 19:52:32 stereoanlage volumio[965]: SPOTIFY: received: {"type":"active","data":null} May 04 19:52:32 stereoanlage volumio[965]: info: Aligning Spotify Volume to Volumio Volume May 04 19:52:32 stereoanlage volumio[965]: info: CoreCommandRouter::volumioGetState May 04 19:52:32 stereoanlage volumio[965]: info: CorePlayQueue::getTrack 0 May 04 19:52:32 stereoanlage volumio[965]: info: Setting Spotify Volume from Volumio: 40 May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=debug msg="fetched chunk 17/20, size: 524288" uri="spotify:track:74xPArLv8AUYyD2E8MDi6w" May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 19:52:32 stereoanlage go-librespot[1294]: time="2025-05-04T19:52:32+02:00" level=trace msg="emitting websocket event: paused" May 04 19:52:32 stereoanlage volumio[965]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:74xPArLv8AUYyD2E8MDi6w","play_origin":"album"}} May 04 19:52:32 stereoanlage volumio[965]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 04 19:52:32 stereoanlage volumio[965]: TypeError: Cannot read property 'service' of undefined May 04 19:52:32 stereoanlage volumio[965]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) May 04 19:52:32 stereoanlage volumio[965]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:270:18) May 04 19:52:32 stereoanlage volumio[965]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) May 04 19:52:32 stereoanlage volumio[965]: at WebSocket.emit (events.js:315:20) May 04 19:52:32 stereoanlage volumio[965]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) May 04 19:52:32 stereoanlage volumio[965]: at Receiver.emit (events.js:315:20) May 04 19:52:32 stereoanlage volumio[965]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) May 04 19:52:32 stereoanlage volumio[965]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) May 04 19:52:32 stereoanlage volumio[965]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) May 04 19:52:32 stereoanlage volumio[965]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) May 04 19:52:32 stereoanlage volumio[965]: at writeOrBuffer (internal/streams/writable.js:358:12) May 04 19:52:32 stereoanlage volumio[965]: at Receiver.Writable.write (internal/streams/writable.js:303:10) May 04 19:52:32 stereoanlage volumio[965]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) May 04 19:52:32 stereoanlage volumio[965]: at Socket.emit (events.js:315:20) May 04 19:52:32 stereoanlage volumio[965]: at addChunk (internal/streams/readable.js:309:12) May 04 19:52:32 stereoanlage volumio[965]: at readableAddChunk (internal/streams/readable.js:284:9) May 04 19:52:32 stereoanlage volumio[965]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 04 19:52:33 stereoanlage sudo[1367]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-04 19:51 May 04 19:52:33 stereoanlage sudo[1367]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 06:54:47 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="436f3f84f6d0b4ffc344f0bc132a32e8"