-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sat 2025-02-15 13:50:41 CET. -- Feb 15 13:50:22 denon-julian systemd-timedated[1138]: Changed local time to Sat Feb 15 13:50:22 2025 Feb 15 13:50:22 denon-julian sudo[1136]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:22 denon-julian volumio-time-update[675]: volumio-time-update-util: System time updated successfully. Feb 15 13:50:22 denon-julian systemd[1]: Starting Daily apt download activities... Feb 15 13:50:22 denon-julian systemd[1]: Started Volumio Time Update Utility. Feb 15 13:50:22 denon-julian ntpd[846]: Listen normally on 3 wlan0 192.168.1.119:123 Feb 15 13:50:22 denon-julian ntpd[846]: new interface(s) found: waking up resolver Feb 15 13:50:23 denon-julian volumio[1114]: info: ------------------------------------------- Feb 15 13:50:23 denon-julian volumio[1114]: info: ----- Volumio3 ---- Feb 15 13:50:23 denon-julian volumio[1114]: info: ------------------------------------------- Feb 15 13:50:23 denon-julian volumio[1114]: info: ----- System startup ---- Feb 15 13:50:23 denon-julian volumio[1114]: info: ------------------------------------------- Feb 15 13:50:23 denon-julian volumio-remote-updater[678]: [2025-02-15 13:50:23] [connect] Successful connection Feb 15 13:50:23 denon-julian nmbd[833]: [2025/02/15 13:50:23.937597, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 15 13:50:23 denon-julian nmbd[833]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Feb 15 13:50:23 denon-julian systemd[1]: Started Samba NMB Daemon. Feb 15 13:50:23 denon-julian nmbd[833]: [2025/02/15 13:50:23.962872, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Feb 15 13:50:23 denon-julian nmbd[833]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.119 for name WORKGROUP<1d>. Feb 15 13:50:23 denon-julian nmbd[833]: This response was from IP 192.168.1.112, reporting an IP address of 192.168.1.112. Feb 15 13:50:23 denon-julian systemd[1]: Starting Samba Winbind Daemon... Feb 15 13:50:23 denon-julian systemd[1]: apt-daily.service: Succeeded. Feb 15 13:50:23 denon-julian systemd[1]: Started Daily apt download activities. Feb 15 13:50:23 denon-julian systemd[1]: Starting Daily apt upgrade and clean activities... Feb 15 13:50:24 denon-julian winbindd[1197]: [2025/02/15 13:50:24.208431, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Feb 15 13:50:24 denon-julian winbindd[1197]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Feb 15 13:50:24 denon-julian winbindd[1197]: [2025/02/15 13:50:24.225342, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 15 13:50:24 denon-julian systemd[1]: Started Samba Winbind Daemon. Feb 15 13:50:24 denon-julian winbindd[1197]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Feb 15 13:50:24 denon-julian systemd[1]: Starting Samba SMB Daemon... Feb 15 13:50:24 denon-julian volumio[1114]: info: MYVOLUMIO Environment detected Feb 15 13:50:24 denon-julian volumio[1114]: info: Plugin folders cleanup Feb 15 13:50:24 denon-julian volumio[1114]: info: Scanning into folder /volumio/app/plugins/ Feb 15 13:50:24 denon-julian volumio[1114]: info: Scanning category audio_interface Feb 15 13:50:24 denon-julian volumio[1114]: info: Scanning category miscellanea Feb 15 13:50:24 denon-julian volumio[1114]: info: Scanning category music_service Feb 15 13:50:24 denon-julian volumio[1114]: info: Scanning category plugins.json Feb 15 13:50:24 denon-julian volumio[1114]: info: Scanning category system_controller Feb 15 13:50:24 denon-julian smbd[1221]: [2025/02/15 13:50:24.667232, 0] ../lib/util/become_daemon.c:138(daemon_ready) Feb 15 13:50:24 denon-julian volumio[1114]: info: Scanning category user_interface Feb 15 13:50:24 denon-julian volumio[1114]: info: Scanning into folder /data/plugins/ Feb 15 13:50:24 denon-julian volumio[1114]: info: Scanning category music_service Feb 15 13:50:24 denon-julian volumio[1114]: info: Plugin folders cleanup completed Feb 15 13:50:24 denon-julian systemd[1]: Started Samba SMB Daemon. Feb 15 13:50:24 denon-julian smbd[1221]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Feb 15 13:50:24 denon-julian systemd[1]: Reached target Multi-User System. Feb 15 13:50:24 denon-julian systemd[1]: Reached target Graphical Interface. Feb 15 13:50:24 denon-julian volumio[1114]: info: ------------------------------------------- Feb 15 13:50:24 denon-julian volumio[1114]: info: ----- Core plugins startup ---- Feb 15 13:50:24 denon-julian volumio[1114]: info: ------------------------------------------- Feb 15 13:50:24 denon-julian volumio[1114]: info: Loading plugins from folder /volumio/app/plugins/ Feb 15 13:50:24 denon-julian volumio[1114]: info: Adding plugin upnp to MyMusic Plugins Feb 15 13:50:24 denon-julian volumio[1114]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 15 13:50:24 denon-julian volumio[1114]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 15 13:50:24 denon-julian volumio[1114]: info: Loading plugins from folder /data/plugins/ Feb 15 13:50:24 denon-julian volumio[1114]: info: Loading plugin "system"... Feb 15 13:50:24 denon-julian volumio[1114]: info: Loading plugin "appearance"... Feb 15 13:50:24 denon-julian systemd[1]: Starting Update UTMP about System Runlevel Changes... Feb 15 13:50:24 denon-julian systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Feb 15 13:50:24 denon-julian systemd[1]: Started Update UTMP about System Runlevel Changes. Feb 15 13:50:25 denon-julian systemd[1]: apt-daily-upgrade.service: Succeeded. Feb 15 13:50:25 denon-julian systemd[1]: Started Daily apt upgrade and clean activities. Feb 15 13:50:25 denon-julian systemd[1]: Startup finished in 13.811s (kernel) + 31.909s (userspace) = 45.720s. Feb 15 13:50:25 denon-julian volumio[1114]: info: Loading plugin "network"... Feb 15 13:50:25 denon-julian volumio[1114]: info: Refreshing Cached IP Addresses Feb 15 13:50:25 denon-julian sudo[1268]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 15 13:50:25 denon-julian sudo[1268]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 13:50:25 denon-julian sudo[1268]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:25 denon-julian sudo[1270]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 15 13:50:25 denon-julian sudo[1270]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 13:50:25 denon-julian sudo[1270]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:25 denon-julian volumio[1114]: info: Loading plugin "services"... Feb 15 13:50:25 denon-julian volumio[1114]: info: Loading plugin "alsa_controller"... Feb 15 13:50:25 denon-julian sudo[1279]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 15 13:50:25 denon-julian sudo[1279]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 13:50:25 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 15 13:50:25 denon-julian volumio[1114]: info: Loading plugin "wizard"... Feb 15 13:50:25 denon-julian volumio[1114]: info: Loading plugin "networkfs"... Feb 15 13:50:25 denon-julian volumio[1114]: info: Starting Udev Watcher for removable devices Feb 15 13:50:25 denon-julian sudo[1294]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=uqlel,password=Julek007*,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.112/media/Music /mnt/NAS/NAS_Music Feb 15 13:50:25 denon-julian sudo[1294]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 13:50:25 denon-julian volumio[1114]: info: Ignoring mount for partition: boot Feb 15 13:50:25 denon-julian volumio[1114]: info: Ignoring mount for partition: volumio Feb 15 13:50:25 denon-julian volumio[1114]: info: Ignoring mount for partition: volumio_data Feb 15 13:50:25 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 15 13:50:25 denon-julian volumio[1114]: info: Loading plugin "volumio_command_line_client"... Feb 15 13:50:25 denon-julian volumio[1114]: info: Loading plugin "upnp"... Feb 15 13:50:25 denon-julian volumio[1114]: info: [1739623825989] Starting Upmpd Daemon Feb 15 13:50:25 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 15 13:50:25 denon-julian volumio[1114]: info: Loading plugin "my_music"... Feb 15 13:50:26 denon-julian volumio[1114]: info: Loading plugin "mpd"... Feb 15 13:50:26 denon-julian kernel: Key type cifs.spnego registered Feb 15 13:50:26 denon-julian kernel: Key type cifs.idmap registered Feb 15 13:50:26 denon-julian 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 15 13:50:26 denon-julian kernel: CIFS: Attempting to mount //192.168.1.112/media/Music Feb 15 13:50:26 denon-julian volumio[1114]: info: Loading plugin "upnp_browser"... Feb 15 13:50:26 denon-julian sudo[1294]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:26 denon-julian volumio[1114]: info: Loading plugin "alarm-clock"... Feb 15 13:50:26 denon-julian volumio[1114]: info: Loading plugin "airplay_emulation"... Feb 15 13:50:26 denon-julian volumio[1114]: info: Starting Shairport Sync Feb 15 13:50:26 denon-julian volumio[1114]: info: Loading plugin "last_100"... Feb 15 13:50:26 denon-julian volumio[1114]: info: Loading plugin "webradio"... Feb 15 13:50:26 denon-julian volumio[1114]: info: Loading plugin "i2s_dacs"... Feb 15 13:50:26 denon-julian volumio[1114]: info: Loading plugin "volumiodiscovery"... Feb 15 13:50:26 denon-julian volumio[1114]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 15 13:50:26 denon-julian volumio[1114]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 15 13:50:26 denon-julian node[1114]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 15 13:50:26 denon-julian volumio[1114]: *** WARNING *** For more information see Feb 15 13:50:26 denon-julian volumio[1114]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 15 13:50:26 denon-julian volumio[1114]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 15 13:50:26 denon-julian volumio[1114]: *** WARNING *** For more information see Feb 15 13:50:26 denon-julian node[1114]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 15 13:50:26 denon-julian node[1114]: *** WARNING *** For more information see Feb 15 13:50:26 denon-julian node[1114]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 15 13:50:26 denon-julian node[1114]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 15 13:50:26 denon-julian node[1114]: *** WARNING *** For more information see Feb 15 13:50:26 denon-julian volumio[1114]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 15 13:50:26 denon-julian volumio[1114]: info: Discovery: Started advertising with name: Denon Julian Feb 15 13:50:26 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 15 13:50:26 denon-julian volumio[1114]: info: Loading plugin "soundcloud"... Feb 15 13:50:27 denon-julian volumio[1114]: info: Loading plugin "spop"... Feb 15 13:50:28 denon-julian volumio[1114]: info: Loading plugin "outputs"... Feb 15 13:50:28 denon-julian volumio[1114]: info: Loading plugin "albumart"... Feb 15 13:50:28 denon-julian volumio[1114]: info: Plugin example_plugin is not enabled Feb 15 13:50:28 denon-julian volumio[1114]: info: Loading plugin "inputs"... Feb 15 13:50:28 denon-julian volumio[1114]: info: Loading plugin "updater_comm"... Feb 15 13:50:28 denon-julian systemd[1]: systemd-fsckd.service: Succeeded. Feb 15 13:50:28 denon-julian volumio[1114]: info: Plugin mpdemulation is not enabled Feb 15 13:50:28 denon-julian volumio[1114]: info: Loading plugin "rest_api"... Feb 15 13:50:28 denon-julian volumio[1114]: info: Loading plugin "websocket"... Feb 15 13:50:28 denon-julian volumio[1114]: info: Starting Socket.io Server version 2.3.0 Feb 15 13:50:28 denon-julian volumio[1114]: info: Loading i18n strings for locale pl Feb 15 13:50:28 denon-julian volumio[1114]: Updating browse sources language Feb 15 13:50:28 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 15 13:50:28 denon-julian volumio[1114]: Forking 3 albumart workers Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::initPlayerControls Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 15 13:50:29 denon-julian volumio[1114]: Express server listening on port 3000 Feb 15 13:50:29 denon-julian volumio[1114]: [Metrics] WebUI: 6s 369.46ms Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreStateMachine::resetVolumioState Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreStateMachine::getcurrentVolume Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::volumioRetrievevolume Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreStateMachine::pushState Feb 15 13:50:29 denon-julian volumio[1114]: info: CorePlayQueue::getTrack 0 Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::volumioPushState Feb 15 13:50:29 denon-julian volumio[1114]: info: Volumio Network Manager: Network status updated: 2 Feb 15 13:50:29 denon-julian sudo[1279]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::volumioGetState Feb 15 13:50:29 denon-julian volumio[1114]: info: CorePlayQueue::getTrack 0 Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 15 13:50:29 denon-julian volumio[1114]: info: Reloading queue from file Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreStateMachine::setRepeat false single undefined Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreStateMachine::pushState Feb 15 13:50:29 denon-julian volumio[1114]: info: CorePlayQueue::getTrack 0 Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::volumioPushState Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreStateMachine::setRandom false Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreStateMachine::pushState Feb 15 13:50:29 denon-julian volumio[1114]: info: CorePlayQueue::getTrack 0 Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::volumioPushState Feb 15 13:50:29 denon-julian volumio[1114]: info: Setting Device type: Raspberry PI Feb 15 13:50:29 denon-julian volumio[1114]: info: Completed loading Core Plugins Feb 15 13:50:29 denon-julian volumio[1114]: info: Preparing to generate the ALSA configuration file Feb 15 13:50:29 denon-julian volumio[1114]: Starting albumart workers Feb 15 13:50:29 denon-julian volumio[1114]: info: Listing playlists Feb 15 13:50:29 denon-julian volumio[1114]: info: Listing playlists Feb 15 13:50:29 denon-julian volumio[1114]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Feb 15 13:50:29 denon-julian volumio[1114]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Feb 15 13:50:29 denon-julian volumio[1114]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Feb 15 13:50:29 denon-julian volumio[1114]: info: Asound.conf file unchanged, so no further update is needed Feb 15 13:50:29 denon-julian volumio[1114]: info: Output device has changed, restarting MPD Feb 15 13:50:29 denon-julian volumio[1114]: Starting albumart workers Feb 15 13:50:29 denon-julian volumio[1114]: Starting albumart workers Feb 15 13:50:29 denon-julian volumio[1114]: info: Output device has changed, restarting Shairport Sync Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 15 13:50:29 denon-julian sudo[1359]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 15 13:50:29 denon-julian sudo[1359]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 13:50:29 denon-julian sudo[1359]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:29 denon-julian sudo[1361]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 15 13:50:29 denon-julian sudo[1361]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 13:50:29 denon-julian systemd[1]: Stopping Music Player Daemon... Feb 15 13:50:29 denon-julian volumio[1114]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 15 13:50:29 denon-julian volumio[1114]: info: ___________ START PLUGINS ___________ Feb 15 13:50:29 denon-julian volumio[1114]: info: ControllerMpd::onStart: Initializing MPD Feb 15 13:50:29 denon-julian volumio[1114]: info: Creating MPD Configuration file Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 15 13:50:29 denon-julian volumio[1114]: info: [1739623829804] CoreMusicLibrary::Adding element Serwery Mediów Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 15 13:50:29 denon-julian sudo[1368]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 15 13:50:29 denon-julian sudo[1368]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 13:50:29 denon-julian sudo[1368]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:29 denon-julian sudo[1370]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 15 13:50:29 denon-julian sudo[1370]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 13:50:29 denon-julian systemd[1]: mpd.service: Succeeded. Feb 15 13:50:29 denon-julian systemd[1]: Stopped Music Player Daemon. Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 15 13:50:29 denon-julian systemd[1]: Starting Music Player Daemon... Feb 15 13:50:29 denon-julian systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Feb 15 13:50:29 denon-julian systemd[1]: mpd.service: Succeeded. Feb 15 13:50:29 denon-julian systemd[1]: Stopped Music Player Daemon. Feb 15 13:50:29 denon-julian systemd[1]: Starting Music Player Daemon... Feb 15 13:50:29 denon-julian volumio[1114]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:29 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 15 13:50:30 denon-julian sudo[1377]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 15 13:50:30 denon-julian sudo[1377]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 13:50:30 denon-julian sudo[1377]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:30 denon-julian volumio[1114]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 15 13:50:30 denon-julian volumio[1114]: info: [1739623830030] CoreMusicLibrary::Adding element Last_100 Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 15 13:50:30 denon-julian volumio[1114]: info: [1739623830045] CoreMusicLibrary::Adding element Webradio Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 15 13:50:30 denon-julian volumio[1114]: info: Initializing BBC Radios Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 15 13:50:30 denon-julian volumio[1114]: info: [1739623830190] CoreMusicLibrary::Adding element SoundCloud Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 15 13:50:30 denon-julian volumio[1114]: Cannot find translation for source SoundCloud Feb 15 13:50:30 denon-julian volumio[1114]: info: Creating Spotify config file Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:30 denon-julian volumio[1114]: info: Volumio Calling Home Feb 15 13:50:30 denon-julian volumio[1114]: info: Discovery: adding 94eade99-0d60-4d76-bab4-050749fcb1b1 Feb 15 13:50:30 denon-julian volumio[1114]: info: Discovery: Found device Denon Julian Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::volumioGetState Feb 15 13:50:30 denon-julian volumio[1114]: info: CorePlayQueue::getTrack 0 Feb 15 13:50:30 denon-julian volumio[1114]: info: MPD Permissions set Feb 15 13:50:30 denon-julian volumio[1114]: info: MPD Permissions set Feb 15 13:50:30 denon-julian volumio[1114]: info: Spotify config file written Feb 15 13:50:30 denon-julian sudo[1421]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 15 13:50:30 denon-julian sudo[1421]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 13:50:30 denon-julian volumio[1114]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 15 13:50:30 denon-julian volumio[1114]: info: No need to fix Spotify hosts Feb 15 13:50:30 denon-julian systemd[1]: Started go-librespot Daemon. Feb 15 13:50:30 denon-julian go-librespot[1427]: Librespot-go daemon starting... Feb 15 13:50:30 denon-julian sudo[1421]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:30 denon-julian volumio[1114]: info: Starting Shairport Sync Feb 15 13:50:30 denon-julian volumio[1114]: info: Starting Shairport Sync Feb 15 13:50:30 denon-julian volumio[1114]: info: Starting Shairport Sync Feb 15 13:50:30 denon-julian sudo[1434]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 15 13:50:30 denon-julian sudo[1434]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 13:50:30 denon-julian sudo[1436]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 15 13:50:30 denon-julian sudo[1436]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 13:50:30 denon-julian systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 15 13:50:30 denon-julian systemd[1]: shairport-sync.service: Succeeded. Feb 15 13:50:30 denon-julian systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::volumioGetState Feb 15 13:50:30 denon-julian volumio[1114]: info: CorePlayQueue::getTrack 0 Feb 15 13:50:30 denon-julian sudo[1439]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 15 13:50:30 denon-julian sudo[1439]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 13:50:30 denon-julian systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 15 13:50:30 denon-julian sudo[1434]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:30 denon-julian systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Feb 15 13:50:30 denon-julian systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Feb 15 13:50:30 denon-julian systemd[1]: shairport-sync.service: Succeeded. Feb 15 13:50:30 denon-julian systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Feb 15 13:50:30 denon-julian systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Feb 15 13:50:30 denon-julian sudo[1436]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:30 denon-julian sudo[1439]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:30 denon-julian sh[582]: timed out Feb 15 13:50:30 denon-julian dhcpcd[632]: timed out Feb 15 13:50:30 denon-julian volumio[1114]: info: Shairport-Sync Started Feb 15 13:50:30 denon-julian volumio[1114]: Error adding Membership: Error: addMembership EINVAL Feb 15 13:50:30 denon-julian volumio[1114]: info: Volumio called home Feb 15 13:50:30 denon-julian dhcpcd[632]: dhcpcd exited Feb 15 13:50:30 denon-julian sh[582]: dhcpcd exited Feb 15 13:50:30 denon-julian sh[582]: ifup: failed to bring up eth0 Feb 15 13:50:30 denon-julian volumio[1114]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 15 13:50:30 denon-julian volumio[1114]: SPOTIFY: BQDbDgxztBoWIWS18aH7G43tSDX8hq8MncUC1gomLP46s6JeRObm8tep_RPTki2uK7u3DRQzgBAy9ou-144mAqFv9Z-axPehYM7Pry5W5_lPdxmTQD_7JAZ_i0uVk4mrXGdAcPkbKC1lMuk71tDF8viXRCkwTAzXZ6RVRA4-n6iRKYPC9fyRVnyPGKFd0t_qojgQm3cbAs9FNqBbHcF4AMc8FEP4XidlD9hlv4GXA2fgOSzmhlDZwjYO_2_b5GUoYCrK1FL4SGU0NDmo7MSIfn2OlCQbdzLzNnZTP8c Feb 15 13:50:30 denon-julian volumio[1114]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 15 13:50:30 denon-julian systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Feb 15 13:50:30 denon-julian systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Feb 15 13:50:30 denon-julian volumio[1114]: info: New Spotify access token = BQDbDgxztBoWIWS18aH7G43tSDX8hq8MncUC1gomLP46s6JeRObm8tep_RPTki2uK7u3DRQzgBAy9ou-144mAqFv9Z-axPehYM7Pry5W5_lPdxmTQD_7JAZ_i0uVk4mrXGdAcPkbKC1lMuk71tDF8viXRCkwTAzXZ6RVRA4-n6iRKYPC9fyRVnyPGKFd0t_qojgQm3cbAs9FNqBbHcF4AMc8FEP4XidlD9hlv4GXA2fgOSzmhlDZwjYO_2_b5GUoYCrK1FL4SGU0NDmo7MSIfn2OlCQbdzLzNnZTP8c Feb 15 13:50:30 denon-julian volumio[1114]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 15 13:50:30 denon-julian volumio[1114]: info: Shairport-Sync Started Feb 15 13:50:30 denon-julian volumio[1114]: info: Shairport-Sync Started Feb 15 13:50:30 denon-julian go-librespot[1427]: time="2025-02-15T13:50:30+01:00" level=info msg="generated new device id: 60871d9260afb7aa7f551c3cad4d24243c2fbdb8" Feb 15 13:50:30 denon-julian go-librespot[1427]: time="2025-02-15T13:50:30+01:00" level=debug msg="stored credentials found for siy96m2kixcbw49onqqyo5pqp" Feb 15 13:50:30 denon-julian volumio[1114]: SPOTIFY: User informations: {"country":"PL","display_name":"uqlel","email":"jchajdys@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/siy96m2kixcbw49onqqyo5pqp"},"followers":{"href":null,"total":7},"href":"https://api.spotify.com/v1/users/siy96m2kixcbw49onqqyo5pqp","id":"siy96m2kixcbw49onqqyo5pqp","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85ad4f1c539490bcd7a4bf33a3","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82ad4f1c539490bcd7a4bf33a3","width":64}],"product":"premium","type":"user","uri":"spotify:user:siy96m2kixcbw49onqqyo5pqp"} Feb 15 13:50:30 denon-julian volumio[1114]: info: Spotify Successfully logged in Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 15 13:50:30 denon-julian volumio[1114]: info: [1739623830866] CoreMusicLibrary::Adding element Spotify Feb 15 13:50:30 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 15 13:50:30 denon-julian volumio[1114]: Cannot find translation for source SoundCloud Feb 15 13:50:30 denon-julian volumio[1114]: Cannot find translation for source Spotify Feb 15 13:50:30 denon-julian mpd[1382]: config_file: config parameter "gapless_mp3_playback" on line 19 is deprecated Feb 15 13:50:30 denon-julian mpd[1382]: config_file: config parameter "buffer_before_play" on line 86 is deprecated Feb 15 13:50:30 denon-julian mpd[1382]: config_file: config parameter "id3v1_encoding" on line 100 is deprecated Feb 15 13:50:30 denon-julian mpd[1382]: Feb 15 13:50 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 15 13:50:30 denon-julian systemd[1]: Started Music Player Daemon. Feb 15 13:50:30 denon-julian sudo[1370]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:30 denon-julian sudo[1361]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:30 denon-julian volumio[1114]: info: Completed starting Core Plugins Feb 15 13:50:30 denon-julian volumio[1114]: info: ------------------------------------------- Feb 15 13:50:30 denon-julian volumio[1114]: info: ----- MyVolumio plugins startup ---- Feb 15 13:50:30 denon-julian volumio[1114]: info: ------------------------------------------- Feb 15 13:50:30 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 15 13:50:31 denon-julian volumio[1114]: error: MPD error: The expression evaluated to a falsy value: Feb 15 13:50:31 denon-julian volumio[1114]: assert.ok(self.idling) Feb 15 13:50:31 denon-julian volumio[1114]: error: The expression evaluated to a falsy value: Feb 15 13:50:31 denon-julian volumio[1114]: assert.ok(self.idling) Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" 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]" Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" 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]" Feb 15 13:50:31 denon-julian volumio[1114]: info: MPD running with PID1382 Feb 15 13:50:31 denon-julian volumio[1114]: ,establishing connection Feb 15 13:50:31 denon-julian volumio[1114]: error: MPD error: The expression evaluated to a falsy value: Feb 15 13:50:31 denon-julian volumio[1114]: assert.ok(self.idling) Feb 15 13:50:31 denon-julian volumio[1114]: error: The expression evaluated to a falsy value: Feb 15 13:50:31 denon-julian volumio[1114]: assert.ok(self.idling) Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" level=debug msg="zeroconf server listening on port 37857" Feb 15 13:50:31 denon-julian volumio[1114]: error: updateQueue error: null Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" level=debug msg="obtained new client token: AAALhiIxTK3O+ua89o78l43LShRCy7qdVvwd9/kMLijmXMzGjirvIx+zYgEmFD6FPxQjrjk42C1fqy0EzJIDLqB3TaGaZAETHsCESq+QatfSVaraHHOoirY4yfYkaGHB86R33sGCjQ/WKhn426C+RB67Rfc+9g7jlaSYSG3Nhoz0MJEDNFkl8kHBZvb8WL6VD8geXoX6J9lmqYsyJWYNqCSeqg8j8lnenkbwYEi1eML5zSzWRPsJbz93CpPAlY4=" Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" level=debug msg="completed keyexchange" Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" level=debug msg="completed challenge" Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" level=debug msg="authenticated as siy96m2kixcbw49onqqyo5pqp" Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" level=debug msg="authenticated as siy96m2kixcbw49onqqyo5pqp" Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" level=debug msg="dealer connection opened" Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" level=debug msg="initializing zeroconf session, username: siy96m2kixcbw49onqqyo5pqp" Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" level=debug msg="autoplay enabled: false" Feb 15 13:50:31 denon-julian go-librespot[1427]: time="2025-02-15T13:50:31+01:00" level=debug msg="received connection id: ZDRiOGFmNmEtMGExMS00YjRmLWEwZWItMDFkMWRlYmQ0MjZkK2RlYWxlcit0Y3A6Ly8wYWNhNTk2Ny5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArRUYzN0ZBRUQ3NzYwNjZENzYxMDcwMTM1RUNGQjA4MTFDMkMyNjIzOUEzNjI1RDcxMUU1NTEyRjZGODIzOUE5Nw==" Feb 15 13:50:32 denon-julian go-librespot[1427]: time="2025-02-15T13:50:32+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 15 13:50:33 denon-julian volumio[1114]: info: go-librespot daemon successfully initialized Feb 15 13:50:33 denon-julian systemd[1]: systemd-hostnamed.service: Succeeded. Feb 15 13:50:36 denon-julian sudo[1479]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 15 13:50:36 denon-julian sudo[1479]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 13:50:36 denon-julian sudo[1479]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:36 denon-julian volumio[1114]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 15 13:50:36 denon-julian sudo[1481]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 15 13:50:36 denon-julian sudo[1481]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 13:50:36 denon-julian sudo[1481]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:36 denon-julian volumio[1114]: Cannot compose Albumart path Feb 15 13:50:36 denon-julian sudo[1485]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 15 13:50:36 denon-julian sudo[1485]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 13:50:36 denon-julian systemd[1]: Started UPnP Renderer front-end to MPD. Feb 15 13:50:36 denon-julian sudo[1485]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:36 denon-julian volumio[1114]: info: Upmpdcli Daemon Started Feb 15 13:50:36 denon-julian volumio[1487]: Generating RSA private key, 4096 bit long modulus (2 primes) Feb 15 13:50:36 denon-julian go-librespot[1427]: time="2025-02-15T13:50:36+01:00" level=debug msg="handling transfer player command from a62d6037de3d230c43a0978872603a29b1e6eb6e" Feb 15 13:50:36 denon-julian go-librespot[1427]: time="2025-02-15T13:50:36+01:00" level=debug msg="resolved context of track" uri="spotify:album:7aNclGRxTysfh6z0d8671k" Feb 15 13:50:36 denon-julian go-librespot[1427]: time="2025-02-15T13:50:36+01:00" level=trace msg="fetched new page 0 with 13 items (list: 13)" uri="spotify:album:7aNclGRxTysfh6z0d8671k" Feb 15 13:50:36 denon-julian go-librespot[1427]: time="2025-02-15T13:50:36+01:00" level=debug msg="shuffled context with seed 819933044992122545 (len: 13, keep: 3)" Feb 15 13:50:36 denon-julian go-librespot[1427]: time="2025-02-15T13:50:36+01:00" level=debug msg="loading track (paused: false, position: 137707ms)" uri="spotify:track:7o2AeQZzfCERsRmOM86EcB" Feb 15 13:50:36 denon-julian volumio[1114]: info: CoreCommandRouter::volumioGetState Feb 15 13:50:36 denon-julian volumio[1114]: info: CorePlayQueue::getTrack 0 Feb 15 13:50:36 denon-julian go-librespot[1427]: time="2025-02-15T13:50:36+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 15 13:50:36 denon-julian go-librespot[1427]: time="2025-02-15T13:50:36+01:00" level=trace msg="emitting websocket event: will_play" Feb 15 13:50:36 denon-julian go-librespot[1427]: time="2025-02-15T13:50:36+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1293" Feb 15 13:50:36 denon-julian go-librespot[1427]: time="2025-02-15T13:50:36+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Feb 15 13:50:36 denon-julian go-librespot[1427]: time="2025-02-15T13:50:36+01:00" level=debug msg="selected format OGG_VORBIS_320 (890f1baed1536a21ccfd61235772b73e8e150e4e)" uri="spotify:track:7o2AeQZzfCERsRmOM86EcB" Feb 15 13:50:36 denon-julian go-librespot[1427]: time="2025-02-15T13:50:36+01:00" level=debug msg="requested aes key for file 890f1baed1536a21ccfd61235772b73e8e150e4e, gid: 7o2AeQZzfCERsRmOM86EcB" Feb 15 13:50:36 denon-julian volumio[1114]: info: Initializing connection to go-librespot Websocket Feb 15 13:50:36 denon-julian go-librespot[1427]: time="2025-02-15T13:50:36+01:00" level=debug msg="new websocket client" Feb 15 13:50:36 denon-julian volumio[1114]: info: Connection to go-librespot Websocket established Feb 15 13:50:38 denon-julian go-librespot[1427]: time="2025-02-15T13:50:38+01:00" level=debug msg="fetched first chunk of 24, total size is 12256832 bytes" uri="spotify:track:7o2AeQZzfCERsRmOM86EcB" Feb 15 13:50:38 denon-julian volumio-remote-updater[678]: [2025-02-15 13:50:38] [connect] Successful connection Feb 15 13:50:38 denon-julian volumio-remote-updater[678]: [2025-02-15 13:50:38] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1739623838 101 Feb 15 13:50:38 denon-julian volumio[1114]: 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: 2 Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 15 13:50:39 denon-julian volumio[1114]: info: Adding plugin bluetooth to MyMusic Plugins Feb 15 13:50:39 denon-julian volumio[1114]: info: Adding plugin multiroom to MyMusic Plugins Feb 15 13:50:39 denon-julian volumio[1114]: info: Adding plugin metavolumio to MyMusic Plugins Feb 15 13:50:39 denon-julian volumio[1114]: info: Adding plugin cd_controller to MyMusic Plugins Feb 15 13:50:39 denon-julian volumio[1114]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 15 13:50:39 denon-julian volumio[1114]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 15 13:50:39 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 15 13:50:39 denon-julian volumio[1487]: ....................................++++ Feb 15 13:50:39 denon-julian go-librespot[1427]: time="2025-02-15T13:50:39+01:00" level=debug msg="fetched chunk 14/23, size: 524288" uri="spotify:track:7o2AeQZzfCERsRmOM86EcB" Feb 15 13:50:39 denon-julian go-librespot[1427]: time="2025-02-15T13:50:39+01:00" level=debug msg="fetched chunk 3/23, size: 524288" uri="spotify:track:7o2AeQZzfCERsRmOM86EcB" Feb 15 13:50:39 denon-julian go-librespot[1427]: time="2025-02-15T13:50:39+01:00" level=debug msg="fetched chunk 12/23, size: 524288" uri="spotify:track:7o2AeQZzfCERsRmOM86EcB" Feb 15 13:50:39 denon-julian go-librespot[1427]: time="2025-02-15T13:50:39+01:00" level=debug msg="fetched chunk 1/23, size: 524288" uri="spotify:track:7o2AeQZzfCERsRmOM86EcB" Feb 15 13:50:39 denon-julian go-librespot[1427]: time="2025-02-15T13:50:39+01:00" level=debug msg="fetched chunk 2/23, size: 524288" uri="spotify:track:7o2AeQZzfCERsRmOM86EcB" Feb 15 13:50:40 denon-julian go-librespot[1427]: time="2025-02-15T13:50:40+01:00" level=debug msg="fetched chunk 13/23, size: 524288" uri="spotify:track:7o2AeQZzfCERsRmOM86EcB" Feb 15 13:50:40 denon-julian volumio[1114]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 15 13:50:40 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 15 13:50:40 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 15 13:50:40 denon-julian volumio[1114]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 15 13:50:40 denon-julian volumio[1114]: info: Starting MyVolumio Remote Streaming Endpoints Feb 15 13:50:40 denon-julian volumio[1114]: info: MyVolumio login type: Token Feb 15 13:50:40 denon-julian volumio[1114]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 15 13:50:40 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 15 13:50:40 denon-julian go-librespot[1427]: time="2025-02-15T13:50:40+01:00" level=debug msg="fetched chunk 11/23, size: 524288" uri="spotify:track:7o2AeQZzfCERsRmOM86EcB" Feb 15 13:50:40 denon-julian go-librespot[1427]: time="2025-02-15T13:50:40+01:00" level=trace msg="seek to 137707ms (diff: 96ms, samples: 6072878, bytes: 5805123)" uri="spotify:track:7o2AeQZzfCERsRmOM86EcB" Feb 15 13:50:40 denon-julian go-librespot[1427]: time="2025-02-15T13:50:40+01: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" Feb 15 13:50:40 denon-julian go-librespot[1427]: time="2025-02-15T13:50:40+01:00" level=debug msg="created new output device" Feb 15 13:50:40 denon-julian go-librespot[1427]: time="2025-02-15T13:50:40+01:00" level=info msg="loaded track \"Xtal\" (paused: false, position: 137707ms, duration: 293751ms, prefetched: false)" uri="spotify:track:7o2AeQZzfCERsRmOM86EcB" Feb 15 13:50:40 denon-julian go-librespot[1427]: time="2025-02-15T13:50:40+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 15 13:50:40 denon-julian go-librespot[1427]: time="2025-02-15T13:50:40+01:00" level=trace msg="scheduling prefetch in 126s" Feb 15 13:50:40 denon-julian go-librespot[1427]: time="2025-02-15T13:50:40+01:00" level=trace msg="emitting websocket event: metadata" Feb 15 13:50:40 denon-julian go-librespot[1427]: time="2025-02-15T13:50:40+01:00" level=trace msg="emitting websocket event: active" Feb 15 13:50:40 denon-julian go-librespot[1427]: time="2025-02-15T13:50:40+01:00" level=debug msg="sending successful reply for dealer request" Feb 15 13:50:40 denon-julian go-librespot[1427]: time="2025-02-15T13:50:40+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 15 13:50:40 denon-julian go-librespot[1427]: time="2025-02-15T13:50:40+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Feb 15 13:50:40 denon-julian go-librespot[1427]: time="2025-02-15T13:50:40+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 15 13:50:40 denon-julian go-librespot[1427]: time="2025-02-15T13:50:40+01:00" level=trace msg="emitting websocket event: playing" Feb 15 13:50:41 denon-julian volumio[1114]: info: Starting Streaming Service Transparent Proxy Feb 15 13:50:41 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 15 13:50:41 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 15 13:50:41 denon-julian volumio[1114]: info: Streaming services startup Feb 15 13:50:41 denon-julian volumio[1114]: info: Starting Streaming Daemon Feb 15 13:50:41 denon-julian sudo[1511]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 15 13:50:41 denon-julian sudo[1511]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 15 13:50:41 denon-julian volumio[1114]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 15 13:50:41 denon-julian sudo[1511]: pam_unix(sudo:session): session closed for user root Feb 15 13:50:41 denon-julian volumio[1114]: info: Getting Spotify volume Feb 15 13:50:41 denon-julian volumio[1114]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7o2AeQZzfCERsRmOM86EcB","name":"Xtal","artist_names":["Aphex Twin"],"album_name":"Selected Ambient Works 85-92","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0238906032688bb13b135ce19a","position":137707,"duration":293751,"release_date":"year:1992 month:2 day:10","track_number":1,"disc_number":1}} Feb 15 13:50:41 denon-julian volumio[1114]: SPOTIFY: received: {"type":"active","data":null} Feb 15 13:50:41 denon-julian volumio[1114]: info: Aligning Spotify Volume to Volumio Volume Feb 15 13:50:41 denon-julian volumio[1114]: info: CoreCommandRouter::volumioGetState Feb 15 13:50:41 denon-julian volumio[1114]: info: CorePlayQueue::getTrack 0 Feb 15 13:50:41 denon-julian volumio[1114]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7o2AeQZzfCERsRmOM86EcB","play_origin":"playlist"}} Feb 15 13:50:41 denon-julian volumio[1114]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 15 13:50:41 denon-julian volumio[1114]: TypeError: Cannot read property 'service' of undefined Feb 15 13:50:41 denon-julian volumio[1114]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) Feb 15 13:50:41 denon-julian volumio[1114]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:263:18) Feb 15 13:50:41 denon-julian volumio[1114]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Feb 15 13:50:41 denon-julian volumio[1114]: at WebSocket.emit (events.js:315:20) Feb 15 13:50:41 denon-julian volumio[1114]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Feb 15 13:50:41 denon-julian volumio[1114]: at Receiver.emit (events.js:315:20) Feb 15 13:50:41 denon-julian volumio[1114]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Feb 15 13:50:41 denon-julian volumio[1114]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Feb 15 13:50:41 denon-julian volumio[1114]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Feb 15 13:50:41 denon-julian volumio[1114]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Feb 15 13:50:41 denon-julian volumio[1114]: at writeOrBuffer (internal/streams/writable.js:358:12) Feb 15 13:50:41 denon-julian volumio[1114]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Feb 15 13:50:41 denon-julian volumio[1114]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Feb 15 13:50:41 denon-julian volumio[1114]: at Socket.emit (events.js:315:20) Feb 15 13:50:41 denon-julian volumio[1114]: at addChunk (internal/streams/readable.js:309:12) Feb 15 13:50:41 denon-julian volumio[1114]: at readableAddChunk (internal/streams/readable.js:284:9) Feb 15 13:50:41 denon-julian volumio[1114]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 15 13:50:41 denon-julian sudo[1527]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-15 13:49 Feb 15 13:50:41 denon-julian sudo[1527]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"