-- Logs begin at Wed 2024-10-30 04:12:16 CET, end at Sun 2024-11-24 19:44:09 CET. -- Nov 24 19:43:23 minidsp-shd systemd[1]: Starting Daily apt download activities... Nov 24 19:43:24 minidsp-shd volumio[790]: info: Loading plugin "network"... Nov 24 19:43:24 minidsp-shd volumio[790]: info: Refreshing Cached IP Addresses Nov 24 19:43:24 minidsp-shd sudo[874]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 24 19:43:24 minidsp-shd sudo[874]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:24 minidsp-shd volumio[790]: info: Loading plugin "services"... Nov 24 19:43:24 minidsp-shd sudo[877]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 24 19:43:24 minidsp-shd sudo[874]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:24 minidsp-shd volumio[790]: info: Loading plugin "alsa_controller"... Nov 24 19:43:24 minidsp-shd sudo[877]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:24 minidsp-shd sudo[877]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:24 minidsp-shd sudo[881]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Nov 24 19:43:24 minidsp-shd sudo[881]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:24 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 24 19:43:24 minidsp-shd volumio[790]: info: Loading plugin "wizard"... Nov 24 19:43:24 minidsp-shd volumio[790]: info: Loading plugin "networkfs"... Nov 24 19:43:24 minidsp-shd systemd[1]: apt-daily.service: Succeeded. Nov 24 19:43:24 minidsp-shd systemd[1]: Started Daily apt download activities. Nov 24 19:43:24 minidsp-shd systemd[1]: Starting Daily apt upgrade and clean activities... Nov 24 19:43:25 minidsp-shd volumio[790]: info: Starting Udev Watcher for removable devices Nov 24 19:43:25 minidsp-shd sudo[898]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.10.197/USB /mnt/NAS/USB Nov 24 19:43:25 minidsp-shd sudo[898]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:25 minidsp-shd kernel: FS-Cache: Loaded Nov 24 19:43:25 minidsp-shd volumio[790]: info: Ignoring mount for partition: BOOT Nov 24 19:43:25 minidsp-shd volumio[790]: info: Ignoring mount for partition: volumio Nov 24 19:43:25 minidsp-shd volumio[790]: info: Ignoring mount for partition: volumio_data Nov 24 19:43:25 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 24 19:43:25 minidsp-shd volumio[790]: info: Loading plugin "volumio_command_line_client"... Nov 24 19:43:25 minidsp-shd volumio[790]: info: Loading plugin "upnp"... Nov 24 19:43:25 minidsp-shd volumio[790]: info: [1732473805283] Starting Upmpd Daemon Nov 24 19:43:25 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 24 19:43:25 minidsp-shd volumio[790]: info: Loading plugin "my_music"... Nov 24 19:43:25 minidsp-shd kernel: FS-Cache: Netfs 'cifs' registered for caching Nov 24 19:43:25 minidsp-shd kernel: Key type cifs.spnego registered Nov 24 19:43:25 minidsp-shd kernel: Key type cifs.idmap registered Nov 24 19:43:25 minidsp-shd kernel: CIFS: Attempting to mount //192.168.10.197/USB Nov 24 19:43:25 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. Nov 24 19:43:25 minidsp-shd volumio[790]: info: Loading plugin "mpd"... Nov 24 19:43:25 minidsp-shd sudo[898]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:26 minidsp-shd systemd[1]: apt-daily-upgrade.service: Succeeded. Nov 24 19:43:26 minidsp-shd systemd[1]: Started Daily apt upgrade and clean activities. Nov 24 19:43:26 minidsp-shd volumio-remote-updater[458]: [2024-11-24 19:43:26] [connect] Successful connection Nov 24 19:43:26 minidsp-shd volumio[790]: info: Loading plugin "upnp_browser"... Nov 24 19:43:27 minidsp-shd volumio[790]: info: Loading plugin "bluetooth"... Nov 24 19:43:27 minidsp-shd volumio[790]: info: [1732473807460] Starting BluetoothController Nov 24 19:43:27 minidsp-shd volumio[790]: info: Loading plugin "alarm-clock"... Nov 24 19:43:28 minidsp-shd volumio[790]: info: Loading plugin "manifestui"... Nov 24 19:43:28 minidsp-shd volumio[790]: info: Loading plugin "metavolumio"... Nov 24 19:43:29 minidsp-shd sudo[881]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:30 minidsp-shd volumio[790]: info: Loading plugin "airplay_emulation"... Nov 24 19:43:30 minidsp-shd volumio[790]: info: Starting Shairport Sync Nov 24 19:43:30 minidsp-shd volumio[790]: info: Loading plugin "cd_controller"... Nov 24 19:43:31 minidsp-shd volumio[790]: info: Loading plugin "last_100"... Nov 24 19:43:31 minidsp-shd volumio[790]: info: Loading plugin "raat"... Nov 24 19:43:31 minidsp-shd volumio[790]: info: RAAT Plugin loaded Nov 24 19:43:31 minidsp-shd volumio[790]: info: Adding restartRAATSocket REST API Endpoint Nov 24 19:43:31 minidsp-shd volumio[790]: info: Adding restartRAATSocket REST Endpoint for plugin: music_service/raat Nov 24 19:43:32 minidsp-shd volumio[790]: info: Loading plugin "streaming_services"... Nov 24 19:43:34 minidsp-shd volumio[790]: info: Starting Streaming Service Transparent Proxy Nov 24 19:43:34 minidsp-shd volumio[790]: info: Loading plugin "tidalconnect"... Nov 24 19:43:34 minidsp-shd volumio[790]: info: Loading plugin "webradio"... Nov 24 19:43:35 minidsp-shd volumio[790]: info: Loading plugin "i2s_dacs"... Nov 24 19:43:35 minidsp-shd volumio[790]: info: I2S DAC not set, start Auto-detection Nov 24 19:43:35 minidsp-shd volumio[790]: info: Loading plugin "volumiodiscovery"... Nov 24 19:43:35 minidsp-shd volumio[790]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 24 19:43:35 minidsp-shd node[790]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 24 19:43:35 minidsp-shd node[790]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 24 19:43:35 minidsp-shd volumio[790]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 24 19:43:35 minidsp-shd volumio[790]: *** WARNING *** For more information see Nov 24 19:43:35 minidsp-shd volumio[790]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 24 19:43:35 minidsp-shd volumio[790]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 24 19:43:35 minidsp-shd volumio[790]: *** WARNING *** For more information see Nov 24 19:43:35 minidsp-shd node[790]: *** WARNING *** For more information see Nov 24 19:43:35 minidsp-shd node[790]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 24 19:43:35 minidsp-shd node[790]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 24 19:43:35 minidsp-shd node[790]: *** WARNING *** For more information see Nov 24 19:43:35 minidsp-shd volumio[790]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 24 19:43:35 minidsp-shd volumio[790]: info: Discovery: Started advertising with name: miniDSP SHD Nov 24 19:43:35 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 24 19:43:35 minidsp-shd volumio[790]: info: Loading plugin "spop"... Nov 24 19:43:36 minidsp-shd volumio[790]: STREAMING PROXY: Starting server on port 3245 Nov 24 19:43:36 minidsp-shd volumio[790]: Node JS runtime: 14 Nov 24 19:43:38 minidsp-shd volumio[790]: info: Loading plugin "multiroom"... Nov 24 19:43:41 minidsp-shd volumio[790]: info: Applying required configuration parameters for plugin multiroom Nov 24 19:43:41 minidsp-shd sudo[984]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Nov 24 19:43:41 minidsp-shd sudo[984]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:41 minidsp-shd sudo[984]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:41 minidsp-shd volumio-remote-updater[458]: [2024-11-24 19:43:41] [connect] Successful connection Nov 24 19:43:41 minidsp-shd volumio[790]: info: MRS: MultiRoom plugin initialized Nov 24 19:43:41 minidsp-shd volumio[790]: info: MRS: STOPPING SNAPCLIENT Nov 24 19:43:41 minidsp-shd volumio[790]: info: MRS: Snap server stop Nov 24 19:43:41 minidsp-shd sudo[1000]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Nov 24 19:43:41 minidsp-shd sudo[1000]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:41 minidsp-shd volumio[790]: info: MRS: STOPPING volumioStreaming Nov 24 19:43:41 minidsp-shd sudo[1002]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Nov 24 19:43:41 minidsp-shd sudo[1002]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:41 minidsp-shd sudo[1005]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Nov 24 19:43:41 minidsp-shd sudo[1005]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:41 minidsp-shd volumio[790]: info: Loading plugin "outputs"... Nov 24 19:43:41 minidsp-shd sudo[1000]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:41 minidsp-shd volumio[790]: info: Loading plugin "albumart"... Nov 24 19:43:41 minidsp-shd sudo[1008]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Nov 24 19:43:41 minidsp-shd sudo[1008]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:41 minidsp-shd sudo[1008]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:41 minidsp-shd sudo[1002]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:41 minidsp-shd volumio[790]: info: Loading plugin "ms_surface_dial"... Nov 24 19:43:41 minidsp-shd sudo[1005]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:42 minidsp-shd volumio[790]: Forking 3 albumart workers Nov 24 19:43:42 minidsp-shd volumio[790]: info: Applying required configuration parameters for plugin ms_surface_dial Nov 24 19:43:42 minidsp-shd volumio[790]: info: Plugin example_plugin is not enabled Nov 24 19:43:42 minidsp-shd volumio[790]: info: Loading plugin "hi_res_audio"... Nov 24 19:43:44 minidsp-shd volumio[790]: Starting albumart workers Nov 24 19:43:44 minidsp-shd volumio[790]: Starting albumart workers Nov 24 19:43:44 minidsp-shd volumio[790]: Starting albumart workers Nov 24 19:43:46 minidsp-shd volumio[790]: info: Applying required configuration parameters for plugin hi_res_audio Nov 24 19:43:46 minidsp-shd volumio[790]: info: Loading plugin "inputs"... Nov 24 19:43:47 minidsp-shd volumio[790]: info: Loading plugin "qobuz"... Nov 24 19:43:49 minidsp-shd volumio[790]: info: Loading plugin "tidal"... Nov 24 19:43:52 minidsp-shd volumio[790]: info: Loading plugin "oem_helper"... Nov 24 19:43:54 minidsp-shd volumio[790]: info: Applying required configuration parameters for plugin oem_helper Nov 24 19:43:54 minidsp-shd volumio[790]: info: Loading plugin "updater_comm"... Nov 24 19:43:54 minidsp-shd volumio[790]: info: Plugin mpdemulation is not enabled Nov 24 19:43:54 minidsp-shd volumio[790]: info: Loading plugin "rest_api"... Nov 24 19:43:54 minidsp-shd volumio[790]: info: Loading plugin "websocket"... Nov 24 19:43:54 minidsp-shd volumio[790]: info: Loading i18n strings for locale en Nov 24 19:43:54 minidsp-shd volumio[790]: Updating browse sources language Nov 24 19:43:54 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreCommandRouter::initPlayerControls Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 19:43:55 minidsp-shd volumio[790]: Express server listening on port 3000 Nov 24 19:43:55 minidsp-shd volumio[790]: [Metrics] WebUI: 37s 187.42ms Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreStateMachine::resetVolumioState Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreStateMachine::getcurrentVolume Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioRetrievevolume Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreStateMachine::pushState Nov 24 19:43:55 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioPushState Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 19:43:55 minidsp-shd sudo[1108]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 24 19:43:55 minidsp-shd sudo[1108]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: inputs , getVolume Nov 24 19:43:55 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: inputs , getDSP Nov 24 19:43:55 minidsp-shd sudo[1108]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:55 minidsp-shd sudo[1110]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 24 19:43:55 minidsp-shd sudo[1110]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:55 minidsp-shd sudo[1110]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:55 minidsp-shd volumio[790]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Nov 24 19:43:55 minidsp-shd volumio[790]: info: Completed loading Core Plugins Nov 24 19:43:55 minidsp-shd volumio[790]: info: Preparing to generate the ALSA configuration file Nov 24 19:43:55 minidsp-shd volumio[790]: info: Cannot read play queue from file Nov 24 19:43:55 minidsp-shd volumio[790]: info: MRS: Removed streaming files Nov 24 19:43:55 minidsp-shd volumio[790]: info: MRS: volumioStreaming STOPPED Nov 24 19:43:55 minidsp-shd volumio[790]: info: MRS: SNAPSERVER STOPPED Nov 24 19:43:55 minidsp-shd volumio[790]: info: MRS: SNAPCLIENT STOPPED Nov 24 19:43:55 minidsp-shd volumio[790]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Nov 24 19:43:55 minidsp-shd volumio[790]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Nov 24 19:43:55 minidsp-shd volumio[790]: info: Reading ALSA contributions from plugins. Nov 24 19:43:56 minidsp-shd volumio[790]: info: Setting Device type: NanoPi NEO 3 Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreStateMachine::setRepeat false single undefined Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreStateMachine::pushState Nov 24 19:43:56 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioPushState Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreStateMachine::setRandom null Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreStateMachine::pushState Nov 24 19:43:56 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioPushState Nov 24 19:43:56 minidsp-shd volumio[790]: info: Asound.conf file unchanged, so no further update is needed Nov 24 19:43:56 minidsp-shd volumio[790]: info: Output device has changed, restarting MPD Nov 24 19:43:56 minidsp-shd sudo[1119]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 24 19:43:56 minidsp-shd sudo[1119]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:56 minidsp-shd volumio-remote-updater[458]: [2024-11-24 19:43:56] [connect] Successful connection Nov 24 19:43:56 minidsp-shd systemd[1]: Started UPnP Renderer front-end to MPD. Nov 24 19:43:56 minidsp-shd sudo[1119]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:56 minidsp-shd sudo[1122]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 24 19:43:56 minidsp-shd sudo[1122]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:56 minidsp-shd sudo[1122]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:56 minidsp-shd volumio[790]: info: Output device has changed, restarting Shairport Sync Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 19:43:56 minidsp-shd sudo[1126]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 24 19:43:56 minidsp-shd sudo[1126]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:56 minidsp-shd systemd[1]: Listening on mpd.socket. Nov 24 19:43:56 minidsp-shd volumio[790]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 24 19:43:56 minidsp-shd systemd[1]: Starting Music Player Daemon... Nov 24 19:43:56 minidsp-shd volumio[790]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:56 minidsp-shd volumio[790]: info: ___________ START PLUGINS ___________ Nov 24 19:43:56 minidsp-shd volumio[790]: info: ControllerMpd::onStart: Initializing MPD Nov 24 19:43:56 minidsp-shd volumio[790]: info: Creating MPD Configuration file Nov 24 19:43:56 minidsp-shd sudo[1135]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 19:43:56 minidsp-shd sudo[1135]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 24 19:43:56 minidsp-shd volumio[790]: info: [1732473836658] CoreMusicLibrary::Adding element Media Servers Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 24 19:43:56 minidsp-shd sudo[1135]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:56 minidsp-shd sudo[1137]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 24 19:43:56 minidsp-shd sudo[1137]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 24 19:43:56 minidsp-shd systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Nov 24 19:43:56 minidsp-shd systemd[1]: mpd.service: Succeeded. Nov 24 19:43:56 minidsp-shd systemd[1]: Stopped Music Player Daemon. Nov 24 19:43:56 minidsp-shd volumio[790]: info: Adding Manifest REST API Endpoints Nov 24 19:43:56 minidsp-shd systemd[1]: Starting Music Player Daemon... Nov 24 19:43:56 minidsp-shd volumio[790]: info: Adding manifestui REST Endpoint for plugin: miscellanea/manifestui Nov 24 19:43:56 minidsp-shd volumio[790]: info: Adding METAVOLUMIO REST API Endpoints Nov 24 19:43:56 minidsp-shd volumio[790]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Nov 24 19:43:56 minidsp-shd volumio[790]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Nov 24 19:43:56 minidsp-shd volumio[790]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Nov 24 19:43:56 minidsp-shd volumio[790]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 19:43:56 minidsp-shd sudo[1141]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name miniDSP SHD Nov 24 19:43:56 minidsp-shd sudo[1141]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:56 minidsp-shd sudo[1141]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:56 minidsp-shd volumio[790]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:56 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 19:43:57 minidsp-shd volumio[790]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 24 19:43:57 minidsp-shd volumio[790]: info: Preparing CD Folders Nov 24 19:43:57 minidsp-shd volumio[790]: info: Adding CD REST API Endpoints Nov 24 19:43:57 minidsp-shd volumio[790]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Nov 24 19:43:57 minidsp-shd volumio[790]: info: Starting UDEV Watcher for CD Nov 24 19:43:57 minidsp-shd volumio[790]: info: Detecting CD presence with UDEV Nov 24 19:43:57 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Nov 24 19:43:57 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 24 19:43:57 minidsp-shd volumio[790]: info: [1732473837058] CoreMusicLibrary::Adding element Last_100 Nov 24 19:43:57 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 24 19:43:57 minidsp-shd volumio[790]: info: Starting RAAT Plugin Nov 24 19:43:57 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Nov 24 19:43:57 minidsp-shd volumio[790]: info: Additional UI Settings Added for plugin music_service/raat Nov 24 19:43:57 minidsp-shd volumio[790]: info: Streaming services startup Nov 24 19:43:57 minidsp-shd volumio[790]: info: Starting Streaming Daemon Nov 24 19:43:57 minidsp-shd sudo[1153]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 24 19:43:57 minidsp-shd sudo[1153]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:57 minidsp-shd sudo[1153]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:57 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 24 19:43:57 minidsp-shd volumio[790]: info: [1732473837305] CoreMusicLibrary::Adding element Webradio Nov 24 19:43:57 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 24 19:43:57 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 24 19:43:57 minidsp-shd sudo[1160]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Nov 24 19:43:57 minidsp-shd sudo[1160]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:57 minidsp-shd volumio[790]: info: Creating Spotify config file Nov 24 19:43:57 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:57 minidsp-shd sudo[1160]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:57 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Nov 24 19:43:57 minidsp-shd volumio[790]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Nov 24 19:43:57 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:57 minidsp-shd dbus-daemon[475]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.8' (uid=1000 pid=790 comm="/usr/bin/node /volumio/index.js ") Nov 24 19:43:57 minidsp-shd volumio[790]: error: Hi Res Audio Failed Login: Missing Login Data Nov 24 19:43:57 minidsp-shd volumio[790]: info: Adding HIGHRESAUDIO REST API Endpoints Nov 24 19:43:57 minidsp-shd volumio[790]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Nov 24 19:43:57 minidsp-shd systemd[1]: Starting Bluetooth service... Nov 24 19:43:57 minidsp-shd bluetoothd[1166]: Bluetooth daemon 5.23 Nov 24 19:43:57 minidsp-shd dbus-daemon[475]: [system] Successfully activated service 'org.bluez' Nov 24 19:43:57 minidsp-shd systemd[1]: Started Bluetooth service. Nov 24 19:43:57 minidsp-shd bluetoothd[1166]: Starting SDP server Nov 24 19:43:57 minidsp-shd bluetoothd[1166]: kernel lacks bnep-protocol support Nov 24 19:43:57 minidsp-shd bluetoothd[1166]: System does not support network plugin Nov 24 19:43:57 minidsp-shd dbus-daemon[475]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.11' (uid=0 pid=1166 comm="/usr/local/libexec/bluetooth/bluetoothd ") Nov 24 19:43:57 minidsp-shd bluetoothd[1166]: Bluetooth management interface 1.14 initialized Nov 24 19:43:57 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 24 19:43:57 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 19:43:57 minidsp-shd volumio[790]: info: Volumio Calling Home Nov 24 19:43:57 minidsp-shd systemd[1]: Starting Hostname Service... Nov 24 19:43:58 minidsp-shd volumio[790]: info: Stopping AccessToken refresher cron for QOBUZ Nov 24 19:43:58 minidsp-shd dbus-daemon[475]: [system] Successfully activated service 'org.freedesktop.hostname1' Nov 24 19:43:58 minidsp-shd systemd[1]: Started Hostname Service. Nov 24 19:43:58 minidsp-shd volumio[790]: info: AccessToken refresher cron started for QOBUZ Nov 24 19:43:58 minidsp-shd volumio[790]: info: Stopping AccessToken refresher cron Nov 24 19:43:58 minidsp-shd volumio[790]: info: AccessToken refresher cron started Nov 24 19:43:58 minidsp-shd volumio[790]: info: Adding TIDAL REST API Endpoints Nov 24 19:43:58 minidsp-shd volumio[790]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Nov 24 19:43:58 minidsp-shd volumio[790]: info: Adding QOBUZ REST API Endpoints Nov 24 19:43:58 minidsp-shd volumio[790]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Nov 24 19:43:58 minidsp-shd volumio[790]: info: Discovery: adding 7de2fe78-6056-4e2f-9f1b-de3300fc121e Nov 24 19:43:58 minidsp-shd volumio[790]: info: Discovery: Found device miniDSP SHD Nov 24 19:43:58 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioGetState Nov 24 19:43:58 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:43:58 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output for this device Nov 24 19:43:58 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output Nov 24 19:43:58 minidsp-shd volumio[790]: info: Adding audio output: Nov 24 19:43:58 minidsp-shd volumio[790]: info: Adding audio output: Nov 24 19:43:58 minidsp-shd volumio[790]: info: Serial port opened successfully Nov 24 19:43:58 minidsp-shd volumio[790]: error: Cannot start Volumio Streaming Daemon Nov 24 19:43:58 minidsp-shd volumio[790]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 24 19:43:58 minidsp-shd volumio[790]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 24 19:43:58 minidsp-shd volumio[790]: info: RAAT Albumart path created successfully Nov 24 19:43:58 minidsp-shd volumio[790]: error: Cannot set new Bluetooth Name : Error: Command failed: /usr/bin/sudo /bin/hciconfig hci0 name 'miniDSP SHD' Nov 24 19:43:58 minidsp-shd volumio[790]: Can't get device info: No such device Nov 24 19:43:58 minidsp-shd volumio[790]: info: MPD Permissions set Nov 24 19:43:58 minidsp-shd volumio[790]: info: MPD Permissions set Nov 24 19:43:58 minidsp-shd volumio[790]: info: Upmpdcli Daemon Started Nov 24 19:43:58 minidsp-shd volumio[790]: info: msSurfaceDial volumioupdatevolume callback: {"vol":76,"dbVolume":-31,"disableVolumeControl":false} Nov 24 19:43:58 minidsp-shd volumio[790]: info: CoreStateMachine::pushState Nov 24 19:43:58 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:43:58 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 19:43:58 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioPushState Nov 24 19:43:58 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output update for this device Nov 24 19:43:58 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output Nov 24 19:43:58 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Nov 24 19:43:58 minidsp-shd volumio[790]: info: Ignoring ROON Volume update because of undefined data Nov 24 19:43:58 minidsp-shd volumio[790]: info: msSurfaceDial Managed Objs {"/org/bluez":{"org.freedesktop.DBus.Introspectable":{},"org.bluez.AgentManager1":{},"org.bluez.ProfileManager1":{}}} Nov 24 19:43:58 minidsp-shd volumio[790]: info: [msSurfaceDial init()] check /org/bluez Nov 24 19:43:58 minidsp-shd volumio[790]: info: [msSurfaceDial init()] Adapter: null; SurfaceDial: null Nov 24 19:43:58 minidsp-shd volumio[790]: info: msSurfaceDial BluetoothSurfaceDial init() - ready! Nov 24 19:43:58 minidsp-shd volumio[790]: info: CoreCommandRouter::Reload Ui Nov 24 19:43:58 minidsp-shd volumio-remote-updater[458]: [2024-11-24 19:43:58] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1732473836 101 Nov 24 19:43:58 minidsp-shd volumio[790]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 1 Nov 24 19:43:58 minidsp-shd volumio[790]: info: Volumio called home Nov 24 19:43:58 minidsp-shd volumio[790]: info: Spotify config file written Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: raat , updateDSP Nov 24 19:43:59 minidsp-shd volumio[790]: info: updateDSP function in raat called! Nov 24 19:43:59 minidsp-shd volumio[790]: info: Updating RAAT Signal Path Nov 24 19:43:59 minidsp-shd volumio[790]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: raat , reconfigureAndRestartRaat Nov 24 19:43:59 minidsp-shd volumio[790]: info: Reconfiguring and Restarting RAAT Plugin Nov 24 19:43:59 minidsp-shd sudo[1183]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 24 19:43:59 minidsp-shd sudo[1183]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd systemd[1]: Started go-librespot Daemon. Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: Not Reporting Auto name since its the default one Nov 24 19:43:59 minidsp-shd go-librespot[1189]: Librespot-go daemon starting... Nov 24 19:43:59 minidsp-shd volumio[790]: info: RAAT Overriding default device vendor model Nov 24 19:43:59 minidsp-shd volumio[790]: info: Adding MINIDSP Inputs Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 24 19:43:59 minidsp-shd volumio[790]: info: [1732473839145] CoreMusicLibrary::Adding element Inputs Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 24 19:43:59 minidsp-shd sudo[1183]: pam_unix(sudo:session): session closed for user root Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 24 19:43:59 minidsp-shd volumio[790]: info: [1732473839159] CoreMusicLibrary::Adding element Presets Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 24 19:43:59 minidsp-shd volumio[790]: Cannot find translation for source Presets Nov 24 19:43:59 minidsp-shd volumio[790]: (node:790) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Nov 24 19:43:59 minidsp-shd volumio[790]: (Use `node --trace-deprecation ...` to show where the warning was created) Nov 24 19:43:59 minidsp-shd volumio[790]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Nov 24 19:43:59 minidsp-shd go-librespot[1189]: time="2024-11-24T19:43:59+01:00" level=info msg="generated new device id: d0f3784ce1f45d1535f5a3247abe976cd9141393" Nov 24 19:43:59 minidsp-shd go-librespot[1189]: time="2024-11-24T19:43:59+01:00" level=debug msg="stored credentials found for 1164747946" Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Nov 24 19:43:59 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:43:59 minidsp-shd volumio[790]: info: No need to fix Spotify hosts Nov 24 19:43:59 minidsp-shd sudo[1211]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Nov 24 19:43:59 minidsp-shd sudo[1211]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:44:00 minidsp-shd systemd[1]: Started Volumio Bluetooth Module. Nov 24 19:44:00 minidsp-shd volumio[790]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 24 19:44:00 minidsp-shd volumio[790]: SPOTIFY: BQDpvxtayXagj-MW37vi1iAEX4eacY7xYN69-3N00azO2hHinRcjwUROHpLUQYRE9ZxoHrc9HlHMzyY7jg_ZIJxPzZiZd-twkIetA7Zv9yD9eH_90ZoXlmivD_4qjRT3ZoqnKbm4hzoGhNdEZci35pd-Lvb6wbMO5QjQgxj-l3apUpUl4u-O0mLXpF1nvZdiU_szt1FkmeKV7CNKD1BpA-PRkMGoAFUCcrQBaAMVVxSz5Foz29F5GiOqF7w Nov 24 19:44:00 minidsp-shd sudo[1211]: pam_unix(sudo:session): session closed for user root Nov 24 19:44:00 minidsp-shd volumio[790]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 24 19:44:00 minidsp-shd volumio[790]: info: New Spotify access token = BQDpvxtayXagj-MW37vi1iAEX4eacY7xYN69-3N00azO2hHinRcjwUROHpLUQYRE9ZxoHrc9HlHMzyY7jg_ZIJxPzZiZd-twkIetA7Zv9yD9eH_90ZoXlmivD_4qjRT3ZoqnKbm4hzoGhNdEZci35pd-Lvb6wbMO5QjQgxj-l3apUpUl4u-O0mLXpF1nvZdiU_szt1FkmeKV7CNKD1BpA-PRkMGoAFUCcrQBaAMVVxSz5Foz29F5GiOqF7w Nov 24 19:44:00 minidsp-shd volumio[790]: info: Spotify credentials grant success - running version from March 24, 2019 Nov 24 19:44:00 minidsp-shd sudo[1215]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Nov 24 19:44:00 minidsp-shd sudo[1215]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:44:00 minidsp-shd volumio[790]: info: CoreCommandRouter::volumiosetSourceActiveno-source Nov 24 19:44:00 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 24 19:44:00 minidsp-shd volumio[790]: Cannot find translation for source Presets Nov 24 19:44:00 minidsp-shd volumiobt[1214]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Nov 24 19:44:00 minidsp-shd sudo[1215]: pam_unix(sudo:session): session closed for user root Nov 24 19:44:00 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:00+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Nov 24 19:44:00 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:00+01: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]" Nov 24 19:44:00 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:00+01: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]" Nov 24 19:44:00 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:00+01:00" level=debug msg="zeroconf server listening on port 37539" Nov 24 19:44:00 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:00+01:00" level=debug msg="obtained new client token: AAC1FDranSeHjpolR45A5zIPDbR2Q2rCMzu3eRj54Ysg5FsLaYayrwdAtGR3YK9yG5zx6O/TEl8xuSFEpRFGgMUoEeqsKMU5BSARG59uy5O9Hu4B1ng8Mej3H35i6/w15hsS+Cuxw64UU/uRd8Q7WJlljHp7F0vRR1io0+CHdZu9KfnBNLJF8MGAv6+B3wg9q3Nip/SUhBcfCI6+ExARPj7iYMRQ8WQTcodMpnjtsJMroC720z1/iwv5OgdmnBc=" Nov 24 19:44:00 minidsp-shd volumio[790]: info: Starting Shairport Sync Nov 24 19:44:00 minidsp-shd volumio[790]: info: Starting Shairport Sync Nov 24 19:44:00 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:00+01:00" level=info msg="connected to ap-gew4.spotify.com:4070" Nov 24 19:44:00 minidsp-shd volumio[790]: info: Starting Shairport Sync Nov 24 19:44:00 minidsp-shd sudo[1219]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 24 19:44:00 minidsp-shd sudo[1219]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:44:00 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:00+01:00" level=debug msg="completed keyexchange" Nov 24 19:44:00 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Nov 24 19:44:00 minidsp-shd sudo[1221]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 24 19:44:00 minidsp-shd sudo[1221]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:44:00 minidsp-shd systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 24 19:44:00 minidsp-shd systemd[1]: shairport-sync.service: Succeeded. Nov 24 19:44:00 minidsp-shd systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 24 19:44:00 minidsp-shd sudo[1224]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 24 19:44:00 minidsp-shd sudo[1224]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:44:00 minidsp-shd volumio[790]: xcb_connection_has_error() returned true Nov 24 19:44:00 minidsp-shd systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 24 19:44:00 minidsp-shd sudo[1219]: pam_unix(sudo:session): session closed for user root Nov 24 19:44:00 minidsp-shd sudo[1221]: pam_unix(sudo:session): session closed for user root Nov 24 19:44:00 minidsp-shd sudo[1224]: pam_unix(sudo:session): session closed for user root Nov 24 19:44:00 minidsp-shd volumio[790]: info: MRS: Found cast device: Altibox-TV-435455ce13cad7e711055c9a6762ab85 Nov 24 19:44:00 minidsp-shd volumio[790]: info: Adding audio output: Nov 24 19:44:00 minidsp-shd sudo[1231]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Nov 24 19:44:00 minidsp-shd sudo[1231]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:44:00 minidsp-shd volumio[790]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 19:44:00 minidsp-shd volumio[790]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 24 19:44:00 minidsp-shd volumio[790]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 24 19:44:00 minidsp-shd volumio[790]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 24 19:44:00 minidsp-shd systemd[1]: Started RAAT DAEMON. Nov 24 19:44:00 minidsp-shd sudo[1231]: pam_unix(sudo:session): session closed for user root Nov 24 19:44:00 minidsp-shd volumio[790]: info: Volumio BT Module successfully started Nov 24 19:44:00 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Nov 24 19:44:00 minidsp-shd volumio[790]: info: Enabling external Volume Control Nov 24 19:44:00 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:44:00 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:44:00 minidsp-shd volumio[790]: info: MRS: Found cast device: Chromecast-Audio-4cae30823081f8544169b645ef26362c Nov 24 19:44:00 minidsp-shd volumio[790]: info: Adding audio output: Nov 24 19:44:01 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:00+01:00" level=debug msg="completed challenge" Nov 24 19:44:01 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:01+01:00" level=debug msg="authenticated as 1164747946" Nov 24 19:44:01 minidsp-shd volumio[790]: info: Raat Daemon started successfully Nov 24 19:44:01 minidsp-shd volumio[790]: info: Shairport-Sync Started Nov 24 19:44:01 minidsp-shd volumio[790]: Error adding Membership: Error: addMembership EINVAL Nov 24 19:44:01 minidsp-shd volumio[790]: info: Shairport-Sync Started Nov 24 19:44:01 minidsp-shd volumio[790]: info: Shairport-Sync Started Nov 24 19:44:01 minidsp-shd volumio[790]: info: TidalConnect service stoped! Nov 24 19:44:01 minidsp-shd sudo[1246]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Nov 24 19:44:01 minidsp-shd sudo[1246]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:44:01 minidsp-shd volumiobt[1214]: pulseaudio: no process found Nov 24 19:44:01 minidsp-shd sudo[1246]: pam_unix(sudo:session): session closed for user root Nov 24 19:44:01 minidsp-shd volumio[790]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Nov 24 19:44:01 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:01+01:00" level=debug msg="authenticated as 1164747946" Nov 24 19:44:01 minidsp-shd dbus-daemon[475]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.18' (uid=1000 pid=1253 comm="/usr/bin/pulseaudio --high-priority=true ") Nov 24 19:44:01 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:01+01:00" level=debug msg="dealer connection opened" Nov 24 19:44:01 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:01+01:00" level=debug msg="initializing zeroconf session, username: 1164747946" Nov 24 19:44:01 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:01+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Nov 24 19:44:01 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:01+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Nov 24 19:44:01 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:01+01:00" level=debug msg="received connection id: YjA0YjRhNDAtYWQyYy00ZjY4LWIwYzItMTJjMWQ5MzUxMjZkK2RlYWxlcit0Y3A6Ly8wYWNhNTg0OC5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNjU4REVCNjdGQkU1MTI2RjU3RTY1MDgwNzdDN0ZFNUI5Qzg2NzkxN0RCQzJFQzMyQzBCMUM3RUMxOTcyNjVFRg==" Nov 24 19:44:01 minidsp-shd systemd[1]: Starting RealtimeKit Scheduling Policy Service... Nov 24 19:44:01 minidsp-shd volumio[790]: info: Executing endpoint restartRAATSocket Nov 24 19:44:01 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Nov 24 19:44:01 minidsp-shd dbus-daemon[475]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Nov 24 19:44:01 minidsp-shd systemd[1]: Started RealtimeKit Scheduling Policy Service. Nov 24 19:44:01 minidsp-shd rtkit-daemon[1254]: Successfully called chroot. Nov 24 19:44:01 minidsp-shd rtkit-daemon[1254]: Successfully dropped privileges. Nov 24 19:44:01 minidsp-shd rtkit-daemon[1254]: Successfully limited resources. Nov 24 19:44:01 minidsp-shd rtkit-daemon[1254]: Running. Nov 24 19:44:01 minidsp-shd rtkit-daemon[1254]: Watchdog thread running. Nov 24 19:44:01 minidsp-shd rtkit-daemon[1254]: Canary thread running. Nov 24 19:44:01 minidsp-shd dbus-daemon[475]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.19' (uid=0 pid=1254 comm="/usr/lib/rtkit/rtkit-daemon ") Nov 24 19:44:01 minidsp-shd systemd[1]: Starting Authorization Manager... Nov 24 19:44:01 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:01+01:00" level=debug msg="put connect state because NEW_DEVICE" Nov 24 19:44:01 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:01+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Nov 24 19:44:01 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:01+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Nov 24 19:44:01 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:01+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Nov 24 19:44:01 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:01+01:00" level=debug msg="autoplay enabled: false" Nov 24 19:44:01 minidsp-shd polkitd[1258]: started daemon version 0.105 using authority implementation `local' version `0.105' Nov 24 19:44:01 minidsp-shd dbus-daemon[475]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Nov 24 19:44:01 minidsp-shd systemd[1]: Started Authorization Manager. Nov 24 19:44:01 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioGetState Nov 24 19:44:01 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:44:01 minidsp-shd volumio[790]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 19:44:01 minidsp-shd volumio[790]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 19:44:02 minidsp-shd volumio[790]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Nov 24 19:44:02 minidsp-shd volumio[790]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Nov 24 19:44:02 minidsp-shd sudo[1267]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Nov 24 19:44:02 minidsp-shd sudo[1267]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:44:02 minidsp-shd volumio[790]: info: msSurfaceDial volumioupdatevolume callback: {"vol":76,"dbVolume":-31,"mute":false,"disableVolumeControl":false} Nov 24 19:44:02 minidsp-shd volumio[790]: info: CoreStateMachine::pushState Nov 24 19:44:02 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:44:02 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 19:44:02 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioPushState Nov 24 19:44:02 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output update for this device Nov 24 19:44:02 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output Nov 24 19:44:02 minidsp-shd volumio[790]: error: Help! Some callbacks for volumioPushState are crashing! Nov 24 19:44:02 minidsp-shd volumio[790]: error: Cannot read property 'sendVolumeMute' of undefined Nov 24 19:44:02 minidsp-shd systemd[1]: Started Volumio Tidal Connect Service. Nov 24 19:44:02 minidsp-shd sudo[1267]: pam_unix(sudo:session): session closed for user root Nov 24 19:44:02 minidsp-shd volumio[790]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 4 Nov 24 19:44:02 minidsp-shd volumio[790]: info: MRS: Getting audio outputs on start Nov 24 19:44:02 minidsp-shd volumio[790]: info: MRS: Requesting all other devices output Nov 24 19:44:02 minidsp-shd pulseaudio[1253]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Nov 24 19:44:02 minidsp-shd pulseaudio[1253]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Nov 24 19:44:02 minidsp-shd volumiobt[1214]: Applying permissions Nov 24 19:44:02 minidsp-shd volumiobt[1214]: Setting BT discoverable and pairable Nov 24 19:44:02 minidsp-shd volumio[790]: info: go-librespot daemon successfully initialized Nov 24 19:44:02 minidsp-shd pulseaudio[1253]: 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 Nov 24 19:44:03 minidsp-shd volumiobt[1214]: [38B blob data] Nov 24 19:44:03 minidsp-shd volumiobt[1214]: Invalid command Nov 24 19:44:03 minidsp-shd volumiobt[1214]: [bluetooth]# agent on Nov 24 19:44:03 minidsp-shd volumiobt[1214]: [bluetooth]# discoverable on Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioGetState Nov 24 19:44:03 minidsp-shd volumiobt[1214]: No default controller available Nov 24 19:44:03 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:44:03 minidsp-shd volumiobt[1214]: [bluetooth]# pairable on Nov 24 19:44:03 minidsp-shd volumiobt[1214]: No default controller available Nov 24 19:44:03 minidsp-shd volumiobt[1214]: [bluetooth]# agent NoInputNoOutput Nov 24 19:44:03 minidsp-shd volumiobt[1214]: Failed to register agent object Nov 24 19:44:03 minidsp-shd volumiobt[1214]: [bluetooth]# default-agent Nov 24 19:44:03 minidsp-shd volumiobt[1214]: No agent is registered Nov 24 19:44:03 minidsp-shd volumiobt[1214]: [bluetooth]# quit Nov 24 19:44:03 minidsp-shd volumiobt[1214]: [61B blob data] Nov 24 19:44:03 minidsp-shd volumio[790]: info: msSurfaceDial volumioupdatevolume callback: {"vol":76,"dbVolume":-31,"mute":false,"disableVolumeControl":false} Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreStateMachine::pushState Nov 24 19:44:03 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioPushState Nov 24 19:44:03 minidsp-shd volumiobt[1214]: [62B blob data] Nov 24 19:44:03 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output update for this device Nov 24 19:44:03 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output Nov 24 19:44:03 minidsp-shd volumio[790]: error: Help! Some callbacks for volumioPushState are crashing! Nov 24 19:44:03 minidsp-shd volumio[790]: error: Cannot read property 'sendVolumeMute' of undefined Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Nov 24 19:44:03 minidsp-shd volumio[790]: SPOTIFY: User informations: {"country":"NO","display_name":"Bartek Gołędowski","email":"baltona84@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/1164747946"},"followers":{"href":null,"total":16},"href":"https://api.spotify.com/v1/users/1164747946","id":"1164747946","images":[{"height":300,"url":"https://scontent-ams2-1.xx.fbcdn.net/v/t31.18172-1/27797538_10156432867544369_5035997697550006766_o.jpg?stp=dst-jpg_s320x320&_nc_cat=111&ccb=1-7&_nc_sid=05c18e&_nc_ohc=8o3q3y_Iwo0Q7kNvgFMhiY9&_nc_zt=24&_nc_ht=scontent-ams2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=ACAYtaJ1hwfXgNxDPMEgvPL&oh=00_AYDXKds8aeToMC4k6nr5DnBYGNGyRVzrw7mvwMpxvyxvOg&oe=676ACBE3","width":300},{"height":64,"url":"https://scontent-ams2-1.xx.fbcdn.net/v/t31.18172-1/27797538_10156432867544369_5035997697550006766_o.jpg?stp=cp0_dst-jpg_s50x50&_nc_cat=111&ccb=1-7&_nc_sid=312bcd&_nc_ohc=8o3q3y_Iwo0Q7kNvgFMhiY9&_nc_zt=24&_nc_ht=scontent-ams2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=ACAYtaJ1hwfXgNxDPMEgvPL&oh=00_AYANYTcUMN4hWH1U2uLSlloMasGv8eiztSXQXXinPOmkJg&oe=676ACBE3","width":64}],"product":"premium","type":"user","uri":"spotify:user:1164747946"} Nov 24 19:44:03 minidsp-shd volumio[790]: info: Spotify Successfully logged in Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 24 19:44:03 minidsp-shd volumio[790]: info: [1732473843259] CoreMusicLibrary::Adding element Spotify Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 24 19:44:03 minidsp-shd volumio[790]: Cannot find translation for source Presets Nov 24 19:44:03 minidsp-shd volumio[790]: Cannot find translation for source Spotify Nov 24 19:44:03 minidsp-shd volumio[790]: info: Executing endpoint tc_getconfig Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Nov 24 19:44:03 minidsp-shd vtcs[1269]: STARTING TidalConnect services, version: 1.3.0.19 Nov 24 19:44:03 minidsp-shd vtcs[1269]: STARTED TidalConnect services. Nov 24 19:44:03 minidsp-shd volumio[790]: info: Executing endpoint tc_connect Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Nov 24 19:44:03 minidsp-shd volumio[790]: info: Connecting to TidalConnect Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreCommandRouter::servicePushState Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreStateMachine::pushState Nov 24 19:44:03 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioPushState Nov 24 19:44:03 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output update for this device Nov 24 19:44:03 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output Nov 24 19:44:03 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:44:03 minidsp-shd volumio[790]: 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} Nov 24 19:44:03 minidsp-shd volumio[790]: verbose: CURRENT POSITION 0 Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreStateMachine::syncState stateService stop Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreStateMachine::syncState currentStatus stop Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreStateMachine::pushState Nov 24 19:44:03 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioPushState Nov 24 19:44:03 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output update for this device Nov 24 19:44:03 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output Nov 24 19:44:03 minidsp-shd volumio[790]: info: No code Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreStateMachine::pushState Nov 24 19:44:03 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioPushState Nov 24 19:44:03 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output update for this device Nov 24 19:44:03 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreCommandRouter::servicePushState Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreStateMachine::pushState Nov 24 19:44:03 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioPushState Nov 24 19:44:03 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output update for this device Nov 24 19:44:03 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output Nov 24 19:44:03 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:44:03 minidsp-shd volumio[790]: 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} Nov 24 19:44:03 minidsp-shd volumio[790]: verbose: CURRENT POSITION 0 Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreStateMachine::syncState stateService stop Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreStateMachine::syncState currentStatus stop Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreStateMachine::pushState Nov 24 19:44:03 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioPushState Nov 24 19:44:03 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output update for this device Nov 24 19:44:03 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output Nov 24 19:44:03 minidsp-shd volumio[790]: info: No code Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreStateMachine::pushState Nov 24 19:44:03 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:44:03 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioPushState Nov 24 19:44:03 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output update for this device Nov 24 19:44:03 minidsp-shd volumio[790]: info: MRS: Pushing multiroomSync output Nov 24 19:44:05 minidsp-shd mpd[1142]: Nov 24 19:44 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 24 19:44:05 minidsp-shd systemd[1]: Started Music Player Daemon. Nov 24 19:44:05 minidsp-shd volumio[790]: Upnp client error: Error: This socket has been ended by the other party Nov 24 19:44:05 minidsp-shd volumio[790]: Upnp client error: Error: This socket has been ended by the other party Nov 24 19:44:05 minidsp-shd sudo[1126]: pam_unix(sudo:session): session closed for user root Nov 24 19:44:05 minidsp-shd sudo[1137]: pam_unix(sudo:session): session closed for user root Nov 24 19:44:05 minidsp-shd volumio[790]: error: MPD error: The expression evaluated to a falsy value: Nov 24 19:44:05 minidsp-shd volumio[790]: assert.ok(self.idling) Nov 24 19:44:05 minidsp-shd volumio[790]: error: The expression evaluated to a falsy value: Nov 24 19:44:05 minidsp-shd volumio[790]: assert.ok(self.idling) Nov 24 19:44:05 minidsp-shd volumio[790]: error: updateQueue error: null Nov 24 19:44:05 minidsp-shd volumio[790]: info: TidalConnect service started! Nov 24 19:44:05 minidsp-shd volumio[790]: info: Completed starting Core Plugins Nov 24 19:44:05 minidsp-shd volumio[790]: info: ------------------------------------------- Nov 24 19:44:05 minidsp-shd volumio[790]: info: ----- MyVolumio plugins startup ---- Nov 24 19:44:05 minidsp-shd volumio[790]: info: ------------------------------------------- Nov 24 19:44:05 minidsp-shd volumio[790]: info: [MyVolumio PluginManager] Fetching plans data.... Nov 24 19:44:05 minidsp-shd volumio[790]: info: MPD running with PID1142 Nov 24 19:44:05 minidsp-shd volumio[790]: ,establishing connection Nov 24 19:44:05 minidsp-shd volumio[790]: error: updateQueue error: null Nov 24 19:44:05 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:05+01:00" level=debug msg="handling transfer player command from 1c3f961463532dd05c7fdd38b2200608ba8c3c1e" Nov 24 19:44:05 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:05+01:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZF1DWWwzidNQX6jx" Nov 24 19:44:05 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:05+01:00" level=trace msg="fetched new page 0 with 100 items (list: 100)" uri="spotify:playlist:37i9dQZF1DWWwzidNQX6jx" Nov 24 19:44:05 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:05+01:00" level=debug msg="loading track (paused: true, position: 0ms)" uri="spotify:track:3mCeeoBvTTpg8Xy2Wuvirw" Nov 24 19:44:05 minidsp-shd volumio[790]: info: Initializing connection to go-librespot Websocket Nov 24 19:44:05 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:05+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 24 19:44:05 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:05+01:00" level=trace msg="emitting websocket event: will_play" Nov 24 19:44:05 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:05+01:00" level=debug msg="new websocket client" Nov 24 19:44:05 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:05+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Nov 24 19:44:05 minidsp-shd volumio[790]: info: Connection to go-librespot Websocket established Nov 24 19:44:06 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:06+01:00" level=debug msg="selected format OGG_VORBIS_320 (89230d19396fbd607a212029a60e6f7678d49459)" uri="spotify:track:3mCeeoBvTTpg8Xy2Wuvirw" Nov 24 19:44:06 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:06+01:00" level=debug msg="requested aes key for file 89230d19396fbd607a212029a60e6f7678d49459, gid: 3mCeeoBvTTpg8Xy2Wuvirw" Nov 24 19:44:06 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:06+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2802" Nov 24 19:44:06 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:06+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1847" Nov 24 19:44:06 minidsp-shd volumio[1124]: Generating RSA private key, 4096 bit long modulus (2 primes) Nov 24 19:44:06 minidsp-shd volumio[1124]: .++++ Nov 24 19:44:07 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:44:07 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:44:07 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 19:44:07 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 19:44:07 minidsp-shd volumio[790]: info: Not Reporting Auto name since its the default one Nov 24 19:44:07 minidsp-shd volumio[790]: info: RAAT Overriding default device vendor model Nov 24 19:44:07 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Nov 24 19:44:07 minidsp-shd volumio[790]: xcb_connection_has_error() returned true Nov 24 19:44:07 minidsp-shd sudo[1318]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Nov 24 19:44:07 minidsp-shd sudo[1318]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 19:44:07 minidsp-shd systemd[1]: Stopping RAAT DAEMON... Nov 24 19:44:07 minidsp-shd systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Nov 24 19:44:07 minidsp-shd systemd[1]: raat-daemon.service: Succeeded. Nov 24 19:44:07 minidsp-shd systemd[1]: Stopped RAAT DAEMON. Nov 24 19:44:07 minidsp-shd systemd[1]: Started RAAT DAEMON. Nov 24 19:44:07 minidsp-shd sudo[1318]: pam_unix(sudo:session): session closed for user root Nov 24 19:44:07 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:07+01:00" level=debug msg="fetched first chunk of 45, total size is 23406736 bytes" uri="spotify:track:3mCeeoBvTTpg8Xy2Wuvirw" Nov 24 19:44:07 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:07+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:3mCeeoBvTTpg8Xy2Wuvirw" Nov 24 19:44:07 minidsp-shd volumio[790]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 19:44:07 minidsp-shd volumio[790]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 24 19:44:07 minidsp-shd go-librespot[1189]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:257:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 22050, but target_pcm volumioOutput has buffer size 4096 Nov 24 19:44:07 minidsp-shd go-librespot[1189]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:268:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 22050, but target_pcm volumioOutput has buffer size 4096 Nov 24 19:44:07 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:07+01:00" level=debug msg="created new output device" Nov 24 19:44:07 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:07+01:00" level=info msg="loaded track \"Bat Out of Hell\" (paused: true, position: 0ms, duration: 590000ms, prefetched: false)" uri="spotify:track:3mCeeoBvTTpg8Xy2Wuvirw" Nov 24 19:44:07 minidsp-shd volumio[790]: info: Raat Daemon started successfully Nov 24 19:44:07 minidsp-shd volumio[790]: info: Executing endpoint restartRAATSocket Nov 24 19:44:07 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Nov 24 19:44:07 minidsp-shd volumio[790]: info: CoreCommandRouter::executeOnPlugin: raat , updateDSP Nov 24 19:44:07 minidsp-shd volumio[790]: info: updateDSP function in raat called! Nov 24 19:44:07 minidsp-shd volumio[790]: info: Updating RAAT Signal Path Nov 24 19:44:07 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:07+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 24 19:44:07 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:07+01:00" level=trace msg="emitting websocket event: metadata" Nov 24 19:44:07 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:07+01:00" level=trace msg="emitting websocket event: active" Nov 24 19:44:07 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:07+01:00" level=debug msg="sending successful reply for dealer request" Nov 24 19:44:07 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:07+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Nov 24 19:44:07 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:07+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Nov 24 19:44:07 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:07+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Nov 24 19:44:07 minidsp-shd volumio[790]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3mCeeoBvTTpg8Xy2Wuvirw","name":"Bat Out of Hell","artist_names":["Meat Loaf"],"album_name":"Bat Out Of Hell","album_cover_url":"https://i.scdn.co/image/ab67616d00001e024111af27787499f6d8752e9f","position":0,"duration":590000,"release_date":"year:1977 month:10 day:21","track_number":1,"disc_number":1}} Nov 24 19:44:07 minidsp-shd volumio[790]: SPOTIFY: received: {"type":"active","data":null} Nov 24 19:44:07 minidsp-shd volumio[790]: info: Aligning Spotify Volume to Volumio Volume Nov 24 19:44:07 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioGetState Nov 24 19:44:07 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:44:07 minidsp-shd volumio[790]: info: Setting Spotify Volume from Volumio: 76 Nov 24 19:44:07 minidsp-shd volumio[790]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5 Nov 24 19:44:07 minidsp-shd volumio[790]: info: CoreCommandRouter::volumioGetState Nov 24 19:44:07 minidsp-shd volumio[790]: info: CorePlayQueue::getTrack 0 Nov 24 19:44:08 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:08+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 24 19:44:08 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:08+01:00" level=trace msg="emitting websocket event: paused" Nov 24 19:44:08 minidsp-shd volumio[790]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:3mCeeoBvTTpg8Xy2Wuvirw","play_origin":"cloud-playback"}} Nov 24 19:44:08 minidsp-shd volumio[790]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 24 19:44:08 minidsp-shd volumio[790]: TypeError: Cannot read property 'service' of undefined Nov 24 19:44:08 minidsp-shd volumio[790]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) Nov 24 19:44:08 minidsp-shd volumio[790]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:271:18) Nov 24 19:44:08 minidsp-shd volumio[790]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Nov 24 19:44:08 minidsp-shd volumio[790]: at WebSocket.emit (events.js:400:28) Nov 24 19:44:08 minidsp-shd volumio[790]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Nov 24 19:44:08 minidsp-shd volumio[790]: at Receiver.emit (events.js:400:28) Nov 24 19:44:08 minidsp-shd volumio[790]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Nov 24 19:44:08 minidsp-shd volumio[790]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Nov 24 19:44:08 minidsp-shd volumio[790]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Nov 24 19:44:08 minidsp-shd volumio[790]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Nov 24 19:44:08 minidsp-shd volumio[790]: at writeOrBuffer (internal/streams/writable.js:358:12) Nov 24 19:44:08 minidsp-shd volumio[790]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Nov 24 19:44:08 minidsp-shd volumio[790]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Nov 24 19:44:08 minidsp-shd volumio[790]: at Socket.emit (events.js:400:28) Nov 24 19:44:08 minidsp-shd volumio[790]: at addChunk (internal/streams/readable.js:293:12) Nov 24 19:44:08 minidsp-shd volumio[790]: at readableAddChunk (internal/streams/readable.js:267:9) Nov 24 19:44:08 minidsp-shd volumio[790]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 24 19:44:09 minidsp-shd go-librespot[1189]: time="2024-11-24T19:44:09+01:00" level=debug msg="fetched chunk 2/44, size: 524288" uri="spotify:track:3mCeeoBvTTpg8Xy2Wuvirw" Nov 24 19:44:09 minidsp-shd sudo[1341]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-24 19:43 Nov 24 19:44:09 minidsp-shd sudo[1341]: 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:13:25 PM CET" VOLUMIO_VERSION="3.608" VOLUMIO_HARDWARE="nanopineo3" VOLUMIO_DEVICENAME="Nanopi Neo3" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="18533ba33f8f92d7e7e459bb30f70beb"