-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Sat 2024-05-04 16:03:24 CEST. -- May 04 16:03:08 minidsp-shd ntpd[761]: receive: Unexpected origin timestamp 0xe9c0f707.b02c5eaf does not match aorg 0000000000.00000000 from server@213.209.109.44 xmt 0xe9e0be9c.8891fc61 May 04 16:03:08 minidsp-shd ntpd[761]: receive: Unexpected origin timestamp 0xe9c0f707.b028780c does not match aorg 0000000000.00000000 from server@144.91.116.85 xmt 0xe9e0be9c.8bf39dae May 04 16:03:08 minidsp-shd systemd[1]: Starting Daily apt download activities... May 04 16:03:09 minidsp-shd volumio[663]: info: Loading plugin "qobuz"... May 04 16:03:09 minidsp-shd systemd[1]: apt-daily.service: Succeeded. May 04 16:03:09 minidsp-shd systemd[1]: Started Daily apt download activities. May 04 16:03:09 minidsp-shd systemd[1]: Starting Daily apt upgrade and clean activities... May 04 16:03:10 minidsp-shd systemd[1]: apt-daily-upgrade.service: Succeeded. May 04 16:03:10 minidsp-shd systemd[1]: Started Daily apt upgrade and clean activities. May 04 16:03:11 minidsp-shd volumio[663]: info: Loading plugin "tidal"... May 04 16:03:13 minidsp-shd volumio[663]: info: Loading plugin "oem_helper"... May 04 16:03:14 minidsp-shd volumio[663]: info: Applying required configuration parameters for plugin oem_helper May 04 16:03:14 minidsp-shd volumio[663]: info: Loading plugin "updater_comm"... May 04 16:03:15 minidsp-shd volumio[663]: info: Plugin mpdemulation is not enabled May 04 16:03:15 minidsp-shd volumio[663]: info: Loading plugin "rest_api"... May 04 16:03:15 minidsp-shd volumio[663]: info: Loading plugin "websocket"... May 04 16:03:15 minidsp-shd volumio[663]: info: Loading i18n strings for locale de May 04 16:03:15 minidsp-shd volumio[663]: Updating browse sources language May 04 16:03:15 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 16:03:15 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 04 16:03:15 minidsp-shd volumio[663]: info: CoreCommandRouter::initPlayerControls May 04 16:03:15 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:15 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:15 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:15 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:15 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:15 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:15 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:15 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:15 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 04 16:03:15 minidsp-shd volumio[663]: Express server listening on port 3000 May 04 16:03:15 minidsp-shd volumio[663]: [Metrics] WebUI: 23s 541.96ms May 04 16:03:15 minidsp-shd volumio[663]: info: CoreStateMachine::resetVolumioState May 04 16:03:15 minidsp-shd volumio[663]: info: CoreStateMachine::getcurrentVolume May 04 16:03:15 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioRetrievevolume May 04 16:03:15 minidsp-shd volumio[663]: info: CoreStateMachine::pushState May 04 16:03:15 minidsp-shd volumio[663]: info: CorePlayQueue::getTrack 0 May 04 16:03:15 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 16:03:15 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioPushState May 04 16:03:15 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 16:03:15 minidsp-shd volumio[663]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' May 04 16:03:15 minidsp-shd volumio[663]: info: Completed loading Core Plugins May 04 16:03:15 minidsp-shd volumio[663]: info: Preparing to generate the ALSA configuration file May 04 16:03:15 minidsp-shd systemd[1]: systemd-fsckd.service: Succeeded. May 04 16:03:15 minidsp-shd volumio[663]: info: Cannot mount NAS Mukke at system boot, trial number 1 ,retrying in 5 seconds May 04 16:03:15 minidsp-shd volumio[663]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan May 04 16:03:15 minidsp-shd volumio[663]: wlan0 Interface doesn't support scanning. May 04 16:03:15 minidsp-shd volumio[663]: info: Cannot use regular scanning, forcing with ap-force May 04 16:03:15 minidsp-shd sudo[941]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force May 04 16:03:15 minidsp-shd sudo[941]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 16:03:15 minidsp-shd sudo[941]: pam_unix(sudo:session): session closed for user root May 04 16:03:15 minidsp-shd volumio[663]: command failed: No such device (-19) May 04 16:03:15 minidsp-shd volumio[663]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force May 04 16:03:15 minidsp-shd volumio[663]: command failed: No such device (-19) May 04 16:03:16 minidsp-shd volumio[663]: info: Asound.conf file unchanged, so no further update is needed May 04 16:03:16 minidsp-shd volumio[663]: info: Output device has changed, restarting MPD May 04 16:03:16 minidsp-shd sudo[952]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 04 16:03:16 minidsp-shd sudo[952]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 16:03:16 minidsp-shd sudo[952]: pam_unix(sudo:session): session closed for user root May 04 16:03:16 minidsp-shd volumio[663]: info: Output device has changed, restarting Shairport Sync May 04 16:03:16 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:16 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 16:03:16 minidsp-shd sudo[955]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 04 16:03:16 minidsp-shd sudo[955]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 16:03:16 minidsp-shd systemd[1]: Listening on mpd.socket. May 04 16:03:16 minidsp-shd systemd[1]: Starting Music Player Daemon... May 04 16:03:16 minidsp-shd volumio[663]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 04 16:03:16 minidsp-shd volumio[663]: info: ___________ START PLUGINS ___________ May 04 16:03:16 minidsp-shd volumio[663]: info: ControllerMpd::onStart: Initializing MPD May 04 16:03:16 minidsp-shd volumio[663]: info: Creating MPD Configuration file May 04 16:03:16 minidsp-shd sudo[962]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 04 16:03:16 minidsp-shd sudo[962]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 16:03:16 minidsp-shd sudo[962]: pam_unix(sudo:session): session closed for user root May 04 16:03:16 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 04 16:03:16 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 16:03:16 minidsp-shd volumio[663]: info: [1714831396342] CoreMusicLibrary::Adding element Medienserver May 04 16:03:16 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 16:03:16 minidsp-shd sudo[965]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 04 16:03:16 minidsp-shd sudo[965]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 16:03:16 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 04 16:03:16 minidsp-shd volumio[663]: info: Adding Manifest REST API Endpoints May 04 16:03:16 minidsp-shd volumio[663]: info: Adding manifestui REST Endpoint for plugin: miscellanea/manifestui May 04 16:03:16 minidsp-shd volumio[663]: info: Adding METAVOLUMIO REST API Endpoints May 04 16:03:16 minidsp-shd volumio[663]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio May 04 16:03:16 minidsp-shd volumio[663]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio May 04 16:03:16 minidsp-shd volumio[663]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio May 04 16:03:16 minidsp-shd volumio[663]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio May 04 16:03:16 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:16 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 16:03:16 minidsp-shd sudo[968]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name miniDSP SHD May 04 16:03:16 minidsp-shd sudo[968]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 16:03:16 minidsp-shd systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 04 16:03:16 minidsp-shd systemd[1]: mpd.service: Succeeded. May 04 16:03:16 minidsp-shd systemd[1]: Stopped Music Player Daemon. May 04 16:03:16 minidsp-shd systemd[1]: Starting Music Player Daemon... May 04 16:03:16 minidsp-shd kernel: Bluetooth: Core ver 2.22 May 04 16:03:16 minidsp-shd kernel: NET: Registered protocol family 31 May 04 16:03:16 minidsp-shd kernel: Bluetooth: HCI device and connection manager initialized May 04 16:03:16 minidsp-shd kernel: Bluetooth: HCI socket layer initialized May 04 16:03:16 minidsp-shd kernel: Bluetooth: L2CAP socket layer initialized May 04 16:03:16 minidsp-shd kernel: Bluetooth: SCO socket layer initialized May 04 16:03:16 minidsp-shd sudo[968]: pam_unix(sudo:session): session closed for user root May 04 16:03:16 minidsp-shd volumio[663]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 04 16:03:16 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:16 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 16:03:16 minidsp-shd volumio[663]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 04 16:03:16 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 16:03:16 minidsp-shd volumio[663]: info: [1714831396550] CoreMusicLibrary::Adding element Last_100 May 04 16:03:16 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 16:03:16 minidsp-shd volumio[663]: info: Streaming services startup May 04 16:03:16 minidsp-shd volumio[663]: info: Starting Streaming Daemon May 04 16:03:16 minidsp-shd sudo[981]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 04 16:03:16 minidsp-shd sudo[981]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 16:03:16 minidsp-shd sudo[981]: pam_unix(sudo:session): session closed for user root May 04 16:03:16 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 16:03:16 minidsp-shd volumio[663]: info: [1714831396673] CoreMusicLibrary::Adding element Webradio May 04 16:03:16 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 16:03:16 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 04 16:03:16 minidsp-shd sudo[988]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 04 16:03:16 minidsp-shd sudo[988]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 16:03:16 minidsp-shd volumio[663]: info: Creating Spotify config file May 04 16:03:16 minidsp-shd sudo[988]: pam_unix(sudo:session): session closed for user root May 04 16:03:16 minidsp-shd volumio[663]: error: Hi Res Audio Failed Login: Missing Login Data May 04 16:03:16 minidsp-shd volumio[663]: info: Adding HIGHRESAUDIO REST API Endpoints May 04 16:03:16 minidsp-shd volumio[663]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio May 04 16:03:16 minidsp-shd volumio[663]: info: Refreshing TIDAL token May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: Volumio Calling Home May 04 16:03:17 minidsp-shd volumio[663]: info: Stopping AccessToken refresher cron for QOBUZ May 04 16:03:17 minidsp-shd volumio[663]: info: AccessToken refresher cron started for QOBUZ May 04 16:03:17 minidsp-shd volumio[663]: info: Adding QOBUZ REST API Endpoints May 04 16:03:17 minidsp-shd volumio[663]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz May 04 16:03:17 minidsp-shd volumio[663]: info: Setting Device type: NanoPi NEO 2 May 04 16:03:17 minidsp-shd volumio[663]: info: CoreStateMachine::setRepeat null single undefined May 04 16:03:17 minidsp-shd volumio[663]: info: CoreStateMachine::pushState May 04 16:03:17 minidsp-shd volumio[663]: info: CorePlayQueue::getTrack 0 May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioPushState May 04 16:03:17 minidsp-shd volumio[663]: info: CoreStateMachine::setRandom null May 04 16:03:17 minidsp-shd volumio[663]: info: CoreStateMachine::pushState May 04 16:03:17 minidsp-shd volumio[663]: info: CorePlayQueue::getTrack 0 May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioPushState May 04 16:03:17 minidsp-shd volumio[663]: info: Serial port opened successfully May 04 16:03:17 minidsp-shd volumio[663]: error: Cannot start Volumio Streaming Daemon May 04 16:03:17 minidsp-shd volumio[663]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 04 16:03:17 minidsp-shd volumio[663]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 04 16:03:17 minidsp-shd volumio[663]: error: Cannot set new Bluetooth Name : Error: Command failed: /usr/bin/sudo /bin/hciconfig hci0 name 'miniDSP SHD' May 04 16:03:17 minidsp-shd volumio[663]: Can't get device info: No such device May 04 16:03:17 minidsp-shd volumio[663]: info: MPD Permissions set May 04 16:03:17 minidsp-shd volumio[663]: info: MPD Permissions set May 04 16:03:17 minidsp-shd volumio[663]: info: Discovery: A device disappeared from network May 04 16:03:17 minidsp-shd volumio[663]: info: Discovery: Browse raised the following error TypeError: Cannot read property 'toLowerCase' of undefined May 04 16:03:17 minidsp-shd volumio[663]: info: Volumio called home May 04 16:03:17 minidsp-shd volumio[663]: info: Spotify config file written May 04 16:03:17 minidsp-shd sudo[1005]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 04 16:03:17 minidsp-shd sudo[1005]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 16:03:17 minidsp-shd volumio[663]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 1 May 04 16:03:17 minidsp-shd systemd[1]: Started go-librespot Daemon. May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd go-librespot[1008]: Librespot-go daemon starting... May 04 16:03:17 minidsp-shd sudo[1005]: pam_unix(sudo:session): session closed for user root May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:17 minidsp-shd volumio[663]: info: Discovery: adding 37c72e1a-a5b6-447a-afd2-964225ad7bb9 May 04 16:03:17 minidsp-shd volumio[663]: info: Discovery: Found device miniDSP SHD May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioGetState May 04 16:03:17 minidsp-shd volumio[663]: info: CorePlayQueue::getTrack 0 May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: raat , reconfigureAndRestartRaat May 04 16:03:17 minidsp-shd volumio[663]: info: Adding MINIDSP Inputs May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 16:03:17 minidsp-shd volumio[663]: info: [1714831397729] CoreMusicLibrary::Adding element Inputs May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 16:03:17 minidsp-shd volumio[663]: info: [1714831397733] CoreMusicLibrary::Adding element Presets May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 16:03:17 minidsp-shd volumio[663]: Cannot find translation for source Presets May 04 16:03:17 minidsp-shd volumio[663]: info: Discovery: this is already registered, 37c72e1a-a5b6-447a-afd2-964225ad7bb9 May 04 16:03:17 minidsp-shd volumio[663]: info: Discovery: Found device miniDSP SHD May 04 16:03:17 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioGetState May 04 16:03:17 minidsp-shd volumio[663]: info: CorePlayQueue::getTrack 0 May 04 16:03:17 minidsp-shd volumio[663]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 04 16:03:17 minidsp-shd volumio[663]: SPOTIFY: BQDlokOmfb0CFeyMbQCTRI3yzJLq60XE-9K76bbicjkjb63ZWQ-M6VRk_F9dKB_2A3EGmHGxcdC_PeP2Hw8nynreT10CFClPs4lNbiFkff_KaJtD42ICO39wroaey2lWDWrJ6BJ1qGlUDDMuCSxDcvDcGh2LzpSWZXo0729W9B542dvk9YHgj4vCoXtwd9K49O1CGXDsxVlFX4CgZle9N4KG7svyRVAWfLYOLw3VhdA0Is2Hr4mSnYB6zPpVt9cvVNWSUG8akyPPMKe8hA May 04 16:03:17 minidsp-shd volumio[663]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ May 04 16:03:17 minidsp-shd volumio[663]: info: New Spotify access token = BQDlokOmfb0CFeyMbQCTRI3yzJLq60XE-9K76bbicjkjb63ZWQ-M6VRk_F9dKB_2A3EGmHGxcdC_PeP2Hw8nynreT10CFClPs4lNbiFkff_KaJtD42ICO39wroaey2lWDWrJ6BJ1qGlUDDMuCSxDcvDcGh2LzpSWZXo0729W9B542dvk9YHgj4vCoXtwd9K49O1CGXDsxVlFX4CgZle9N4KG7svyRVAWfLYOLw3VhdA0Is2Hr4mSnYB6zPpVt9cvVNWSUG8akyPPMKe8hA May 04 16:03:17 minidsp-shd volumio[663]: info: Spotify credentials grant success - running version from March 24, 2019 May 04 16:03:17 minidsp-shd volumio[663]: info: Starting Shairport Sync May 04 16:03:17 minidsp-shd volumio[663]: info: Starting Shairport Sync May 04 16:03:17 minidsp-shd sudo[1029]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 04 16:03:17 minidsp-shd sudo[1029]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 16:03:17 minidsp-shd volumio[663]: info: Starting Shairport Sync May 04 16:03:18 minidsp-shd sudo[1032]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 04 16:03:18 minidsp-shd sudo[1032]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 16:03:18 minidsp-shd systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 04 16:03:18 minidsp-shd systemd[1]: shairport-sync.service: Succeeded. May 04 16:03:18 minidsp-shd systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 04 16:03:18 minidsp-shd sudo[1035]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 04 16:03:18 minidsp-shd sudo[1035]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 16:03:18 minidsp-shd systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 04 16:03:18 minidsp-shd sudo[1029]: pam_unix(sudo:session): session closed for user root May 04 16:03:18 minidsp-shd sudo[1032]: pam_unix(sudo:session): session closed for user root May 04 16:03:18 minidsp-shd systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 04 16:03:18 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:18+02:00" level=info msg="generated new device id: d0f04f781d621621b1687af7ae12a550b97de955" May 04 16:03:18 minidsp-shd systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 04 16:03:18 minidsp-shd systemd[1]: shairport-sync.service: Succeeded. May 04 16:03:18 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:18+02:00" level=debug msg="stored credentials found for rsjp59dkdxcm24bykm52m6tda" May 04 16:03:18 minidsp-shd systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 04 16:03:18 minidsp-shd volumio[663]: info: Access Token successfully retrieved May 04 16:03:18 minidsp-shd systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 04 16:03:18 minidsp-shd sudo[1035]: pam_unix(sudo:session): session closed for user root May 04 16:03:18 minidsp-shd volumio[663]: info: Shairport-Sync Started May 04 16:03:18 minidsp-shd volumio[663]: Error adding Membership: Error: addMembership EINVAL May 04 16:03:18 minidsp-shd volumio[663]: error: error May 04 16:03:18 minidsp-shd volumio[663]: info: Shairport-Sync Started May 04 16:03:18 minidsp-shd volumio[663]: info: Shairport-Sync Started May 04 16:03:18 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioGetState May 04 16:03:18 minidsp-shd volumio[663]: info: CorePlayQueue::getTrack 0 May 04 16:03:18 minidsp-shd volumio[663]: info: CorePlayQueue::getTrack 0 May 04 16:03:18 minidsp-shd volumio[663]: info: CoreCommandRouter::volumiosetSourceActiveno-source May 04 16:03:18 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 16:03:18 minidsp-shd volumio[663]: Cannot find translation for source Presets May 04 16:03:18 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioStop May 04 16:03:18 minidsp-shd volumio[663]: info: CoreStateMachine::stop May 04 16:03:18 minidsp-shd volumio[663]: info: CoreStateMachine::setConsumeUpdateService undefined May 04 16:03:18 minidsp-shd volumio[663]: info: Notifying Active Input {"trackType":"input","service":"inputs","title":"TOSLINK","disableUiControls":true,"albumart":"/albumart"} May 04 16:03:18 minidsp-shd volumio[663]: info: CoreStateMachine::setConsumeUpdateService undefined May 04 16:03:18 minidsp-shd volumio[663]: SPOTIFY: User informations: {"display_name":"Aori","external_urls":{"spotify":"https://open.spotify.com/user/rsjp59dkdxcm24bykm52m6tda"},"href":"https://api.spotify.com/v1/users/rsjp59dkdxcm24bykm52m6tda","id":"rsjp59dkdxcm24bykm52m6tda","images":[{"url":"https://i.scdn.co/image/ab67757000003b82b0e44710a9ff5acc511cc3b1","height":64,"width":64},{"url":"https://i.scdn.co/image/ab6775700000ee85b0e44710a9ff5acc511cc3b1","height":300,"width":300}],"type":"user","uri":"spotify:user:rsjp59dkdxcm24bykm52m6tda","followers":{"href":null,"total":0},"country":"DE","product":"premium","explicit_content":{"filter_enabled":false,"filter_locked":false},"email":"aori.sato@web.de"} May 04 16:03:18 minidsp-shd volumio[663]: info: Spotify Successfully logged in May 04 16:03:18 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 16:03:18 minidsp-shd volumio[663]: info: [1714831398549] CoreMusicLibrary::Adding element Spotify May 04 16:03:18 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 16:03:18 minidsp-shd volumio[663]: Cannot find translation for source Presets May 04 16:03:18 minidsp-shd volumio[663]: Cannot find translation for source Spotify May 04 16:03:18 minidsp-shd volumio[663]: info: Successfully retrieved User Session From TIDAL May 04 16:03:18 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:18+02:00" level=debug msg="obtained new client token: AADwM527K3ezGOhVCdYTcyKbkmOUHguk3YLOYU1ieleu3NBv82MUpLe6DFMNRlFaLgHKFBYzjLaEffjWbbLWwbg57KCu58vQAN4nURg7aHaS1fm1AXjkxXmnUNtzJXRWfP/4LGnWtEeqwxpMccALcFukLTOgjWxzI+rk8NT4cq9AABe+p2DC9GdE3INk+rrbLkfpFqBsNreO8hY94D4/a54NztCFT3gc736z0Qj2Sb2fg7o51V/zDs60afzx5A==" May 04 16:03:18 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:18+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-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 04 16:03:18 minidsp-shd volumio[663]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 May 04 16:03:18 minidsp-shd volumio[663]: info: CoreCommandRouter::servicePushState May 04 16:03:18 minidsp-shd volumio[663]: info: CoreStateMachine::pushState May 04 16:03:18 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 16:03:18 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioPushState May 04 16:03:18 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:18+02:00" level=debug msg="completed keyexchange" May 04 16:03:19 minidsp-shd volumio[663]: info: Successfully retrieved User Subscription From TIDAL May 04 16:03:19 minidsp-shd volumio[663]: info: Adding TIDAL to Browse Sources May 04 16:03:19 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 04 16:03:19 minidsp-shd volumio[663]: info: [1714831399043] CoreMusicLibrary::Adding element TIDAL May 04 16:03:19 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 04 16:03:19 minidsp-shd volumio[663]: Cannot find translation for source Presets May 04 16:03:19 minidsp-shd volumio[663]: Cannot find translation for source Spotify May 04 16:03:19 minidsp-shd volumio[663]: Cannot find translation for source TIDAL May 04 16:03:19 minidsp-shd volumio[663]: info: Stopping AccessToken refresher cron May 04 16:03:19 minidsp-shd volumio[663]: info: AccessToken refresher cron started May 04 16:03:19 minidsp-shd volumio[663]: info: Adding TIDAL REST API Endpoints May 04 16:03:19 minidsp-shd volumio[663]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal May 04 16:03:19 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:19+02:00" level=debug msg="completed challenge" May 04 16:03:19 minidsp-shd sudo[1043]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service May 04 16:03:19 minidsp-shd sudo[1043]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 16:03:19 minidsp-shd systemd[1]: Started Volumio Bluetooth Module. May 04 16:03:19 minidsp-shd sudo[1043]: pam_unix(sudo:session): session closed for user root May 04 16:03:19 minidsp-shd sudo[1046]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* May 04 16:03:19 minidsp-shd sudo[1046]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 16:03:19 minidsp-shd volumiobt[1045]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory May 04 16:03:19 minidsp-shd sudo[1046]: pam_unix(sudo:session): session closed for user root May 04 16:03:19 minidsp-shd volumio[663]: info: Volumio BT Module successfully started May 04 16:03:19 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:19+02:00" level=debug msg="authenticated as rsjp59dkdxcm24bykm52m6tda" May 04 16:03:19 minidsp-shd volumio[663]: info: TidalConnect service stoped! May 04 16:03:19 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:19+02:00" level=debug msg="authenticated as rsjp59dkdxcm24bykm52m6tda" May 04 16:03:19 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:19+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" May 04 16:03:19 minidsp-shd volumio[663]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 04 16:03:19 minidsp-shd volumio[663]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect May 04 16:03:19 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:19+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" May 04 16:03:19 minidsp-shd sudo[1058]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 04 16:03:19 minidsp-shd sudo[1058]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 16:03:19 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 04 16:03:19 minidsp-shd volumio[663]: info: Enabling external Volume Control May 04 16:03:19 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:19 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 04 16:03:19 minidsp-shd systemd[1]: Started Volumio Tidal Connect Service. May 04 16:03:19 minidsp-shd sudo[1058]: pam_unix(sudo:session): session closed for user root May 04 16:03:19 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:19+02:00" level=debug msg="dealer connection opened" May 04 16:03:19 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:19+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 04 16:03:19 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:19+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 04 16:03:19 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:19+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 04 16:03:19 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:19+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 04 16:03:19 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:19+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" May 04 16:03:19 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:19+02:00" level=debug msg="received connection id: MjM2MTJlZjEtZTIwZi00MjFmLTg1OGMtODY1NmEwNTBlZjkxK2RlYWxlcit0Y3A6Ly9nZXc0LWRlYWxlci1hLXg1cXAuZ2V3NC5zcG90aWZ5Lm5ldDo1NzAwKzc2NUY4NTg5MzZBNTg2NjMyRUE4OTYwQkI4ODQ4QkIxM0E1NzhBRDA0MUMwRThDQzg3ODBDNzUyN0NBMUFDRTQ=" May 04 16:03:20 minidsp-shd volumio-remote-updater[437]: [2024-05-04 16:03:20] [connect] Successful connection May 04 16:03:20 minidsp-shd volumio-remote-updater[437]: [2024-05-04 16:03:20] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1714831400 101 May 04 16:03:20 minidsp-shd volumio[663]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 3 May 04 16:03:20 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:20+02:00" level=debug msg="put connect state because NEW_DEVICE" May 04 16:03:20 minidsp-shd sudo[1064]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio May 04 16:03:20 minidsp-shd sudo[1064]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 16:03:20 minidsp-shd volumiobt[1045]: pulseaudio: no process found May 04 16:03:20 minidsp-shd sudo[1064]: pam_unix(sudo:session): session closed for user root May 04 16:03:20 minidsp-shd volumio[663]: info: Executing endpoint tc_getconfig May 04 16:03:20 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 04 16:03:20 minidsp-shd vtcs[1060]: STARTING TidalConnect services, version: 1.3.0.19 May 04 16:03:20 minidsp-shd dbus-daemon[430]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.13' (uid=1000 pid=1068 comm="/usr/bin/pulseaudio --high-priority=true ") May 04 16:03:20 minidsp-shd systemd[1]: Starting RealtimeKit Scheduling Policy Service... May 04 16:03:20 minidsp-shd volumio[663]: ------------------------------------ BT MESSAGE: BT STATUS: running May 04 16:03:20 minidsp-shd dbus-daemon[430]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' May 04 16:03:20 minidsp-shd systemd[1]: Started RealtimeKit Scheduling Policy Service. May 04 16:03:20 minidsp-shd vtcs[1060]: STARTED TidalConnect services. May 04 16:03:20 minidsp-shd rtkit-daemon[1069]: Successfully called chroot. May 04 16:03:20 minidsp-shd rtkit-daemon[1069]: Successfully dropped privileges. May 04 16:03:20 minidsp-shd rtkit-daemon[1069]: Successfully limited resources. May 04 16:03:20 minidsp-shd rtkit-daemon[1069]: Running. May 04 16:03:20 minidsp-shd rtkit-daemon[1069]: Canary thread running. May 04 16:03:20 minidsp-shd rtkit-daemon[1069]: Watchdog thread running. May 04 16:03:20 minidsp-shd dbus-daemon[430]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.14' (uid=0 pid=1069 comm="/usr/lib/rtkit/rtkit-daemon ") May 04 16:03:20 minidsp-shd systemd[1]: Starting Authorization Manager... May 04 16:03:20 minidsp-shd volumio[663]: info: Executing endpoint tc_connect May 04 16:03:20 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect May 04 16:03:20 minidsp-shd volumio[663]: info: Connecting to TidalConnect May 04 16:03:20 minidsp-shd volumio[663]: ------------------------------------ BT MESSAGE: BT STATUS: running May 04 16:03:20 minidsp-shd sudo[1079]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=musicshare4,password=12345678,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //DISKStation/music /mnt/NAS/Mukke May 04 16:03:20 minidsp-shd volumio[663]: info: CoreCommandRouter::servicePushState May 04 16:03:20 minidsp-shd volumio[663]: info: CoreStateMachine::pushState May 04 16:03:20 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioPushState May 04 16:03:20 minidsp-shd sudo[1079]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 16:03:20 minidsp-shd volumio[663]: info: CorePlayQueue::getTrack 0 May 04 16:03:20 minidsp-shd volumio[663]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} May 04 16:03:20 minidsp-shd volumio[663]: verbose: CURRENT POSITION 0 May 04 16:03:20 minidsp-shd volumio[663]: info: CoreStateMachine::syncState stateService stop May 04 16:03:20 minidsp-shd volumio[663]: info: CoreStateMachine::syncState currentStatus play May 04 16:03:20 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioPushState May 04 16:03:20 minidsp-shd volumio[663]: info: CoreStateMachine::stPlaybackTimer May 04 16:03:20 minidsp-shd volumio[663]: info: CoreCommandRouter::servicePushState May 04 16:03:20 minidsp-shd volumio[663]: info: CoreStateMachine::pushState May 04 16:03:20 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 16:03:20 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioPushState May 04 16:03:20 minidsp-shd volumio[663]: info: CorePlayQueue::getTrack 0 May 04 16:03:20 minidsp-shd volumio[663]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} May 04 16:03:20 minidsp-shd volumio[663]: verbose: CURRENT POSITION 0 May 04 16:03:20 minidsp-shd volumio[663]: info: CoreStateMachine::syncState stateService stop May 04 16:03:20 minidsp-shd volumio[663]: info: CoreStateMachine::syncState currentStatus stop May 04 16:03:20 minidsp-shd volumio[663]: info: CoreStateMachine::pushState May 04 16:03:20 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioPushState May 04 16:03:20 minidsp-shd mpd[971]: May 04 16:03 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 04 16:03:20 minidsp-shd volumio[663]: info: No code May 04 16:03:20 minidsp-shd volumio[663]: info: CoreStateMachine::pushState May 04 16:03:20 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioPushState May 04 16:03:20 minidsp-shd polkitd[1077]: started daemon version 0.105 using authority implementation `local' version `0.105' May 04 16:03:20 minidsp-shd dbus-daemon[430]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' May 04 16:03:20 minidsp-shd systemd[1]: Started Authorization Manager. May 04 16:03:20 minidsp-shd volumio[663]: info: go-librespot daemon successfully initialized May 04 16:03:20 minidsp-shd kernel: FS-Cache: Loaded May 04 16:03:21 minidsp-shd kernel: FS-Cache: Netfs 'cifs' registered for caching May 04 16:03:21 minidsp-shd kernel: Key type cifs.idmap registered May 04 16:03:21 minidsp-shd 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. May 04 16:03:21 minidsp-shd volumio[663]: info: CoreStateMachine::pushState May 04 16:03:21 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 16:03:21 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioPushState May 04 16:03:21 minidsp-shd systemd[1]: Started Music Player Daemon. May 04 16:03:21 minidsp-shd sudo[965]: pam_unix(sudo:session): session closed for user root May 04 16:03:21 minidsp-shd sudo[955]: pam_unix(sudo:session): session closed for user root May 04 16:03:21 minidsp-shd sudo[1079]: pam_unix(sudo:session): session closed for user root May 04 16:03:21 minidsp-shd volumio[663]: error: MPD error: The expression evaluated to a falsy value: May 04 16:03:21 minidsp-shd volumio[663]: assert.ok(self.idling) May 04 16:03:21 minidsp-shd volumio[663]: error: The expression evaluated to a falsy value: May 04 16:03:21 minidsp-shd volumio[663]: assert.ok(self.idling) May 04 16:03:21 minidsp-shd volumio[663]: info: MPD running with PID971 May 04 16:03:21 minidsp-shd volumio[663]: ,establishing connection May 04 16:03:21 minidsp-shd dbus-daemon[430]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.35' (uid=1000 pid=1068 comm="/usr/bin/pulseaudio --high-priority=true ") May 04 16:03:21 minidsp-shd systemd[1]: Starting Bluetooth service... May 04 16:03:21 minidsp-shd volumio[663]: error: MPD error: The expression evaluated to a falsy value: May 04 16:03:21 minidsp-shd volumio[663]: assert.ok(self.idling) May 04 16:03:21 minidsp-shd volumio[663]: error: The expression evaluated to a falsy value: May 04 16:03:21 minidsp-shd volumio[663]: assert.ok(self.idling) May 04 16:03:21 minidsp-shd volumio[663]: ------------------------------------ BT MESSAGE: BT STATUS: running May 04 16:03:21 minidsp-shd volumio[663]: error: updateQueue error: null May 04 16:03:21 minidsp-shd bluetoothd[1119]: Bluetooth daemon 5.23 May 04 16:03:21 minidsp-shd dbus-daemon[430]: [system] Successfully activated service 'org.bluez' May 04 16:03:21 minidsp-shd systemd[1]: Started Bluetooth service. May 04 16:03:21 minidsp-shd bluetoothd[1119]: Starting SDP server May 04 16:03:21 minidsp-shd kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 May 04 16:03:21 minidsp-shd kernel: Bluetooth: BNEP filters: protocol multicast May 04 16:03:21 minidsp-shd kernel: Bluetooth: BNEP socket layer initialized May 04 16:03:21 minidsp-shd dbus-daemon[430]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.36' (uid=0 pid=1119 comm="/usr/local/libexec/bluetooth/bluetoothd ") May 04 16:03:21 minidsp-shd pulseaudio[1068]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 May 04 16:03:21 minidsp-shd pulseaudio[1068]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 May 04 16:03:21 minidsp-shd bluetoothd[1119]: Bluetooth management interface 1.14 initialized May 04 16:03:21 minidsp-shd volumiobt[1045]: Applying permissions May 04 16:03:21 minidsp-shd volumiobt[1045]: Setting BT discoverable and pairable May 04 16:03:21 minidsp-shd pulseaudio[1068]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files May 04 16:03:21 minidsp-shd systemd[1]: Starting Hostname Service... May 04 16:03:21 minidsp-shd volumio[663]: ------------------------------------ BT MESSAGE: BT STATUS: running May 04 16:03:21 minidsp-shd volumiobt[1045]: [38B blob data] May 04 16:03:21 minidsp-shd volumiobt[1045]: Invalid command May 04 16:03:21 minidsp-shd volumiobt[1045]: [bluetooth]# agent on May 04 16:03:21 minidsp-shd volumiobt[1045]: [bluetooth]# discoverable on May 04 16:03:21 minidsp-shd volumiobt[1045]: No default controller available May 04 16:03:21 minidsp-shd volumiobt[1045]: [bluetooth]# pairable on May 04 16:03:21 minidsp-shd volumiobt[1045]: No default controller available May 04 16:03:21 minidsp-shd volumiobt[1045]: [bluetooth]# agent NoInputNoOutput May 04 16:03:21 minidsp-shd volumiobt[1045]: Failed to register agent object May 04 16:03:21 minidsp-shd volumiobt[1045]: [bluetooth]# default-agent May 04 16:03:21 minidsp-shd volumiobt[1045]: No agent is registered May 04 16:03:21 minidsp-shd volumiobt[1045]: [bluetooth]# quit May 04 16:03:21 minidsp-shd volumiobt[1045]: [61B blob data] May 04 16:03:21 minidsp-shd volumiobt[1045]: [62B blob data] May 04 16:03:21 minidsp-shd dbus-daemon[430]: [system] Successfully activated service 'org.freedesktop.hostname1' May 04 16:03:21 minidsp-shd systemd[1]: Started Hostname Service. May 04 16:03:21 minidsp-shd volumio[663]: info: CoreStateMachine::pushState May 04 16:03:21 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 16:03:21 minidsp-shd volumio[663]: info: CoreCommandRouter::volumioPushState May 04 16:03:21 minidsp-shd volumio[663]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume May 04 16:03:22 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:22+02:00" level=debug msg="handling transfer player command from 75c65fd70fdf5231b6f70daafbcbb971b6253786" May 04 16:03:22 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:22+02:00" level=debug msg="loading track spotify:track:6ULPTGkn3X3fAMjs7HhgVT (paused: true, position: 148493ms)" May 04 16:03:22 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:22+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 16:03:22 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:22+02:00" level=trace msg="emitting websocket event: will_play" May 04 16:03:22 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:22+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" May 04 16:03:22 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:22+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:6ULPTGkn3X3fAMjs7HhgVT" May 04 16:03:22 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:22+02:00" level=debug msg="requested aes key for file 4b86883c732b4cbe0c544ae6b011e66b5e548f3d, gid: 6ULPTGkn3X3fAMjs7HhgVT" May 04 16:03:22 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:22+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1903" May 04 16:03:22 minidsp-shd volumio[663]: info: TidalConnect service started! May 04 16:03:22 minidsp-shd volumio[663]: info: Completed starting Core Plugins May 04 16:03:22 minidsp-shd volumio[663]: info: ------------------------------------------- May 04 16:03:22 minidsp-shd volumio[663]: info: ----- MyVolumio plugins startup ---- May 04 16:03:22 minidsp-shd volumio[663]: info: ------------------------------------------- May 04 16:03:22 minidsp-shd volumio[663]: info: [MyVolumio PluginManager] Fetching plans data.... May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1504" May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=debug msg="fetched first chunk of 20, total size is 10412568 bytes" May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=debug msg="fetched chunk 1/19, size: 524288" May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=debug msg="fetched chunk 15/19, size: 524288" May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=debug msg="fetched chunk 13/19, size: 524288" May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=debug msg="fetched chunk 2/19, size: 524288" May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=debug msg="fetched chunk 3/19, size: 524288" May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=debug msg="fetched chunk 14/19, size: 524288" May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=debug msg="fetched chunk 12/19, size: 524288" May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=trace msg="seek to 148493ms (diff: 146ms, samples: 6548541, bytes: 6437449)" May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=info msg="loaded track \"DISSENSION\" (uri: spotify:track:6ULPTGkn3X3fAMjs7HhgVT, paused: true, position: 148493ms, duration: 241466ms)" May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=trace msg="emitting websocket event: metadata" May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=trace msg="emitting websocket event: active" May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=debug msg="sending successful reply for delaer request" May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 04 16:03:23 minidsp-shd volumio[663]: info: Initializing connection to go-librespot Websocket May 04 16:03:23 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:23+02:00" level=debug msg="new websocket client" May 04 16:03:23 minidsp-shd volumio[663]: info: Connection to go-librespot Websocket established May 04 16:03:24 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:24+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 04 16:03:24 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:24+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 04 16:03:24 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:24+02:00" level=trace msg="emitting websocket event: paused" May 04 16:03:24 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:24+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1907" May 04 16:03:24 minidsp-shd volumio[663]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6ULPTGkn3X3fAMjs7HhgVT","play_origin":"playlist"}} May 04 16:03:24 minidsp-shd volumio[663]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 04 16:03:24 minidsp-shd volumio[663]: TypeError: Cannot read property 'service' of undefined May 04 16:03:24 minidsp-shd volumio[663]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:322:50) May 04 16:03:24 minidsp-shd volumio[663]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:256:18) May 04 16:03:24 minidsp-shd volumio[663]: at WebSocket.message (/data/plugins/music_service/spop/index.js:175:14) May 04 16:03:24 minidsp-shd volumio[663]: at WebSocket.emit (events.js:400:28) May 04 16:03:24 minidsp-shd volumio[663]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1192:20) May 04 16:03:24 minidsp-shd volumio[663]: at Receiver.emit (events.js:400:28) May 04 16:03:24 minidsp-shd volumio[663]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:560:14) May 04 16:03:24 minidsp-shd volumio[663]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:478:17) May 04 16:03:24 minidsp-shd volumio[663]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:22) May 04 16:03:24 minidsp-shd volumio[663]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:180:18 May 04 16:03:24 minidsp-shd volumio[663]: at internal/process/task_queues.js:141:7 May 04 16:03:24 minidsp-shd volumio[663]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) May 04 16:03:24 minidsp-shd volumio[663]: at AsyncResource.runMicrotask (internal/process/task_queues.js:138:8) May 04 16:03:24 minidsp-shd volumio[663]: at processTicksAndRejections (internal/process/task_queues.js:95:5) May 04 16:03:24 minidsp-shd volumio[663]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 04 16:03:24 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:24+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 04 16:03:24 minidsp-shd go-librespot[1008]: time="2024-05-04T16:03:24+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1903" May 04 16:03:24 minidsp-shd sudo[1135]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-04 16:02 May 04 16:03:24 minidsp-shd sudo[1135]: 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"