-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Sun 2025-04-20 15:50:02 CEST. -- Apr 20 15:49:43 tycshd systemd[1]: Starting Daily apt download activities... Apr 20 15:49:43 tycshd volumio[662]: Starting albumart workers Apr 20 15:49:44 tycshd volumio[662]: info: Applying required configuration parameters for plugin hi_res_audio Apr 20 15:49:44 tycshd volumio[662]: info: Loading plugin "inputs"... Apr 20 15:49:45 tycshd volumio[662]: info: Loading plugin "qobuz"... Apr 20 15:49:45 tycshd systemd[1]: apt-daily.service: Succeeded. Apr 20 15:49:45 tycshd systemd[1]: Started Daily apt download activities. Apr 20 15:49:45 tycshd systemd[1]: Starting Daily apt upgrade and clean activities... Apr 20 15:49:46 tycshd systemd[1]: apt-daily-upgrade.service: Succeeded. Apr 20 15:49:46 tycshd systemd[1]: Started Daily apt upgrade and clean activities. Apr 20 15:49:47 tycshd volumio[662]: info: Loading plugin "tidal"... Apr 20 15:49:49 tycshd volumio[662]: info: Loading plugin "oem_helper"... Apr 20 15:49:49 tycshd systemd[1]: systemd-fsckd.service: Succeeded. Apr 20 15:49:50 tycshd volumio[662]: info: Applying required configuration parameters for plugin oem_helper Apr 20 15:49:50 tycshd volumio[662]: info: Loading plugin "updater_comm"... Apr 20 15:49:50 tycshd volumio[662]: info: Plugin mpdemulation is not enabled Apr 20 15:49:50 tycshd volumio[662]: info: Loading plugin "rest_api"... Apr 20 15:49:51 tycshd volumio[662]: info: Loading plugin "websocket"... Apr 20 15:49:51 tycshd volumio[662]: info: Loading i18n strings for locale en Apr 20 15:49:51 tycshd volumio[662]: Updating browse sources language Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::initPlayerControls Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 20 15:49:51 tycshd volumio[662]: Express server listening on port 3000 Apr 20 15:49:51 tycshd volumio[662]: [Metrics] WebUI: 25s 382.88ms Apr 20 15:49:51 tycshd volumio[662]: info: CoreStateMachine::resetVolumioState Apr 20 15:49:51 tycshd volumio[662]: info: CoreStateMachine::getcurrentVolume Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::volumioRetrievevolume Apr 20 15:49:51 tycshd volumio[662]: info: CoreStateMachine::pushState Apr 20 15:49:51 tycshd volumio[662]: info: CorePlayQueue::getTrack 0 Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::volumioPushState Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 20 15:49:51 tycshd sudo[1018]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 20 15:49:51 tycshd sudo[1018]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 15:49:51 tycshd sudo[1018]: pam_unix(sudo:session): session closed for user root Apr 20 15:49:51 tycshd sudo[1021]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 20 15:49:51 tycshd sudo[1021]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 15:49:51 tycshd volumio[662]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Apr 20 15:49:51 tycshd volumio[662]: info: Completed loading Core Plugins Apr 20 15:49:51 tycshd volumio[662]: info: Preparing to generate the ALSA configuration file Apr 20 15:49:51 tycshd sudo[1021]: pam_unix(sudo:session): session closed for user root Apr 20 15:49:51 tycshd volumio[662]: info: Cannot mount NAS Tycstation at system boot, trial number 1 ,retrying in 5 seconds Apr 20 15:49:51 tycshd volumio[662]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Apr 20 15:49:51 tycshd volumio[662]: wlan0 Interface doesn't support scanning. Apr 20 15:49:51 tycshd volumio[662]: info: Cannot use regular scanning, forcing with ap-force Apr 20 15:49:51 tycshd sudo[1026]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Apr 20 15:49:51 tycshd sudo[1026]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 15:49:51 tycshd sudo[1026]: pam_unix(sudo:session): session closed for user root Apr 20 15:49:51 tycshd volumio[662]: command failed: No such device (-19) Apr 20 15:49:51 tycshd volumio[662]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Apr 20 15:49:51 tycshd volumio[662]: command failed: No such device (-19) Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::volumioGetState Apr 20 15:49:51 tycshd volumio[662]: info: CorePlayQueue::getTrack 0 Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::volumioGetState Apr 20 15:49:51 tycshd volumio[662]: info: CorePlayQueue::getTrack 0 Apr 20 15:49:51 tycshd volumio[662]: info: CoreCommandRouter::volumioGetState Apr 20 15:49:51 tycshd volumio[662]: info: CorePlayQueue::getTrack 0 Apr 20 15:49:52 tycshd volumio[662]: info: Asound.conf file unchanged, so no further update is needed Apr 20 15:49:52 tycshd volumio[662]: info: Output device has changed, restarting MPD Apr 20 15:49:52 tycshd sudo[1037]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 20 15:49:52 tycshd sudo[1037]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 15:49:52 tycshd sudo[1037]: pam_unix(sudo:session): session closed for user root Apr 20 15:49:52 tycshd volumio[662]: info: ___________ START PLUGINS ___________ Apr 20 15:49:52 tycshd volumio[662]: info: ControllerMpd::onStart: Initializing MPD Apr 20 15:49:52 tycshd sudo[1040]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 20 15:49:52 tycshd volumio[662]: info: Creating MPD Configuration file Apr 20 15:49:52 tycshd sudo[1040]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 15:49:52 tycshd systemd[1]: Listening on mpd.socket. Apr 20 15:49:52 tycshd sudo[1043]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 20 15:49:52 tycshd sudo[1043]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 15:49:52 tycshd systemd[1]: Starting Music Player Daemon... Apr 20 15:49:52 tycshd sudo[1043]: pam_unix(sudo:session): session closed for user root Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 20 15:49:52 tycshd volumio[662]: info: [1745156992173] CoreMusicLibrary::Adding element Media Servers Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 20 15:49:52 tycshd sudo[1047]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 20 15:49:52 tycshd sudo[1047]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 15:49:52 tycshd volumio[662]: info: Adding Manifest REST API Endpoints Apr 20 15:49:52 tycshd volumio[662]: info: Adding manifestui REST Endpoint for plugin: miscellanea/manifestui Apr 20 15:49:52 tycshd volumio[662]: info: Adding METAVOLUMIO REST API Endpoints Apr 20 15:49:52 tycshd volumio[662]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Apr 20 15:49:52 tycshd volumio[662]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Apr 20 15:49:52 tycshd volumio[662]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Apr 20 15:49:52 tycshd volumio[662]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 20 15:49:52 tycshd volumio[662]: info: [1745156992217] CoreMusicLibrary::Adding element Last_100 Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 20 15:49:52 tycshd volumio[662]: info: Streaming services startup Apr 20 15:49:52 tycshd volumio[662]: info: Starting Streaming Daemon Apr 20 15:49:52 tycshd systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 20 15:49:52 tycshd systemd[1]: mpd.service: Succeeded. Apr 20 15:49:52 tycshd systemd[1]: Stopped Music Player Daemon. Apr 20 15:49:52 tycshd sudo[1050]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 20 15:49:52 tycshd systemd[1]: Starting Music Player Daemon... Apr 20 15:49:52 tycshd sudo[1050]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 15:49:52 tycshd sudo[1050]: pam_unix(sudo:session): session closed for user root Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 20 15:49:52 tycshd volumio[662]: info: [1745156992333] CoreMusicLibrary::Adding element Webradio Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 20 15:49:52 tycshd volumio[662]: info: [1745156992358] CoreMusicLibrary::Adding element SoundCloud Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 20 15:49:52 tycshd volumio[662]: Cannot find translation for source SoundCloud Apr 20 15:49:52 tycshd volumio[662]: info: Creating Spotify config file Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 20 15:49:52 tycshd volumio[662]: info: [1745156992525] CoreMusicLibrary::Adding element YouTube2 Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 20 15:49:52 tycshd volumio[662]: Cannot find translation for source SoundCloud Apr 20 15:49:52 tycshd volumio[662]: Cannot find translation for source YouTube2 Apr 20 15:49:52 tycshd volumio[662]: error: Hi Res Audio Failed Login: Missing Login Data Apr 20 15:49:52 tycshd volumio[662]: info: Adding HIGHRESAUDIO REST API Endpoints Apr 20 15:49:52 tycshd volumio[662]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 20 15:49:52 tycshd volumio[662]: info: Volumio Calling Home Apr 20 15:49:52 tycshd volumio[662]: info: Stopping AccessToken refresher cron for QOBUZ Apr 20 15:49:52 tycshd volumio[662]: info: AccessToken refresher cron started for QOBUZ Apr 20 15:49:52 tycshd volumio[662]: info: Stopping AccessToken refresher cron Apr 20 15:49:52 tycshd volumio[662]: info: AccessToken refresher cron started Apr 20 15:49:52 tycshd volumio[662]: info: Adding TIDAL REST API Endpoints Apr 20 15:49:52 tycshd volumio[662]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Apr 20 15:49:52 tycshd volumio[662]: info: Adding QOBUZ REST API Endpoints Apr 20 15:49:52 tycshd volumio[662]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Apr 20 15:49:52 tycshd volumio[662]: info: Setting Device type: NanoPi NEO 2 Apr 20 15:49:52 tycshd volumio[662]: info: CoreStateMachine::setRepeat false single undefined Apr 20 15:49:52 tycshd volumio[662]: info: CoreStateMachine::pushState Apr 20 15:49:52 tycshd volumio[662]: info: CorePlayQueue::getTrack 0 Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::volumioPushState Apr 20 15:49:52 tycshd volumio[662]: info: CoreStateMachine::setRandom null Apr 20 15:49:52 tycshd volumio[662]: info: CoreStateMachine::pushState Apr 20 15:49:52 tycshd volumio[662]: info: CorePlayQueue::getTrack 0 Apr 20 15:49:52 tycshd volumio[662]: info: CoreCommandRouter::volumioPushState Apr 20 15:49:52 tycshd volumio[662]: info: Listing playlists Apr 20 15:49:52 tycshd volumio[662]: info: Listing playlists Apr 20 15:49:53 tycshd volumio[662]: info: Serial port opened successfully Apr 20 15:49:53 tycshd volumio[662]: error: Cannot start Volumio Streaming Daemon Apr 20 15:49:53 tycshd volumio[662]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 20 15:49:53 tycshd volumio[662]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 20 15:49:53 tycshd volumio[662]: info: MPD Permissions set Apr 20 15:49:53 tycshd volumio[662]: info: MPD Permissions set Apr 20 15:49:53 tycshd volumio[662]: info: Discovery: A device disappeared from network Apr 20 15:49:53 tycshd volumio[662]: info: Discovery: Browse raised the following error TypeError: Cannot read property 'toLowerCase' of undefined Apr 20 15:49:53 tycshd sudo[1072]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 20 15:49:53 tycshd sudo[1072]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 15:49:53 tycshd volumio[662]: info: Volumio called home Apr 20 15:49:53 tycshd volumio[662]: info: Spotify config file written Apr 20 15:49:53 tycshd systemd[1]: Started UPnP Renderer front-end to MPD. Apr 20 15:49:53 tycshd sudo[1072]: pam_unix(sudo:session): session closed for user root Apr 20 15:49:53 tycshd sudo[1076]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 20 15:49:53 tycshd sudo[1076]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 15:49:53 tycshd systemd[1]: Started go-librespot Daemon. Apr 20 15:49:53 tycshd sudo[1076]: pam_unix(sudo:session): session closed for user root Apr 20 15:49:53 tycshd go-librespot[1079]: go-librespot daemon starting... Apr 20 15:49:53 tycshd volumio[662]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 1 Apr 20 15:49:53 tycshd volumio[662]: info: Discovery: adding 120ce0ca-4893-4538-b389-bf03232d172c Apr 20 15:49:53 tycshd volumio[662]: info: Discovery: Found device TycSHD Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::volumioGetState Apr 20 15:49:53 tycshd volumio[662]: info: CorePlayQueue::getTrack 0 Apr 20 15:49:53 tycshd volumio[662]: info: No need to fix Spotify hosts Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: raat , reconfigureAndRestartRaat Apr 20 15:49:53 tycshd volumio[662]: info: Adding MINIDSP Inputs Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 20 15:49:53 tycshd volumio[662]: info: [1745156993550] CoreMusicLibrary::Adding element Inputs Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 20 15:49:53 tycshd volumio[662]: Cannot find translation for source SoundCloud Apr 20 15:49:53 tycshd volumio[662]: Cannot find translation for source YouTube2 Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 20 15:49:53 tycshd volumio[662]: info: [1745156993554] CoreMusicLibrary::Adding element Presets Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 20 15:49:53 tycshd volumio[662]: Cannot find translation for source SoundCloud Apr 20 15:49:53 tycshd volumio[662]: Cannot find translation for source YouTube2 Apr 20 15:49:53 tycshd volumio[662]: Cannot find translation for source Presets Apr 20 15:49:53 tycshd volumio[662]: info: Upmpdcli Daemon Started Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::volumioGetState Apr 20 15:49:53 tycshd volumio[662]: info: CorePlayQueue::getTrack 0 Apr 20 15:49:53 tycshd volumio[662]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 20 15:49:53 tycshd volumio[662]: SPOTIFY: BQDrF9LPKDNOMumHS6ZXP1pRk8g2V9h2D45zHL0JbAnIkZjEJgU9FHepIYeevrvkmL1FX6VbDJ4ksTd-HXnqiNffjMN3dZ6Oq3IxPnkSJBKLlYJnuXPDFWm_GFpT-tl3ngOA9nxQk2E7n8fp93iekHuo3B5XQMrmAZuRIyTE-haRcsnI9CRVQoccU8FiTde5fcDkCAtpZh80reP520EaSd7NEN_HbQuq_LrNEEt8fOGWw55a3i9d-A5dj-_f-KT7_JCgG5FAoB5bFJNAhg Apr 20 15:49:53 tycshd volumio[662]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 20 15:49:53 tycshd volumio[662]: info: New Spotify access token = BQDrF9LPKDNOMumHS6ZXP1pRk8g2V9h2D45zHL0JbAnIkZjEJgU9FHepIYeevrvkmL1FX6VbDJ4ksTd-HXnqiNffjMN3dZ6Oq3IxPnkSJBKLlYJnuXPDFWm_GFpT-tl3ngOA9nxQk2E7n8fp93iekHuo3B5XQMrmAZuRIyTE-haRcsnI9CRVQoccU8FiTde5fcDkCAtpZh80reP520EaSd7NEN_HbQuq_LrNEEt8fOGWw55a3i9d-A5dj-_f-KT7_JCgG5FAoB5bFJNAhg Apr 20 15:49:53 tycshd volumio[662]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 20 15:49:53 tycshd volumio[662]: info: Discovery: this is already registered, 120ce0ca-4893-4538-b389-bf03232d172c Apr 20 15:49:53 tycshd volumio[662]: info: Discovery: Found device TycSHD Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::volumioGetState Apr 20 15:49:53 tycshd volumio[662]: info: CorePlayQueue::getTrack 0 Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::volumioGetState Apr 20 15:49:53 tycshd volumio[662]: info: CorePlayQueue::getTrack 0 Apr 20 15:49:53 tycshd go-librespot[1079]: time="2025-04-20T15:49:53+02:00" level=info msg="running go-librespot 0.2.0" Apr 20 15:49:53 tycshd go-librespot[1079]: time="2025-04-20T15:49:53+02:00" level=debug msg="app state loaded" Apr 20 15:49:53 tycshd go-librespot[1079]: time="2025-04-20T15:49:53+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 20 15:49:53 tycshd volumio[662]: info: CoreCommandRouter::volumioGetState Apr 20 15:49:53 tycshd volumio[662]: info: CorePlayQueue::getTrack 0 Apr 20 15:49:54 tycshd volumio-remote-updater[453]: [2025-04-20 15:49:54] [connect] Successful connection Apr 20 15:49:54 tycshd volumio[662]: info: CorePlayQueue::getTrack 0 Apr 20 15:49:54 tycshd volumio[662]: info: CoreCommandRouter::volumiosetSourceActiveno-source Apr 20 15:49:54 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 20 15:49:54 tycshd volumio[662]: Cannot find translation for source SoundCloud Apr 20 15:49:54 tycshd volumio[662]: Cannot find translation for source YouTube2 Apr 20 15:49:54 tycshd volumio[662]: Cannot find translation for source Presets Apr 20 15:49:54 tycshd volumio[662]: info: CoreCommandRouter::volumioStop Apr 20 15:49:54 tycshd volumio[662]: info: CoreStateMachine::stop Apr 20 15:49:54 tycshd volumio[662]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 15:49:54 tycshd volumio[662]: info: Notifying Active Input {"trackType":"input","service":"inputs","title":"TOSLINK","disableUiControls":true,"albumart":"/albumart"} Apr 20 15:49:54 tycshd volumio[662]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 20 15:49:54 tycshd volumio-remote-updater[453]: [2025-04-20 15:49:54] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1745156994 101 Apr 20 15:49:54 tycshd volumio[662]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 2 Apr 20 15:49:54 tycshd volumio[662]: SPOTIFY: User informations: {"country":"DE","display_name":"tyc0rc","email":"t.schottdorf@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/tyc0rc"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/tyc0rc","id":"tyc0rc","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee851e490f7a46a57804e154e2c6","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b821e490f7a46a57804e154e2c6","width":64}],"product":"premium","type":"user","uri":"spotify:user:tyc0rc"} Apr 20 15:49:54 tycshd volumio[662]: info: Spotify Successfully logged in Apr 20 15:49:54 tycshd volumio[662]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 20 15:49:54 tycshd volumio[662]: info: [1745156994217] CoreMusicLibrary::Adding element Spotify Apr 20 15:49:54 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 20 15:49:54 tycshd volumio[662]: Cannot find translation for source SoundCloud Apr 20 15:49:54 tycshd volumio[662]: Cannot find translation for source YouTube2 Apr 20 15:49:54 tycshd volumio[662]: Cannot find translation for source Presets Apr 20 15:49:54 tycshd volumio[662]: Cannot find translation for source Spotify Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=info msg="zeroconf server listening on port 43135" Apr 20 15:49:54 tycshd volumio[662]: info: CoreCommandRouter::servicePushState Apr 20 15:49:54 tycshd volumio[662]: info: CoreStateMachine::pushState Apr 20 15:49:54 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 20 15:49:54 tycshd volumio[662]: info: CoreCommandRouter::volumioPushState Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=debug msg="obtained new client token: AACCCNHPFJXUzTH7vS7GNUeuANH6FX1sv47e8rhznNXOaeP9xbEFC7YDJVpUFXsBac2O+LBuAKUxtigSvz836IAUSwYxNecrV2V4xaVTdrFkllSZtduT3D9tWJNjXOMUOu/SiHSgzSIfA0xa2xmHICRsi0Xiw6tmNZlP8IM3d+54OEHFBktWyWK5VdWuhYldaG6+n2FoKJChW2PQmy9cL2hKOUV+9BrfVyOk4IT1JheOgDJ80WWE/L0q" Apr 20 15:49:54 tycshd volumio[662]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=debug msg="completed keyexchange" Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=debug msg="completed challenge" Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=info msg="authenticated AP as tyc0rc" Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=info msg="authenticated Login5 as tyc0rc" Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=debug msg="initializing zeroconf session, username: tyc0rc" Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=debug msg="dealer connection opened" Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=trace msg="starting accesspoint recv loop" Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=trace msg="starting dealer recv loop" Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=trace msg="received accesspoint ping" Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 20 15:49:54 tycshd go-librespot[1079]: time="2025-04-20T15:49:54+02:00" level=debug msg="received connection id: Zjk5Y2ZkMDYtN2ZiMy00M2I4LWFhOGQtZDAzNjUyODQzMjViK2RlYWxlcit0Y3A6Ly8wYWNhNWE1Ni5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArOEVGQTMwRkU5NTI5ODkwN0FFRjZBMzc3QzVBRTc4MzNBRUM4OTM1RTAwRTVDRjg1RTdEMTAzRjIwODFDQzNBQg==" Apr 20 15:49:55 tycshd go-librespot[1079]: time="2025-04-20T15:49:55+02:00" level=debug msg="put connect state because NEW_DEVICE" Apr 20 15:49:55 tycshd go-librespot[1079]: time="2025-04-20T15:49:55+02:00" level=debug msg="update volume to 65535/65535" Apr 20 15:49:55 tycshd go-librespot[1079]: time="2025-04-20T15:49:55+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 20 15:49:55 tycshd go-librespot[1079]: time="2025-04-20T15:49:55+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 20 15:49:55 tycshd go-librespot[1079]: time="2025-04-20T15:49:55+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 20 15:49:55 tycshd go-librespot[1079]: time="2025-04-20T15:49:55+02:00" level=trace msg="received accesspoint pong ack" Apr 20 15:49:55 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 20 15:49:55 tycshd volumio[662]: info: Enabling external Volume Control Apr 20 15:49:55 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:55 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 20 15:49:56 tycshd go-librespot[1079]: time="2025-04-20T15:49:56+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 20 15:49:56 tycshd go-librespot[1079]: time="2025-04-20T15:49:56+02:00" level=trace msg="emitting websocket event: volume" Apr 20 15:49:56 tycshd mpd[1052]: Apr 20 15:49 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 20 15:49:56 tycshd volumio[662]: info: CoreStateMachine::pushState Apr 20 15:49:56 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 20 15:49:56 tycshd volumio[662]: info: CoreCommandRouter::volumioPushState Apr 20 15:49:56 tycshd systemd[1]: Started Music Player Daemon. Apr 20 15:49:56 tycshd volumio[662]: Upnp client error: Error: This socket has been ended by the other party Apr 20 15:49:56 tycshd sudo[1047]: pam_unix(sudo:session): session closed for user root Apr 20 15:49:56 tycshd sudo[1040]: pam_unix(sudo:session): session closed for user root Apr 20 15:49:56 tycshd volumio[662]: info: Completed starting Core Plugins Apr 20 15:49:56 tycshd volumio[662]: info: ------------------------------------------- Apr 20 15:49:56 tycshd volumio[662]: info: ----- MyVolumio plugins startup ---- Apr 20 15:49:56 tycshd volumio[662]: info: ------------------------------------------- Apr 20 15:49:56 tycshd volumio[662]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 20 15:49:56 tycshd volumio[662]: info: MPD running with PID1052 Apr 20 15:49:56 tycshd volumio[662]: ,establishing connection Apr 20 15:49:56 tycshd volumio[662]: info: go-librespot daemon successfully initialized Apr 20 15:49:56 tycshd sudo[1106]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Tycplex,password=^lc*$2:JhS)h,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //Tycstation/Music /mnt/NAS/Tycstation Apr 20 15:49:56 tycshd sudo[1106]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 20 15:49:56 tycshd kernel: FS-Cache: Loaded Apr 20 15:49:56 tycshd kernel: FS-Cache: Netfs 'cifs' registered for caching Apr 20 15:49:56 tycshd kernel: Key type cifs.idmap registered Apr 20 15:49:56 tycshd kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount. Apr 20 15:49:56 tycshd volumio[662]: error: MPD error: The expression evaluated to a falsy value: Apr 20 15:49:56 tycshd volumio[662]: assert.ok(self.idling) Apr 20 15:49:56 tycshd volumio[662]: error: The expression evaluated to a falsy value: Apr 20 15:49:56 tycshd volumio[662]: assert.ok(self.idling) Apr 20 15:49:56 tycshd volumio[662]: error: MPD error: The expression evaluated to a falsy value: Apr 20 15:49:56 tycshd volumio[662]: assert.ok(self.idling) Apr 20 15:49:56 tycshd volumio[662]: error: The expression evaluated to a falsy value: Apr 20 15:49:56 tycshd volumio[662]: assert.ok(self.idling) Apr 20 15:49:56 tycshd volumio[662]: error: updateQueue error: null Apr 20 15:49:57 tycshd sudo[1106]: pam_unix(sudo:session): session closed for user root Apr 20 15:49:57 tycshd volumio[1075]: Generating RSA private key, 4096 bit long modulus (2 primes) Apr 20 15:49:57 tycshd volumio[662]: info: CoreStateMachine::pushState Apr 20 15:49:57 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 20 15:49:57 tycshd volumio[662]: info: CoreCommandRouter::volumioPushState Apr 20 15:49:57 tycshd volumio[662]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Apr 20 15:49:59 tycshd volumio[662]: info: Initializing connection to go-librespot Websocket Apr 20 15:49:59 tycshd go-librespot[1079]: time="2025-04-20T15:49:59+02:00" level=debug msg="new websocket client" Apr 20 15:49:59 tycshd volumio[662]: info: Connection to go-librespot Websocket established Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="handling transfer player command from e465ffcfb2f72061eae7c624ab845033f18e502b" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="resolved context of track" uri="spotify:search:craw" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:search:craw" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="loading track (paused: false, position: 80949ms)" uri="spotify:track:57BrRMwf9LrcmuOsyGilwr" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=trace msg="emitting websocket event: will_play" Apr 20 15:50:01 tycshd volumio[662]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:57BrRMwf9LrcmuOsyGilwr","play_origin":"search"}} Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="selected format OGG_VORBIS_320 (a921507b919393cc3320273412096750cb21fe33)" uri="spotify:track:57BrRMwf9LrcmuOsyGilwr" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="requested aes key for file a921507b919393cc3320273412096750cb21fe33, gid: 57BrRMwf9LrcmuOsyGilwr" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1655" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="fetched first chunk of 16, total size is 8217416 bytes" uri="spotify:track:57BrRMwf9LrcmuOsyGilwr" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:57BrRMwf9LrcmuOsyGilwr" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1273" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="fetched chunk 6/15, size: 524288" uri="spotify:track:57BrRMwf9LrcmuOsyGilwr" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:57BrRMwf9LrcmuOsyGilwr" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:57BrRMwf9LrcmuOsyGilwr" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="fetched chunk 5/15, size: 524288" uri="spotify:track:57BrRMwf9LrcmuOsyGilwr" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=trace msg="seek to 80949ms (diff: 58ms, samples: 3569850, bytes: 3144800)" uri="spotify:track:57BrRMwf9LrcmuOsyGilwr" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="created new output device" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="fetched chunk 8/15, size: 524288" uri="spotify:track:57BrRMwf9LrcmuOsyGilwr" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="fetched chunk 7/15, size: 524288" uri="spotify:track:57BrRMwf9LrcmuOsyGilwr" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 166666 us, period size = 7350 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 3 frames" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=info msg="loaded track \"Crawling\" (paused: false, position: 80949ms, duration: 208960ms, prefetched: false)" uri="spotify:track:57BrRMwf9LrcmuOsyGilwr" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="fetched chunk 9/15, size: 524288" uri="spotify:track:57BrRMwf9LrcmuOsyGilwr" Apr 20 15:50:01 tycshd volumio[662]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=trace msg="scheduling prefetch in 98s" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=trace msg="emitting websocket event: metadata" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=trace msg="emitting websocket event: active" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="sending successful reply for dealer request" Apr 20 15:50:01 tycshd volumio[662]: Cannot compose Albumart path Apr 20 15:50:01 tycshd volumio[662]: Cannot compose Albumart path Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=trace msg="emitting websocket event: playing" Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Apr 20 15:50:01 tycshd go-librespot[1079]: time="2025-04-20T15:50:01+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 20 15:50:02 tycshd volumio[662]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:57BrRMwf9LrcmuOsyGilwr","name":"Crawling","artist_names":["Linkin Park"],"album_name":"Hybrid Theory (Bonus Edition)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e2f039481babe23658fc719a","position":80949,"duration":208960,"release_date":"year:2000 month:10 day:24","track_number":5,"disc_number":1}} Apr 20 15:50:02 tycshd volumio[662]: SPOTIFY: received: {"type":"active","data":null} Apr 20 15:50:02 tycshd volumio[662]: info: Aligning Spotify Volume to Volumio Volume Apr 20 15:50:02 tycshd volumio[662]: info: CoreCommandRouter::volumioGetState Apr 20 15:50:02 tycshd volumio[662]: info: Setting Spotify Volume from Volumio: 68 Apr 20 15:50:02 tycshd volumio[662]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:57BrRMwf9LrcmuOsyGilwr","play_origin":"search"}} Apr 20 15:50:02 tycshd volumio[662]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 20 15:50:02 tycshd volumio[662]: TypeError: Cannot read property 'service' of undefined Apr 20 15:50:02 tycshd volumio[662]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:340:50) Apr 20 15:50:02 tycshd volumio[662]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:266:18) Apr 20 15:50:02 tycshd volumio[662]: at WebSocket.message (/data/plugins/music_service/spop/index.js:193:14) Apr 20 15:50:02 tycshd volumio[662]: at WebSocket.emit (events.js:400:28) Apr 20 15:50:02 tycshd volumio[662]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Apr 20 15:50:02 tycshd volumio[662]: at Receiver.emit (events.js:400:28) Apr 20 15:50:02 tycshd volumio[662]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Apr 20 15:50:02 tycshd volumio[662]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Apr 20 15:50:02 tycshd volumio[662]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Apr 20 15:50:02 tycshd volumio[662]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Apr 20 15:50:02 tycshd volumio[662]: at writeOrBuffer (internal/streams/writable.js:358:12) Apr 20 15:50:02 tycshd volumio[662]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Apr 20 15:50:02 tycshd volumio[662]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Apr 20 15:50:02 tycshd volumio[662]: at Socket.emit (events.js:400:28) Apr 20 15:50:02 tycshd volumio[662]: at addChunk (internal/streams/readable.js:293:12) Apr 20 15:50:02 tycshd volumio[662]: at readableAddChunk (internal/streams/readable.js:267:9) Apr 20 15:50:02 tycshd volumio[662]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 20 15:50:02 tycshd sudo[1155]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-20 15:49 Apr 20 15:50:02 tycshd sudo[1155]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="17fcb754ddd6bd152b01008c46cc4ba1ca48bf35" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="281cefcd7a302aa7cfba569185cf7aae19b8c376" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 22 Mar 2024 03:00:28 PM CET" VOLUMIO_VERSION="3.608" VOLUMIO_HARDWARE="nanopineo2" VOLUMIO_DEVICENAME="NanoPi Neo2" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="29ccfe8a9cff19911db4b736879ac117"