-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Thu 2025-02-20 09:51:52 CET. -- Feb 20 09:51:11 volumio systemd-timedated[1018]: Changed local time to Thu Feb 20 09:51:11 2025 Feb 20 09:51:11 volumio sudo[1011]: pam_unix(sudo:session): session closed for user root Feb 20 09:51:11 volumio volumio-time-update[586]: volumio-time-update-util: System time updated successfully. Feb 20 09:51:11 volumio systemd[1]: Starting Daily man-db regeneration... Feb 20 09:51:11 volumio systemd[1]: Starting Daily apt download activities... Feb 20 09:51:11 volumio systemd[1]: Started Volumio Time Update Utility. Feb 20 09:51:11 volumio systemd[1]: Reached target Multi-User System. Feb 20 09:51:11 volumio systemd[1]: Reached target Graphical Interface. Feb 20 09:51:11 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... Feb 20 09:51:11 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Feb 20 09:51:11 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. Feb 20 09:51:12 volumio sh[468]: timed out Feb 20 09:51:12 volumio dhcpcd[519]: timed out Feb 20 09:51:14 volumio systemd[1]: systemd-hostnamed.service: Succeeded. Feb 20 09:51:14 volumio sh[468]: dhcpcd exited Feb 20 09:51:14 volumio dhcpcd[519]: dhcpcd exited Feb 20 09:51:14 volumio sh[468]: ifup: failed to bring up eth0 Feb 20 09:51:14 volumio systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Feb 20 09:51:14 volumio systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Feb 20 09:51:15 volumio volumio-remote-updater[579]: [2025-02-20 09:51:15] [info] asio async_connect error: system:111 (Connection refused) Feb 20 09:51:15 volumio volumio-remote-updater[579]: [2025-02-20 09:51:15] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Feb 20 09:51:15 volumio volumio-remote-updater[579]: [2025-02-20 09:51:15] [error] handle_connect error: Underlying Transport Error Feb 20 09:51:15 volumio systemd[1]: man-db.service: Succeeded. Feb 20 09:51:15 volumio systemd[1]: Started Daily man-db regeneration. Feb 20 09:51:17 volumio volumio[979]: info: ------------------------------------------- Feb 20 09:51:17 volumio volumio[979]: info: ----- Volumio3 ---- Feb 20 09:51:17 volumio volumio[979]: info: ------------------------------------------- Feb 20 09:51:17 volumio volumio[979]: info: ----- System startup ---- Feb 20 09:51:17 volumio volumio[979]: info: ------------------------------------------- Feb 20 09:51:17 volumio sshd[1058]: Did not receive identification string from 10.10.1.1 port 36266 Feb 20 09:51:18 volumio volumio[979]: info: MYVOLUMIO Environment detected Feb 20 09:51:18 volumio systemd[1]: apt-daily.service: Succeeded. Feb 20 09:51:18 volumio systemd[1]: Started Daily apt download activities. Feb 20 09:51:18 volumio systemd[1]: Starting Daily apt upgrade and clean activities... Feb 20 09:51:18 volumio volumio[979]: info: Plugin folders cleanup Feb 20 09:51:18 volumio volumio[979]: info: Scanning into folder /volumio/app/plugins/ Feb 20 09:51:18 volumio volumio[979]: info: Scanning category audio_interface Feb 20 09:51:18 volumio volumio[979]: info: Scanning category miscellanea Feb 20 09:51:18 volumio volumio[979]: info: Scanning category music_service Feb 20 09:51:18 volumio volumio[979]: info: Scanning category plugins.json Feb 20 09:51:18 volumio volumio[979]: info: Scanning category system_controller Feb 20 09:51:18 volumio volumio[979]: info: Scanning category user_interface Feb 20 09:51:18 volumio volumio[979]: info: Scanning into folder /data/plugins/ Feb 20 09:51:18 volumio volumio[979]: info: Scanning category music_service Feb 20 09:51:18 volumio volumio[979]: info: Scanning category system_hardware Feb 20 09:51:18 volumio volumio[979]: info: Scanning category user_interface Feb 20 09:51:18 volumio volumio[979]: info: Plugin folders cleanup completed Feb 20 09:51:18 volumio volumio[979]: info: ------------------------------------------- Feb 20 09:51:18 volumio volumio[979]: info: ----- Core plugins startup ---- Feb 20 09:51:18 volumio volumio[979]: info: ------------------------------------------- Feb 20 09:51:18 volumio volumio[979]: info: Loading plugins from folder /volumio/app/plugins/ Feb 20 09:51:18 volumio volumio[979]: info: Adding plugin upnp to MyMusic Plugins Feb 20 09:51:18 volumio volumio[979]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 20 09:51:18 volumio volumio[979]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 20 09:51:18 volumio volumio[979]: info: Loading plugins from folder /data/plugins/ Feb 20 09:51:18 volumio volumio[979]: info: Loading plugin "system"... Feb 20 09:51:18 volumio volumio[979]: info: Loading plugin "appearance"... Feb 20 09:51:20 volumio volumio[979]: info: Loading plugin "network"... Feb 20 09:51:20 volumio systemd[1]: apt-daily-upgrade.service: Succeeded. Feb 20 09:51:20 volumio systemd[1]: Started Daily apt upgrade and clean activities. Feb 20 09:51:20 volumio systemd[1]: Startup finished in 19.078s (kernel) + 45.177s (userspace) = 1min 4.255s. Feb 20 09:51:20 volumio volumio[979]: info: Refreshing Cached IP Addresses Feb 20 09:51:20 volumio sudo[1145]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 20 09:51:20 volumio sudo[1145]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 09:51:20 volumio sudo[1145]: pam_unix(sudo:session): session closed for user root Feb 20 09:51:20 volumio sudo[1147]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 20 09:51:20 volumio sudo[1147]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 09:51:20 volumio sudo[1147]: pam_unix(sudo:session): session closed for user root Feb 20 09:51:20 volumio volumio[979]: info: Loading plugin "services"... Feb 20 09:51:20 volumio volumio[979]: info: Loading plugin "alsa_controller"... Feb 20 09:51:20 volumio sudo[1156]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 20 09:51:20 volumio sudo[1156]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 09:51:20 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 20 09:51:20 volumio volumio[979]: info: Loading plugin "wizard"... Feb 20 09:51:20 volumio volumio[979]: info: Loading plugin "networkfs"... Feb 20 09:51:20 volumio volumio[979]: info: Starting Udev Watcher for removable devices Feb 20 09:51:20 volumio sudo[1171]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //10.10.1.58/Muza /mnt/NAS/Muza Feb 20 09:51:20 volumio sudo[1171]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 09:51:20 volumio volumio[979]: info: Ignoring mount for partition: boot Feb 20 09:51:20 volumio volumio[979]: info: Ignoring mount for partition: volumio Feb 20 09:51:20 volumio volumio[979]: info: Ignoring mount for partition: volumio_data Feb 20 09:51:20 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 20 09:51:20 volumio volumio[979]: info: Loading plugin "volumio_command_line_client"... Feb 20 09:51:20 volumio volumio[979]: info: Loading plugin "upnp"... Feb 20 09:51:20 volumio volumio[979]: info: [1740041480894] Starting Upmpd Daemon Feb 20 09:51:20 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 20 09:51:20 volumio volumio[979]: info: Loading plugin "my_music"... Feb 20 09:51:20 volumio volumio[979]: info: Loading plugin "mpd"... Feb 20 09:51:21 volumio kernel: Key type cifs.spnego registered Feb 20 09:51:21 volumio kernel: Key type cifs.idmap registered Feb 20 09:51:21 volumio kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Feb 20 09:51:21 volumio kernel: CIFS: Attempting to mount //10.10.1.58/Muza Feb 20 09:51:21 volumio kernel: cryptd: max_cpu_qlen set to 1000 Feb 20 09:51:21 volumio volumio[979]: info: Loading plugin "upnp_browser"... Feb 20 09:51:21 volumio sudo[1171]: pam_unix(sudo:session): session closed for user root Feb 20 09:51:21 volumio volumio[979]: info: Loading plugin "alarm-clock"... Feb 20 09:51:22 volumio volumio[979]: info: Plugin airplay_emulation is not enabled Feb 20 09:51:22 volumio volumio[979]: info: Loading plugin "last_100"... Feb 20 09:51:22 volumio volumio[979]: info: Loading plugin "webradio"... Feb 20 09:51:22 volumio volumio[979]: info: Loading plugin "i2s_dacs"... Feb 20 09:51:22 volumio volumio[979]: info: Loading plugin "volumiodiscovery"... Feb 20 09:51:22 volumio volumio[979]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 20 09:51:22 volumio volumio[979]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 20 09:51:22 volumio volumio[979]: *** WARNING *** For more information see Feb 20 09:51:22 volumio volumio[979]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 20 09:51:22 volumio node[979]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 20 09:51:22 volumio volumio[979]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 20 09:51:22 volumio volumio[979]: *** WARNING *** For more information see Feb 20 09:51:22 volumio node[979]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 20 09:51:22 volumio node[979]: *** WARNING *** For more information see Feb 20 09:51:22 volumio node[979]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 20 09:51:22 volumio node[979]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 20 09:51:22 volumio node[979]: *** WARNING *** For more information see Feb 20 09:51:22 volumio volumio[979]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 20 09:51:22 volumio volumio[979]: info: Discovery: Started advertising with name: Volumio Feb 20 09:51:22 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 20 09:51:22 volumio volumio[979]: info: Loading plugin "spop"... Feb 20 09:51:24 volumio sudo[1156]: pam_unix(sudo:session): session closed for user root Feb 20 09:51:25 volumio volumio-remote-updater[579]: [2025-02-20 09:51:25] [connect] Successful connection Feb 20 09:51:29 volumio volumio[979]: info: Loading plugin "ytmusic"... Feb 20 09:51:30 volumio volumio[979]: info: Loading plugin "now_playing"... Feb 20 09:51:32 volumio volumio[979]: info: Plugin peppy_screensaver is not enabled Feb 20 09:51:32 volumio volumio[979]: info: Loading plugin "outputs"... Feb 20 09:51:32 volumio volumio[979]: info: Loading plugin "albumart"... Feb 20 09:51:32 volumio volumio[979]: info: Plugin example_plugin is not enabled Feb 20 09:51:32 volumio volumio[979]: info: Loading plugin "inputs"... Feb 20 09:51:32 volumio volumio[979]: info: Loading plugin "updater_comm"... Feb 20 09:51:32 volumio volumio[979]: info: Plugin mpdemulation is not enabled Feb 20 09:51:32 volumio volumio[979]: info: Loading plugin "rest_api"... Feb 20 09:51:33 volumio volumio[979]: info: Loading plugin "websocket"... Feb 20 09:51:33 volumio volumio[979]: info: Starting Socket.io Server version 2.3.0 Feb 20 09:51:33 volumio volumio[979]: info: Loading plugin "music_services_shield"... Feb 20 09:51:33 volumio volumio[979]: Forking 3 albumart workers Feb 20 09:51:34 volumio volumio[979]: info: Applying required configuration parameters for plugin music_services_shield Feb 20 09:51:34 volumio volumio[979]: info: Plugin peppyspectrum is not enabled Feb 20 09:51:34 volumio volumio[979]: info: Plugin touch_display is not enabled Feb 20 09:51:34 volumio volumio[979]: info: Loading i18n strings for locale pl Feb 20 09:51:34 volumio volumio[979]: Updating browse sources language Feb 20 09:51:34 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 20 09:51:34 volumio volumio[979]: Starting albumart workers Feb 20 09:51:34 volumio volumio[979]: Starting albumart workers Feb 20 09:51:34 volumio volumio[979]: Starting albumart workers Feb 20 09:51:34 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 09:51:34 volumio volumio[979]: info: CoreCommandRouter::initPlayerControls Feb 20 09:51:34 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:34 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:34 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:34 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:34 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:34 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:34 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:34 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:34 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 09:51:34 volumio volumio[979]: Express server listening on port 3000 Feb 20 09:51:34 volumio volumio[979]: [Metrics] WebUI: 19s 204.22ms Feb 20 09:51:34 volumio volumio[979]: info: CoreStateMachine::resetVolumioState Feb 20 09:51:34 volumio volumio[979]: info: CoreStateMachine::getcurrentVolume Feb 20 09:51:34 volumio volumio[979]: info: CoreCommandRouter::volumioRetrievevolume Feb 20 09:51:34 volumio volumio[979]: info: CoreStateMachine::pushState Feb 20 09:51:34 volumio volumio[979]: info: CorePlayQueue::getTrack 0 Feb 20 09:51:34 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 09:51:34 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Feb 20 09:51:34 volumio sudo[1260]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 20 09:51:34 volumio sudo[1260]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 09:51:34 volumio sudo[1260]: pam_unix(sudo:session): session closed for user root Feb 20 09:51:34 volumio sudo[1262]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 20 09:51:34 volumio sudo[1262]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 09:51:34 volumio sudo[1262]: pam_unix(sudo:session): session closed for user root Feb 20 09:51:34 volumio volumio[979]: info: Volumio Network Manager: Network status updated: 2 Feb 20 09:51:40 volumio volumio-remote-updater[579]: [2025-02-20 09:51:40] [connect] Successful connection Feb 20 09:51:41 volumio systemd[1]: systemd-timedated.service: Succeeded. Feb 20 09:51:44 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 09:51:44 volumio volumio[979]: info: Reloading queue from file Feb 20 09:51:44 volumio volumio-remote-updater[579]: [2025-02-20 09:51:44] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1740041500 101 Feb 20 09:51:44 volumio volumio[979]: 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 Feb 20 09:51:44 volumio volumio[979]: info: CoreStateMachine::setRepeat null single undefined Feb 20 09:51:44 volumio volumio[979]: info: CoreStateMachine::pushState Feb 20 09:51:44 volumio volumio[979]: info: CorePlayQueue::getTrack 0 Feb 20 09:51:44 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 20 09:51:44 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Feb 20 09:51:44 volumio volumio[979]: info: CoreStateMachine::setRandom null Feb 20 09:51:44 volumio volumio[979]: info: CoreStateMachine::pushState Feb 20 09:51:44 volumio volumio[979]: info: CorePlayQueue::getTrack 0 Feb 20 09:51:44 volumio volumio[979]: info: CoreCommandRouter::volumioPushState Feb 20 09:51:44 volumio volumio[979]: info: Setting Device type: Raspberry PI Feb 20 09:51:44 volumio volumio[979]: info: Completed loading Core Plugins Feb 20 09:51:44 volumio volumio[979]: info: Preparing to generate the ALSA configuration file Feb 20 09:51:44 volumio sudo[1352]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 20 09:51:44 volumio sudo[1352]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 09:51:44 volumio volumio[979]: info: Asound.conf file unchanged, so no further update is needed Feb 20 09:51:44 volumio volumio[979]: info: Output device has changed, restarting MPD Feb 20 09:51:44 volumio sudo[1356]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 20 09:51:44 volumio sudo[1356]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 09:51:44 volumio volumio[979]: info: ___________ START PLUGINS ___________ Feb 20 09:51:44 volumio volumio[979]: info: ControllerMpd::onStart: Initializing MPD Feb 20 09:51:44 volumio volumio[979]: info: Creating MPD Configuration file Feb 20 09:51:44 volumio sudo[1356]: pam_unix(sudo:session): session closed for user root Feb 20 09:51:44 volumio sudo[1358]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 20 09:51:44 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Feb 20 09:51:44 volumio sudo[1358]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 09:51:44 volumio sudo[1362]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 20 09:51:44 volumio sudo[1362]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 09:51:44 volumio sudo[1362]: pam_unix(sudo:session): session closed for user root Feb 20 09:51:44 volumio sudo[1352]: pam_unix(sudo:session): session closed for user root Feb 20 09:51:44 volumio systemd[1]: musicservicesshield.service: Succeeded. Feb 20 09:51:44 volumio systemd[1]: Stopped Shield Volumio Music Services in the User CPU Set. Feb 20 09:51:44 volumio systemd[1]: Stopping Shield Volumio Music Services in the User CPU Set... Feb 20 09:51:44 volumio systemd[1]: Stopping Music Player Daemon... Feb 20 09:51:44 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 20 09:51:44 volumio volumio[979]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 20 09:51:44 volumio volumio[979]: info: [1740041504373] CoreMusicLibrary::Adding element Serwery Mediów Feb 20 09:51:44 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 20 09:51:44 volumio sudo[1365]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 20 09:51:44 volumio sudo[1365]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 09:51:44 volumio volumio[979]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 20 09:51:44 volumio volumio[979]: info: [1740041504409] CoreMusicLibrary::Adding element Last_100 Feb 20 09:51:44 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 20 09:51:44 volumio volumio[979]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 20 09:51:44 volumio volumio[979]: info: [1740041504415] CoreMusicLibrary::Adding element Webradio Feb 20 09:51:44 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 20 09:51:44 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 20 09:51:44 volumio volumio[979]: info: Initializing BBC Radios Feb 20 09:51:44 volumio systemd[1]: mpd.service: Succeeded. Feb 20 09:51:44 volumio systemd[1]: Stopped Music Player Daemon. Feb 20 09:51:44 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 20 09:51:44 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 09:51:44 volumio volumio[979]: info: Creating Spotify config file Feb 20 09:51:44 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:44 volumio systemd[1]: Starting Music Player Daemon... Feb 20 09:51:44 volumio volumio[979]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 20 09:51:44 volumio volumio[979]: info: [1740041504658] CoreMusicLibrary::Adding element YouTube Music Feb 20 09:51:44 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 20 09:51:44 volumio volumio[979]: Cannot find translation for source YouTube Music Feb 20 09:51:44 volumio volumio[979]: info: [now-playing] ConfigUpdater: config is up to date. Feb 20 09:51:44 volumio sudo[1377]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 20 09:51:44 volumio sudo[1377]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 09:51:44 volumio sudo[1377]: pam_unix(sudo:session): session closed for user root Feb 20 09:51:44 volumio volumio[979]: info: Volumio Calling Home Feb 20 09:51:44 volumio sudo[1406]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/moveallprocesses.sh Feb 20 09:51:44 volumio sudo[1406]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 09:51:45 volumio volumio[979]: info: [now-playing] App is listening on port 4004. Feb 20 09:51:45 volumio volumio[979]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Feb 20 09:51:45 volumio volumio[979]: info: Discovery: adding 540c9aba-0273-4314-8a87-1a23490ebd8b Feb 20 09:51:45 volumio volumio[979]: info: Discovery: Found device Volumio Feb 20 09:51:45 volumio volumio[979]: info: CoreCommandRouter::volumioGetState Feb 20 09:51:45 volumio volumio[979]: info: CorePlayQueue::getTrack 0 Feb 20 09:51:45 volumio volumio[979]: info: MPD Permissions set Feb 20 09:51:45 volumio volumio[979]: info: MPD Permissions set Feb 20 09:51:45 volumio volumio[979]: info: Upmpdcli Daemon Started Feb 20 09:51:45 volumio volumio[979]: info: Spotify config file written Feb 20 09:51:45 volumio sudo[1422]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 20 09:51:45 volumio sudo[1422]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 09:51:45 volumio volumio[979]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 20 09:51:45 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:45 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:45 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:45 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:45 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 09:51:45 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:45 volumio volumio[979]: info: No need to fix Spotify hosts Feb 20 09:51:45 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:45 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:45 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:45 volumio systemd[1]: Started go-librespot Daemon. Feb 20 09:51:45 volumio go-librespot[1426]: Librespot-go daemon starting... Feb 20 09:51:45 volumio sudo[1422]: pam_unix(sudo:session): session closed for user root Feb 20 09:51:45 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 20 09:51:45 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 20 09:51:45 volumio volumio[979]: info: Volumio called home Feb 20 09:51:45 volumio volumio[979]: info: CoreCommandRouter::volumioGetState Feb 20 09:51:45 volumio volumio[979]: info: CorePlayQueue::getTrack 0 Feb 20 09:51:45 volumio sudo[1406]: pam_unix(sudo:session): session closed for user root Feb 20 09:51:45 volumio volumio[979]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 20 09:51:45 volumio volumio[979]: SPOTIFY: BQA3MjzdVDgnKpKUWfp_qQW10RpK5OwWY-VY689SYwgUU4UeCeqTneyFUrFIZwb-O7zxfHO-qtTxJ0ogTwHrcVzz2LjeBOPNXqqXXhcwmtEhtnMgw-932m0r5U-VgMc4Q_Rqw9HRsDqanzOQODG6TMKerRMa8YZa6RadsX0x1wJpARuhPk_MLIM68OUPVHpynFJUz5QMTYy8ZfHpgBlg5FbrpsEQwytTgSh_ru7XpdOsuRT5Gr2yJ5CRfjFVpWJxSuJkCxz8bphreb4KsL27 Feb 20 09:51:45 volumio volumio[979]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 20 09:51:45 volumio volumio[979]: info: New Spotify access token = BQA3MjzdVDgnKpKUWfp_qQW10RpK5OwWY-VY689SYwgUU4UeCeqTneyFUrFIZwb-O7zxfHO-qtTxJ0ogTwHrcVzz2LjeBOPNXqqXXhcwmtEhtnMgw-932m0r5U-VgMc4Q_Rqw9HRsDqanzOQODG6TMKerRMa8YZa6RadsX0x1wJpARuhPk_MLIM68OUPVHpynFJUz5QMTYy8ZfHpgBlg5FbrpsEQwytTgSh_ru7XpdOsuRT5Gr2yJ5CRfjFVpWJxSuJkCxz8bphreb4KsL27 Feb 20 09:51:45 volumio volumio[979]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 20 09:51:45 volumio sudo[1445]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/data/plugins/system_hardware/music_services_shield/addservice.sh Feb 20 09:51:45 volumio sudo[1445]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 09:51:46 volumio go-librespot[1426]: time="2025-02-20T09:51:46+01:00" level=info msg="generated new device id: 12da4c7e1c4721ca9b57331101d1f265c1dc4aa2" Feb 20 09:51:46 volumio go-librespot[1426]: time="2025-02-20T09:51:46+01:00" level=debug msg="stored credentials found for codythejack" Feb 20 09:51:46 volumio volumio[979]: SPOTIFY: User informations: {"country":"PL","display_name":"codythejack","email":"codythejack@o2.pl","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/codythejack"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/codythejack","id":"codythejack","images":[],"product":"premium","type":"user","uri":"spotify:user:codythejack"} Feb 20 09:51:46 volumio volumio[979]: info: Spotify Successfully logged in Feb 20 09:51:46 volumio volumio[979]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 20 09:51:46 volumio volumio[979]: info: [1740041506285] CoreMusicLibrary::Adding element Spotify Feb 20 09:51:46 volumio volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 20 09:51:46 volumio volumio[979]: Cannot find translation for source YouTube Music Feb 20 09:51:46 volumio volumio[979]: Cannot find translation for source Spotify Feb 20 09:51:46 volumio go-librespot[1426]: time="2025-02-20T09:51:46+01: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-gew1.spotify.com:80]" Feb 20 09:51:46 volumio go-librespot[1426]: time="2025-02-20T09:51:46+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 20 09:51:46 volumio go-librespot[1426]: time="2025-02-20T09:51:46+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 20 09:51:46 volumio go-librespot[1426]: time="2025-02-20T09:51:46+01:00" level=debug msg="zeroconf server listening on port 43411" Feb 20 09:51:46 volumio mpd[1383]: Feb 20 09:51 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 20 09:51:46 volumio systemd[1]: Started Music Player Daemon. Feb 20 09:51:46 volumio sudo[1365]: pam_unix(sudo:session): session closed for user root Feb 20 09:51:46 volumio volumio[979]: Upnp client error: Error: This socket has been ended by the other party Feb 20 09:51:46 volumio sudo[1358]: pam_unix(sudo:session): session closed for user root Feb 20 09:51:46 volumio volumio[979]: info: Completed starting Core Plugins Feb 20 09:51:46 volumio volumio[979]: info: ------------------------------------------- Feb 20 09:51:46 volumio volumio[979]: info: ----- MyVolumio plugins startup ---- Feb 20 09:51:46 volumio volumio[979]: info: ------------------------------------------- Feb 20 09:51:46 volumio volumio[979]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 20 09:51:46 volumio volumio[979]: info: MPD running with PID1383 Feb 20 09:51:46 volumio volumio[979]: ,establishing connection Feb 20 09:51:46 volumio systemd[1]: Starting Shield Volumio Music Services in the User CPU Set... Feb 20 09:51:46 volumio volumio[979]: error: MPD error: The expression evaluated to a falsy value: Feb 20 09:51:46 volumio volumio[979]: assert.ok(self.idling) Feb 20 09:51:46 volumio volumio[979]: error: The expression evaluated to a falsy value: Feb 20 09:51:46 volumio volumio[979]: assert.ok(self.idling) Feb 20 09:51:46 volumio volumio[979]: error: MPD error: The expression evaluated to a falsy value: Feb 20 09:51:46 volumio volumio[979]: assert.ok(self.idling) Feb 20 09:51:46 volumio volumio[979]: error: The expression evaluated to a falsy value: Feb 20 09:51:46 volumio volumio[979]: assert.ok(self.idling) Feb 20 09:51:46 volumio volumio[979]: error: updateQueue error: null Feb 20 09:51:46 volumio go-librespot[1426]: time="2025-02-20T09:51:46+01:00" level=debug msg="obtained new client token: AAArqi+Dh9vPPKvo7UAd+LTeGvl9v9HmuujfbrOBJkCKRBeFVd+pkpbhgpVcressU7nqkt7ovPcokrquqpKBeGg80z7uElwk/NhWowmiVHw0J0Iq6BE+7S0OwCT3RM1JwJz1CxlZuP3LwPpJeciO29NxU5rUfsA1ocDea8tIjA5OdMh5yKRzCk33D1QcpbUSs8Bi56L9a9i31I/KXKmoiL6D4RMBeRaWsKdpKXUMY5lP0kZ8xBJe2vuInwnJ2nWp" Feb 20 09:51:46 volumio go-librespot[1426]: time="2025-02-20T09:51:46+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 20 09:51:46 volumio go-librespot[1426]: time="2025-02-20T09:51:46+01:00" level=debug msg="completed keyexchange" Feb 20 09:51:47 volumio volumio[1453]: cset: --> shielding system active with Feb 20 09:51:47 volumio volumio[1453]: cset: "system" cpuset of CPUSPEC(1-3) with 110 tasks running Feb 20 09:51:47 volumio volumio[1453]: cset: "user" cpuset of CPUSPEC(0) with 3 tasks running Feb 20 09:51:47 volumio systemd[1]: Started Shield Volumio Music Services in the User CPU Set. Feb 20 09:51:47 volumio systemd[1]: Reloading. Feb 20 09:51:47 volumio sshd[1470]: Did not receive identification string from 10.10.1.1 port 36444 Feb 20 09:51:47 volumio go-librespot[1426]: time="2025-02-20T09:51:47+01:00" level=debug msg="completed challenge" Feb 20 09:51:47 volumio go-librespot[1426]: time="2025-02-20T09:51:47+01:00" level=debug msg="authenticated as codythejack" Feb 20 09:51:47 volumio systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. Feb 20 09:51:47 volumio go-librespot[1426]: time="2025-02-20T09:51:47+01:00" level=debug msg="authenticated as codythejack" Feb 20 09:51:47 volumio systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. Feb 20 09:51:48 volumio sudo[1445]: pam_unix(sudo:session): session closed for user root Feb 20 09:51:48 volumio volumio[979]: info: succeeded Feb 20 09:51:48 volumio go-librespot[1426]: time="2025-02-20T09:51:48+01:00" level=debug msg="dealer connection opened" Feb 20 09:51:48 volumio go-librespot[1426]: time="2025-02-20T09:51:48+01:00" level=debug msg="initializing zeroconf session, username: codythejack" Feb 20 09:51:48 volumio go-librespot[1426]: time="2025-02-20T09:51:48+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 20 09:51:48 volumio go-librespot[1426]: time="2025-02-20T09:51:48+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 20 09:51:48 volumio go-librespot[1426]: time="2025-02-20T09:51:48+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 20 09:51:48 volumio go-librespot[1426]: time="2025-02-20T09:51:48+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 20 09:51:48 volumio go-librespot[1426]: time="2025-02-20T09:51:48+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 20 09:51:48 volumio go-librespot[1426]: time="2025-02-20T09:51:48+01:00" level=debug msg="autoplay enabled: false" Feb 20 09:51:48 volumio go-librespot[1426]: time="2025-02-20T09:51:48+01:00" level=debug msg="received connection id: MjRmOTM4MGUtOGI4OC00ZjA2LThlOTMtNGIxZWM2YTAyN2U4K2RlYWxlcit0Y3A6Ly8wYWNhNTliYS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArRDExMzFEQUVEMDI2QjZFREI4NzhGRDAzNUYwNDQwODdGQ0REODgyRTNCMzNBMTlBNzc3NTc0NkQzNkM5MEMwMA==" Feb 20 09:51:48 volumio volumio[1354]: Generating RSA private key, 4096 bit long modulus (2 primes) Feb 20 09:51:48 volumio volumio[979]: info: go-librespot daemon successfully initialized Feb 20 09:51:48 volumio go-librespot[1426]: time="2025-02-20T09:51:48+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 20 09:51:50 volumio ntpd[767]: Soliciting pool server 46.175.224.7 Feb 20 09:51:51 volumio go-librespot[1426]: time="2025-02-20T09:51:51+01:00" level=debug msg="handling transfer player command from 8f86cbf0e795300b2a897781e2f2f450f054e1d2" Feb 20 09:51:51 volumio go-librespot[1426]: time="2025-02-20T09:51:51+01:00" level=debug msg="resolved context of track" uri="spotify:track:572JyJV4pu3RCuIYXb5wQS" Feb 20 09:51:51 volumio go-librespot[1426]: time="2025-02-20T09:51:51+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:572JyJV4pu3RCuIYXb5wQS" Feb 20 09:51:51 volumio go-librespot[1426]: time="2025-02-20T09:51:51+01:00" level=debug msg="loading track (paused: true, position: 1697ms)" uri="spotify:track:572JyJV4pu3RCuIYXb5wQS" Feb 20 09:51:51 volumio go-librespot[1426]: time="2025-02-20T09:51:51+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 20 09:51:51 volumio go-librespot[1426]: time="2025-02-20T09:51:51+01:00" level=trace msg="emitting websocket event: will_play" Feb 20 09:51:51 volumio go-librespot[1426]: time="2025-02-20T09:51:51+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Feb 20 09:51:51 volumio go-librespot[1426]: time="2025-02-20T09:51:51+01:00" level=debug msg="selected format OGG_VORBIS_320 (ee3c5e389bf664346628725f7eae6ee53b9b49b1)" uri="spotify:track:572JyJV4pu3RCuIYXb5wQS" Feb 20 09:51:51 volumio go-librespot[1426]: time="2025-02-20T09:51:51+01:00" level=debug msg="requested aes key for file ee3c5e389bf664346628725f7eae6ee53b9b49b1, gid: 572JyJV4pu3RCuIYXb5wQS" Feb 20 09:51:51 volumio go-librespot[1426]: time="2025-02-20T09:51:51+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1344" Feb 20 09:51:51 volumio volumio[979]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 20 09:51:51 volumio volumio[979]: info: Initializing connection to go-librespot Websocket Feb 20 09:51:51 volumio go-librespot[1426]: time="2025-02-20T09:51:51+01:00" level=debug msg="new websocket client" Feb 20 09:51:51 volumio volumio[979]: info: Connection to go-librespot Websocket established Feb 20 09:51:51 volumio ntpd[767]: Soliciting pool server 51.68.141.5 Feb 20 09:51:51 volumio ntpd[767]: Soliciting pool server 80.50.102.114 Feb 20 09:51:51 volumio go-librespot[1426]: time="2025-02-20T09:51:51+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1116" Feb 20 09:51:52 volumio go-librespot[1426]: time="2025-02-20T09:51:52+01:00" level=debug msg="fetched first chunk of 8, total size is 4021524 bytes" uri="spotify:track:572JyJV4pu3RCuIYXb5wQS" Feb 20 09:51:52 volumio go-librespot[1426]: time="2025-02-20T09:51:52+01:00" level=trace msg="seek to 1697ms (diff: 45ms, samples: 74837, bytes: 51478)" uri="spotify:track:572JyJV4pu3RCuIYXb5wQS" Feb 20 09:51:52 volumio go-librespot[1426]: time="2025-02-20T09:51:52+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5011 us, period size = 221 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 99 frames" Feb 20 09:51:52 volumio go-librespot[1426]: time="2025-02-20T09:51:52+01:00" level=debug msg="created new output device" Feb 20 09:51:52 volumio go-librespot[1426]: time="2025-02-20T09:51:52+01:00" level=info msg="loaded track \"Souvenir\" (paused: true, position: 1697ms, duration: 120466ms, prefetched: false)" uri="spotify:track:572JyJV4pu3RCuIYXb5wQS" Feb 20 09:51:52 volumio ntpd[767]: Soliciting pool server 89.161.47.132 Feb 20 09:51:52 volumio go-librespot[1426]: time="2025-02-20T09:51:52+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 20 09:51:52 volumio go-librespot[1426]: time="2025-02-20T09:51:52+01:00" level=debug msg="fetched chunk 3/7, size: 524288" uri="spotify:track:572JyJV4pu3RCuIYXb5wQS" Feb 20 09:51:52 volumio go-librespot[1426]: time="2025-02-20T09:51:52+01:00" level=trace msg="emitting websocket event: metadata" Feb 20 09:51:52 volumio go-librespot[1426]: time="2025-02-20T09:51:52+01:00" level=trace msg="emitting websocket event: active" Feb 20 09:51:52 volumio go-librespot[1426]: time="2025-02-20T09:51:52+01:00" level=debug msg="sending successful reply for dealer request" Feb 20 09:51:52 volumio go-librespot[1426]: time="2025-02-20T09:51:52+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Feb 20 09:51:52 volumio go-librespot[1426]: time="2025-02-20T09:51:52+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 20 09:51:52 volumio go-librespot[1426]: time="2025-02-20T09:51:52+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 20 09:51:52 volumio volumio[979]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:572JyJV4pu3RCuIYXb5wQS","name":"Souvenir","artist_names":["Billy Joel"],"album_name":"Streetlife Serenade","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02c709d60c4fa67bb4f28a1a59","position":1697,"duration":120466,"release_date":"year:1974 month:10 day:11","track_number":9,"disc_number":1}} Feb 20 09:51:52 volumio volumio[979]: SPOTIFY: received: {"type":"active","data":null} Feb 20 09:51:52 volumio volumio[979]: info: Aligning Spotify Volume to Volumio Volume Feb 20 09:51:52 volumio volumio[979]: info: CoreCommandRouter::volumioGetState Feb 20 09:51:52 volumio volumio[979]: info: CorePlayQueue::getTrack 0 Feb 20 09:51:52 volumio go-librespot[1426]: time="2025-02-20T09:51:52+01:00" level=debug msg="fetched chunk 2/7, size: 524288" uri="spotify:track:572JyJV4pu3RCuIYXb5wQS" Feb 20 09:51:52 volumio go-librespot[1426]: time="2025-02-20T09:51:52+01:00" level=debug msg="fetched chunk 1/7, size: 524288" uri="spotify:track:572JyJV4pu3RCuIYXb5wQS" Feb 20 09:51:52 volumio go-librespot[1426]: time="2025-02-20T09:51:52+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 20 09:51:52 volumio go-librespot[1426]: time="2025-02-20T09:51:52+01:00" level=trace msg="emitting websocket event: paused" Feb 20 09:51:52 volumio volumio[979]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:572JyJV4pu3RCuIYXb5wQS","play_origin":"track"}} Feb 20 09:51:52 volumio volumio[979]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 20 09:51:52 volumio volumio[979]: TypeError: Cannot read property 'service' of undefined Feb 20 09:51:52 volumio volumio[979]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) Feb 20 09:51:52 volumio volumio[979]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:271:18) Feb 20 09:51:52 volumio volumio[979]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Feb 20 09:51:52 volumio volumio[979]: at WebSocket.emit (events.js:315:20) Feb 20 09:51:52 volumio volumio[979]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Feb 20 09:51:52 volumio volumio[979]: at Receiver.emit (events.js:315:20) Feb 20 09:51:52 volumio volumio[979]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Feb 20 09:51:52 volumio volumio[979]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Feb 20 09:51:52 volumio volumio[979]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Feb 20 09:51:52 volumio volumio[979]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Feb 20 09:51:52 volumio volumio[979]: at writeOrBuffer (internal/streams/writable.js:358:12) Feb 20 09:51:52 volumio volumio[979]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Feb 20 09:51:52 volumio volumio[979]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Feb 20 09:51:52 volumio volumio[979]: at Socket.emit (events.js:315:20) Feb 20 09:51:52 volumio volumio[979]: at addChunk (internal/streams/readable.js:309:12) Feb 20 09:51:52 volumio volumio[979]: at readableAddChunk (internal/streams/readable.js:284:9) Feb 20 09:51:52 volumio volumio[979]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 20 09:51:52 volumio ntpd[767]: Soliciting pool server 91.210.128.220 Feb 20 09:51:52 volumio ntpd[767]: Soliciting pool server 89.161.47.136 Feb 20 09:51:52 volumio ntpd[767]: Soliciting pool server 185.157.13.96 Feb 20 09:51:52 volumio sudo[1528]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-20 09:50 Feb 20 09:51:52 volumio sudo[1528]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 20 09:51:52 volumio volumio[1354]: ....................................++++ 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="cc0042a1eab1cb7982711a1347e242f8947b54b6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="d316d397153fbb98c246d670c12f98a120b995a2" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 11 Jan 2025 10:58:50 AM CET" VOLUMIO_VERSION="3.788" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e6f1869148b01453dc48d3e2d79d1421"