-- Logs begin at Fri 2024-03-22 15:13:25 CET, end at Sun 2024-10-20 10:08:16 CEST. -- Oct 20 10:07:32 minidsp-shd systemd[1]: Starting Daily apt download activities... Oct 20 10:07:32 minidsp-shd systemd[1]: systemd-fsckd.service: Succeeded. Oct 20 10:07:32 minidsp-shd sh[389]: timed out Oct 20 10:07:32 minidsp-shd sh[389]: dhcpcd exited Oct 20 10:07:32 minidsp-shd dhcpcd[434]: timed out Oct 20 10:07:32 minidsp-shd sh[389]: ifup: failed to bring up eth0 Oct 20 10:07:32 minidsp-shd systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Oct 20 10:07:32 minidsp-shd dhcpcd[434]: dhcpcd exited Oct 20 10:07:32 minidsp-shd systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Oct 20 10:07:33 minidsp-shd volumio[789]: info: Loading plugin "network"... Oct 20 10:07:33 minidsp-shd volumio[789]: info: Refreshing Cached IP Addresses Oct 20 10:07:33 minidsp-shd sudo[861]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 20 10:07:33 minidsp-shd sudo[861]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:07:33 minidsp-shd sudo[861]: pam_unix(sudo:session): session closed for user root Oct 20 10:07:33 minidsp-shd volumio[789]: info: Loading plugin "services"... Oct 20 10:07:33 minidsp-shd sudo[864]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 20 10:07:33 minidsp-shd sudo[864]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:07:33 minidsp-shd volumio[789]: info: Loading plugin "alsa_controller"... Oct 20 10:07:33 minidsp-shd sudo[864]: pam_unix(sudo:session): session closed for user root Oct 20 10:07:33 minidsp-shd sudo[868]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 20 10:07:33 minidsp-shd sudo[868]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:07:33 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 20 10:07:33 minidsp-shd volumio[789]: info: Loading plugin "wizard"... Oct 20 10:07:33 minidsp-shd volumio[789]: info: Loading plugin "networkfs"... Oct 20 10:07:33 minidsp-shd volumio[789]: info: Starting Udev Watcher for removable devices Oct 20 10:07:33 minidsp-shd sudo[886]: 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 Oct 20 10:07:33 minidsp-shd sudo[886]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:07:33 minidsp-shd kernel: FS-Cache: Loaded Oct 20 10:07:33 minidsp-shd volumio[789]: info: Ignoring mount for partition: BOOT Oct 20 10:07:33 minidsp-shd volumio[789]: info: Ignoring mount for partition: volumio Oct 20 10:07:33 minidsp-shd volumio[789]: info: Ignoring mount for partition: volumio_data Oct 20 10:07:33 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 20 10:07:33 minidsp-shd volumio[789]: info: Loading plugin "volumio_command_line_client"... Oct 20 10:07:33 minidsp-shd volumio[789]: info: Loading plugin "upnp"... Oct 20 10:07:33 minidsp-shd volumio[789]: info: [1729411653639] Starting Upmpd Daemon Oct 20 10:07:33 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 20 10:07:33 minidsp-shd volumio[789]: info: Loading plugin "my_music"... Oct 20 10:07:33 minidsp-shd volumio[789]: info: Loading plugin "mpd"... Oct 20 10:07:33 minidsp-shd kernel: FS-Cache: Netfs 'cifs' registered for caching Oct 20 10:07:33 minidsp-shd kernel: Key type cifs.spnego registered Oct 20 10:07:33 minidsp-shd kernel: Key type cifs.idmap registered Oct 20 10:07:33 minidsp-shd kernel: CIFS: Attempting to mount //192.168.10.197/USB Oct 20 10:07:33 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. Oct 20 10:07:33 minidsp-shd systemd[1]: apt-daily.service: Succeeded. Oct 20 10:07:33 minidsp-shd systemd[1]: Started Daily apt download activities. Oct 20 10:07:33 minidsp-shd systemd[1]: Starting Daily apt upgrade and clean activities... Oct 20 10:07:33 minidsp-shd sudo[886]: pam_unix(sudo:session): session closed for user root Oct 20 10:07:34 minidsp-shd volumio[789]: info: Loading plugin "upnp_browser"... Oct 20 10:07:35 minidsp-shd systemd[1]: apt-daily-upgrade.service: Succeeded. Oct 20 10:07:35 minidsp-shd systemd[1]: Started Daily apt upgrade and clean activities. Oct 20 10:07:35 minidsp-shd volumio[789]: info: Loading plugin "bluetooth"... Oct 20 10:07:35 minidsp-shd volumio[789]: info: [1729411655853] Starting BluetoothController Oct 20 10:07:36 minidsp-shd volumio[789]: info: Loading plugin "alarm-clock"... Oct 20 10:07:36 minidsp-shd volumio[789]: info: Loading plugin "manifestui"... Oct 20 10:07:36 minidsp-shd volumio[789]: info: Loading plugin "metavolumio"... Oct 20 10:07:37 minidsp-shd sudo[868]: pam_unix(sudo:session): session closed for user root Oct 20 10:07:39 minidsp-shd volumio[789]: info: Loading plugin "airplay_emulation"... Oct 20 10:07:39 minidsp-shd volumio[789]: info: Starting Shairport Sync Oct 20 10:07:39 minidsp-shd volumio[789]: info: Loading plugin "cd_controller"... Oct 20 10:07:39 minidsp-shd volumio[789]: info: Loading plugin "last_100"... Oct 20 10:07:39 minidsp-shd volumio[789]: info: Loading plugin "raat"... Oct 20 10:07:40 minidsp-shd volumio[789]: info: RAAT Plugin loaded Oct 20 10:07:40 minidsp-shd volumio[789]: info: Adding restartRAATSocket REST API Endpoint Oct 20 10:07:40 minidsp-shd volumio[789]: info: Adding restartRAATSocket REST Endpoint for plugin: music_service/raat Oct 20 10:07:40 minidsp-shd volumio[789]: info: Loading plugin "streaming_services"... Oct 20 10:07:41 minidsp-shd volumio-remote-updater[472]: [2024-10-20 10:07:41] [connect] Successful connection Oct 20 10:07:42 minidsp-shd volumio[789]: info: Starting Streaming Service Transparent Proxy Oct 20 10:07:42 minidsp-shd volumio[789]: info: Loading plugin "tidalconnect"... Oct 20 10:07:43 minidsp-shd volumio[789]: info: Loading plugin "webradio"... Oct 20 10:07:43 minidsp-shd volumio[789]: info: Loading plugin "i2s_dacs"... Oct 20 10:07:43 minidsp-shd volumio[789]: info: I2S DAC not set, start Auto-detection Oct 20 10:07:43 minidsp-shd volumio[789]: info: Loading plugin "volumiodiscovery"... Oct 20 10:07:43 minidsp-shd volumio[789]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 20 10:07:43 minidsp-shd volumio[789]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 20 10:07:43 minidsp-shd node[789]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 20 10:07:43 minidsp-shd volumio[789]: *** WARNING *** For more information see Oct 20 10:07:43 minidsp-shd volumio[789]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 20 10:07:43 minidsp-shd volumio[789]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 20 10:07:43 minidsp-shd volumio[789]: *** WARNING *** For more information see Oct 20 10:07:43 minidsp-shd node[789]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 20 10:07:43 minidsp-shd node[789]: *** WARNING *** For more information see Oct 20 10:07:43 minidsp-shd node[789]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 20 10:07:43 minidsp-shd node[789]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 20 10:07:43 minidsp-shd node[789]: *** WARNING *** For more information see Oct 20 10:07:43 minidsp-shd volumio[789]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 20 10:07:43 minidsp-shd volumio[789]: info: Discovery: Started advertising with name: miniDSP SHD Oct 20 10:07:43 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 20 10:07:43 minidsp-shd volumio[789]: info: Loading plugin "spop"... Oct 20 10:07:44 minidsp-shd volumio[789]: STREAMING PROXY: Starting server on port 3245 Oct 20 10:07:44 minidsp-shd volumio[789]: Node JS runtime: 14 Oct 20 10:07:46 minidsp-shd volumio[789]: info: Loading plugin "multiroom"... Oct 20 10:07:49 minidsp-shd volumio[789]: info: Applying required configuration parameters for plugin multiroom Oct 20 10:07:49 minidsp-shd sudo[984]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Oct 20 10:07:49 minidsp-shd sudo[984]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:07:49 minidsp-shd sudo[984]: pam_unix(sudo:session): session closed for user root Oct 20 10:07:49 minidsp-shd volumio[789]: info: MRS: MultiRoom plugin initialized Oct 20 10:07:49 minidsp-shd volumio[789]: info: MRS: STOPPING SNAPCLIENT Oct 20 10:07:49 minidsp-shd volumio[789]: info: MRS: Snap server stop Oct 20 10:07:49 minidsp-shd sudo[1000]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Oct 20 10:07:49 minidsp-shd volumio[789]: info: MRS: STOPPING volumioStreaming Oct 20 10:07:49 minidsp-shd sudo[1000]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:07:49 minidsp-shd sudo[1002]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Oct 20 10:07:49 minidsp-shd sudo[1002]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:07:49 minidsp-shd sudo[1000]: pam_unix(sudo:session): session closed for user root Oct 20 10:07:49 minidsp-shd volumio[789]: info: Loading plugin "outputs"... Oct 20 10:07:49 minidsp-shd sudo[1005]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Oct 20 10:07:49 minidsp-shd sudo[1005]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:07:49 minidsp-shd sudo[1008]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Oct 20 10:07:49 minidsp-shd sudo[1008]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:07:49 minidsp-shd volumio[789]: info: Loading plugin "albumart"... Oct 20 10:07:49 minidsp-shd sudo[1008]: pam_unix(sudo:session): session closed for user root Oct 20 10:07:49 minidsp-shd sudo[1002]: pam_unix(sudo:session): session closed for user root Oct 20 10:07:49 minidsp-shd volumio[789]: info: Loading plugin "ms_surface_dial"... Oct 20 10:07:49 minidsp-shd sudo[1005]: pam_unix(sudo:session): session closed for user root Oct 20 10:07:50 minidsp-shd volumio[789]: Forking 3 albumart workers Oct 20 10:07:51 minidsp-shd volumio[789]: info: Applying required configuration parameters for plugin ms_surface_dial Oct 20 10:07:51 minidsp-shd volumio[789]: info: Plugin example_plugin is not enabled Oct 20 10:07:51 minidsp-shd volumio[789]: info: Loading plugin "hi_res_audio"... Oct 20 10:07:52 minidsp-shd volumio[789]: Starting albumart workers Oct 20 10:07:52 minidsp-shd volumio[789]: Starting albumart workers Oct 20 10:07:52 minidsp-shd volumio[789]: Starting albumart workers Oct 20 10:07:54 minidsp-shd volumio[789]: info: Applying required configuration parameters for plugin hi_res_audio Oct 20 10:07:54 minidsp-shd volumio[789]: info: Loading plugin "inputs"... Oct 20 10:07:55 minidsp-shd volumio[789]: info: Loading plugin "qobuz"... Oct 20 10:07:56 minidsp-shd volumio-remote-updater[472]: [2024-10-20 10:07:56] [connect] Successful connection Oct 20 10:07:58 minidsp-shd volumio[789]: info: Loading plugin "tidal"... Oct 20 10:08:00 minidsp-shd volumio[789]: info: Loading plugin "oem_helper"... Oct 20 10:08:02 minidsp-shd volumio[789]: info: Applying required configuration parameters for plugin oem_helper Oct 20 10:08:02 minidsp-shd volumio[789]: info: Loading plugin "updater_comm"... Oct 20 10:08:03 minidsp-shd volumio[789]: info: Plugin mpdemulation is not enabled Oct 20 10:08:03 minidsp-shd volumio[789]: info: Loading plugin "rest_api"... Oct 20 10:08:03 minidsp-shd volumio[789]: info: Loading plugin "websocket"... Oct 20 10:08:03 minidsp-shd volumio[789]: info: Loading i18n strings for locale en Oct 20 10:08:03 minidsp-shd volumio[789]: Updating browse sources language Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::initPlayerControls Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 20 10:08:03 minidsp-shd volumio[789]: Express server listening on port 3000 Oct 20 10:08:03 minidsp-shd volumio[789]: [Metrics] WebUI: 37s 198.38ms Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreStateMachine::resetVolumioState Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreStateMachine::getcurrentVolume Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioRetrievevolume Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Oct 20 10:08:03 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 10:08:03 minidsp-shd sudo[1103]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 20 10:08:03 minidsp-shd sudo[1103]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: inputs , getVolume Oct 20 10:08:03 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: inputs , getDSP Oct 20 10:08:03 minidsp-shd sudo[1103]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:03 minidsp-shd sudo[1110]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 20 10:08:03 minidsp-shd sudo[1110]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:03 minidsp-shd sudo[1110]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:03 minidsp-shd volumio[789]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Oct 20 10:08:03 minidsp-shd volumio[789]: info: Completed loading Core Plugins Oct 20 10:08:03 minidsp-shd volumio[789]: info: Preparing to generate the ALSA configuration file Oct 20 10:08:04 minidsp-shd volumio[789]: info: Cannot read play queue from file Oct 20 10:08:04 minidsp-shd volumio[789]: info: MRS: Removed streaming files Oct 20 10:08:04 minidsp-shd volumio[789]: info: MRS: volumioStreaming STOPPED Oct 20 10:08:04 minidsp-shd volumio[789]: info: MRS: SNAPSERVER STOPPED Oct 20 10:08:04 minidsp-shd volumio[789]: info: MRS: SNAPCLIENT STOPPED Oct 20 10:08:04 minidsp-shd volumio[789]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Oct 20 10:08:04 minidsp-shd volumio[789]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 20 10:08:04 minidsp-shd volumio[789]: info: Reading ALSA contributions from plugins. Oct 20 10:08:04 minidsp-shd volumio[789]: info: CoreStateMachine::setRepeat null single undefined Oct 20 10:08:04 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Oct 20 10:08:04 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Oct 20 10:08:04 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Oct 20 10:08:04 minidsp-shd volumio[789]: info: CoreStateMachine::setRandom null Oct 20 10:08:04 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Oct 20 10:08:04 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Oct 20 10:08:04 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Oct 20 10:08:04 minidsp-shd volumio[789]: info: Setting Device type: NanoPi NEO 3 Oct 20 10:08:04 minidsp-shd volumio[789]: info: Asound.conf file unchanged, so no further update is needed Oct 20 10:08:04 minidsp-shd volumio[789]: info: Output device has changed, restarting MPD Oct 20 10:08:04 minidsp-shd sudo[1119]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 20 10:08:04 minidsp-shd sudo[1119]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:04 minidsp-shd systemd[1]: Started UPnP Renderer front-end to MPD. Oct 20 10:08:04 minidsp-shd sudo[1122]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 20 10:08:04 minidsp-shd sudo[1122]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:04 minidsp-shd volumio[789]: info: Output device has changed, restarting Shairport Sync Oct 20 10:08:04 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:04 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 10:08:04 minidsp-shd sudo[1119]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:04 minidsp-shd sudo[1122]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:04 minidsp-shd sudo[1126]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 20 10:08:04 minidsp-shd sudo[1126]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:04 minidsp-shd volumio[789]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 20 10:08:04 minidsp-shd volumio[789]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 20 10:08:04 minidsp-shd systemd[1]: Listening on mpd.socket. Oct 20 10:08:04 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:04 minidsp-shd systemd[1]: Starting Music Player Daemon... Oct 20 10:08:04 minidsp-shd volumio[789]: info: ___________ START PLUGINS ___________ Oct 20 10:08:04 minidsp-shd volumio[789]: info: ControllerMpd::onStart: Initializing MPD Oct 20 10:08:04 minidsp-shd volumio[789]: info: Creating MPD Configuration file Oct 20 10:08:05 minidsp-shd sudo[1135]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 20 10:08:05 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 20 10:08:05 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 20 10:08:05 minidsp-shd sudo[1135]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:05 minidsp-shd volumio[789]: info: [1729411685042] CoreMusicLibrary::Adding element Media Servers Oct 20 10:08:05 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 20 10:08:05 minidsp-shd sudo[1135]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:05 minidsp-shd sudo[1137]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 20 10:08:05 minidsp-shd sudo[1137]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:05 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 20 10:08:05 minidsp-shd systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Oct 20 10:08:05 minidsp-shd systemd[1]: mpd.service: Succeeded. Oct 20 10:08:05 minidsp-shd systemd[1]: Stopped Music Player Daemon. Oct 20 10:08:05 minidsp-shd systemd[1]: Starting Music Player Daemon... Oct 20 10:08:05 minidsp-shd volumio[789]: info: Adding Manifest REST API Endpoints Oct 20 10:08:05 minidsp-shd volumio[789]: info: Adding manifestui REST Endpoint for plugin: miscellanea/manifestui Oct 20 10:08:05 minidsp-shd volumio[789]: info: Adding METAVOLUMIO REST API Endpoints Oct 20 10:08:05 minidsp-shd volumio[789]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Oct 20 10:08:05 minidsp-shd volumio[789]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Oct 20 10:08:05 minidsp-shd volumio[789]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Oct 20 10:08:05 minidsp-shd volumio[789]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Oct 20 10:08:05 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:05 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 10:08:05 minidsp-shd sudo[1142]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name miniDSP SHD Oct 20 10:08:05 minidsp-shd sudo[1142]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:05 minidsp-shd sudo[1142]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:05 minidsp-shd volumio[789]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 20 10:08:05 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:05 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 10:08:05 minidsp-shd volumio[789]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 20 10:08:05 minidsp-shd volumio[789]: info: Preparing CD Folders Oct 20 10:08:05 minidsp-shd volumio[789]: info: Adding CD REST API Endpoints Oct 20 10:08:05 minidsp-shd volumio[789]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Oct 20 10:08:05 minidsp-shd volumio[789]: info: Starting UDEV Watcher for CD Oct 20 10:08:05 minidsp-shd volumio[789]: info: Detecting CD presence with UDEV Oct 20 10:08:05 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Oct 20 10:08:05 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 20 10:08:05 minidsp-shd volumio[789]: info: [1729411685449] CoreMusicLibrary::Adding element Last_100 Oct 20 10:08:05 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 20 10:08:05 minidsp-shd volumio[789]: info: Starting RAAT Plugin Oct 20 10:08:05 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Oct 20 10:08:05 minidsp-shd volumio[789]: info: Additional UI Settings Added for plugin music_service/raat Oct 20 10:08:05 minidsp-shd volumio[789]: info: Streaming services startup Oct 20 10:08:05 minidsp-shd volumio[789]: info: Starting Streaming Daemon Oct 20 10:08:05 minidsp-shd sudo[1153]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 20 10:08:05 minidsp-shd sudo[1153]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:05 minidsp-shd sudo[1153]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:05 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 20 10:08:05 minidsp-shd volumio[789]: info: [1729411685704] CoreMusicLibrary::Adding element Webradio Oct 20 10:08:05 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 20 10:08:05 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 20 10:08:05 minidsp-shd sudo[1160]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 20 10:08:05 minidsp-shd sudo[1160]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:05 minidsp-shd volumio[789]: info: Creating Spotify config file Oct 20 10:08:05 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:05 minidsp-shd sudo[1160]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:05 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Oct 20 10:08:06 minidsp-shd volumio[789]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Oct 20 10:08:06 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:06 minidsp-shd dbus-daemon[460]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.8' (uid=1000 pid=789 comm="/usr/bin/node /volumio/index.js ") Oct 20 10:08:06 minidsp-shd volumio[789]: error: Hi Res Audio Failed Login: Missing Login Data Oct 20 10:08:06 minidsp-shd volumio[789]: info: Adding HIGHRESAUDIO REST API Endpoints Oct 20 10:08:06 minidsp-shd volumio[789]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Oct 20 10:08:06 minidsp-shd systemd[1]: Starting Bluetooth service... Oct 20 10:08:06 minidsp-shd bluetoothd[1166]: Bluetooth daemon 5.23 Oct 20 10:08:06 minidsp-shd dbus-daemon[460]: [system] Successfully activated service 'org.bluez' Oct 20 10:08:06 minidsp-shd systemd[1]: Started Bluetooth service. Oct 20 10:08:06 minidsp-shd bluetoothd[1166]: Starting SDP server Oct 20 10:08:06 minidsp-shd bluetoothd[1166]: kernel lacks bnep-protocol support Oct 20 10:08:06 minidsp-shd bluetoothd[1166]: System does not support network plugin Oct 20 10:08:06 minidsp-shd dbus-daemon[460]: [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 ") Oct 20 10:08:06 minidsp-shd bluetoothd[1166]: Bluetooth management interface 1.14 initialized Oct 20 10:08:06 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 20 10:08:06 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 10:08:06 minidsp-shd volumio[789]: info: Volumio Calling Home Oct 20 10:08:06 minidsp-shd systemd[1]: Starting Hostname Service... Oct 20 10:08:06 minidsp-shd volumio[789]: info: Stopping AccessToken refresher cron for QOBUZ Oct 20 10:08:06 minidsp-shd dbus-daemon[460]: [system] Successfully activated service 'org.freedesktop.hostname1' Oct 20 10:08:06 minidsp-shd systemd[1]: Started Hostname Service. Oct 20 10:08:06 minidsp-shd volumio[789]: info: AccessToken refresher cron started for QOBUZ Oct 20 10:08:06 minidsp-shd volumio[789]: info: Stopping AccessToken refresher cron Oct 20 10:08:06 minidsp-shd volumio[789]: info: AccessToken refresher cron started Oct 20 10:08:06 minidsp-shd volumio[789]: info: Adding TIDAL REST API Endpoints Oct 20 10:08:06 minidsp-shd volumio[789]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Oct 20 10:08:06 minidsp-shd volumio[789]: info: Adding QOBUZ REST API Endpoints Oct 20 10:08:06 minidsp-shd volumio[789]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Oct 20 10:08:06 minidsp-shd volumio[789]: info: Discovery: adding 7de2fe78-6056-4e2f-9f1b-de3300fc121e Oct 20 10:08:06 minidsp-shd volumio[789]: info: Discovery: Found device miniDSP SHD Oct 20 10:08:06 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioGetState Oct 20 10:08:06 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Oct 20 10:08:06 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output for this device Oct 20 10:08:06 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Oct 20 10:08:06 minidsp-shd volumio[789]: info: Adding audio output: Oct 20 10:08:07 minidsp-shd volumio[789]: info: Adding audio output: Oct 20 10:08:07 minidsp-shd volumio[789]: info: Serial port opened successfully Oct 20 10:08:07 minidsp-shd volumio[789]: error: Cannot start Volumio Streaming Daemon Oct 20 10:08:07 minidsp-shd volumio[789]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 20 10:08:07 minidsp-shd volumio[789]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 20 10:08:07 minidsp-shd volumio[789]: info: RAAT Albumart path created successfully Oct 20 10:08:07 minidsp-shd volumio[789]: error: Cannot set new Bluetooth Name : Error: Command failed: /usr/bin/sudo /bin/hciconfig hci0 name 'miniDSP SHD' Oct 20 10:08:07 minidsp-shd volumio[789]: Can't get device info: No such device Oct 20 10:08:07 minidsp-shd volumio[789]: info: MPD Permissions set Oct 20 10:08:07 minidsp-shd volumio[789]: info: MPD Permissions set Oct 20 10:08:07 minidsp-shd volumio[789]: info: Upmpdcli Daemon Started Oct 20 10:08:07 minidsp-shd volumio[789]: info: msSurfaceDial volumioupdatevolume callback: {"vol":79,"dbVolume":-27,"disableVolumeControl":false} Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Oct 20 10:08:07 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Oct 20 10:08:07 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Oct 20 10:08:07 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Oct 20 10:08:07 minidsp-shd volumio[789]: info: Ignoring ROON Volume update because of undefined data Oct 20 10:08:07 minidsp-shd volumio[789]: info: msSurfaceDial Managed Objs {"/org/bluez":{"org.freedesktop.DBus.Introspectable":{},"org.bluez.AgentManager1":{},"org.bluez.ProfileManager1":{}}} Oct 20 10:08:07 minidsp-shd volumio[789]: info: [msSurfaceDial init()] check /org/bluez Oct 20 10:08:07 minidsp-shd volumio[789]: info: [msSurfaceDial init()] Adapter: null; SurfaceDial: null Oct 20 10:08:07 minidsp-shd volumio[789]: info: msSurfaceDial BluetoothSurfaceDial init() - ready! Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::Reload Ui Oct 20 10:08:07 minidsp-shd volumio[789]: info: Volumio called home Oct 20 10:08:07 minidsp-shd volumio[789]: info: Spotify config file written Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: raat , updateDSP Oct 20 10:08:07 minidsp-shd volumio[789]: info: updateDSP function in raat called! Oct 20 10:08:07 minidsp-shd volumio[789]: info: Updating RAAT Signal Path Oct 20 10:08:07 minidsp-shd volumio[789]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: raat , reconfigureAndRestartRaat Oct 20 10:08:07 minidsp-shd volumio[789]: info: Reconfiguring and Restarting RAAT Plugin Oct 20 10:08:07 minidsp-shd sudo[1183]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 20 10:08:07 minidsp-shd sudo[1183]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd systemd[1]: Started go-librespot Daemon. Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: Not Reporting Auto name since its the default one Oct 20 10:08:07 minidsp-shd volumio[789]: info: RAAT Overriding default device vendor model Oct 20 10:08:07 minidsp-shd volumio[789]: info: Adding MINIDSP Inputs Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 20 10:08:07 minidsp-shd volumio[789]: info: [1729411687472] CoreMusicLibrary::Adding element Inputs Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 20 10:08:07 minidsp-shd volumio[789]: info: [1729411687482] CoreMusicLibrary::Adding element Presets Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 20 10:08:07 minidsp-shd volumio[789]: Cannot find translation for source Presets Oct 20 10:08:07 minidsp-shd sudo[1183]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:07 minidsp-shd go-librespot[1189]: Librespot-go daemon starting... Oct 20 10:08:07 minidsp-shd volumio[789]: (node:789) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Oct 20 10:08:07 minidsp-shd volumio[789]: (Use `node --trace-deprecation ...` to show where the warning was created) Oct 20 10:08:07 minidsp-shd volumio[789]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 1 Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:07+02:00" level=info msg="generated new device id: 6a1392d78a4839bae106661f7d890719e7d8f406" Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:07+02:00" level=debug msg="stored credentials found for 1164747946" Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 20 10:08:07 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:07 minidsp-shd volumio[789]: info: No need to fix Spotify hosts Oct 20 10:08:08 minidsp-shd sudo[1210]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Oct 20 10:08:08 minidsp-shd sudo[1210]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:08 minidsp-shd systemd[1]: Started Volumio Bluetooth Module. Oct 20 10:08:08 minidsp-shd sudo[1210]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:08 minidsp-shd volumio[789]: info: Starting Shairport Sync Oct 20 10:08:08 minidsp-shd volumio[789]: info: Starting Shairport Sync Oct 20 10:08:08 minidsp-shd sudo[1214]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Oct 20 10:08:08 minidsp-shd sudo[1214]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:08 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:08+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 20 10:08:08 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:08+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 20 10:08:08 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:08+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 20 10:08:08 minidsp-shd volumiobt[1213]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Oct 20 10:08:08 minidsp-shd sudo[1214]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:08 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:08+02:00" level=debug msg="zeroconf server listening on port 33555" Oct 20 10:08:08 minidsp-shd sudo[1216]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 20 10:08:08 minidsp-shd sudo[1216]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:08 minidsp-shd volumio[789]: info: Starting Shairport Sync Oct 20 10:08:08 minidsp-shd systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 20 10:08:08 minidsp-shd systemd[1]: shairport-sync.service: Succeeded. Oct 20 10:08:08 minidsp-shd sudo[1221]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 20 10:08:08 minidsp-shd systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 20 10:08:08 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Oct 20 10:08:08 minidsp-shd sudo[1221]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:08 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:08+02:00" level=debug msg="obtained new client token: AADV9uQ1a+zI0BTN83Uz7frXztmXsQrSHeBzWhYRsDYbF1uxHxf+7tZVAEJMLRTIYDa18qmWssTVr+rJjXVFSHzmmkfiQfnBXy6nSJUGG6i1IeHh0qCA6aEjcEAIL4QyABkLJ7B/zC5JQwvUjGHYMj8OC0/7s3HIjzSeP0ZPCRqnMw00cJmcogjolBhw0t2/iPoT3+1cuKgUhsEcbD0jfJPQOkHn7dod3+Y48Dr668+TdfhpnO5eQgDJ7waCdxw=" Oct 20 10:08:08 minidsp-shd systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 20 10:08:08 minidsp-shd sudo[1216]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:08 minidsp-shd sudo[1224]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 20 10:08:08 minidsp-shd sudo[1224]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:08 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:08+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 20 10:08:08 minidsp-shd systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 20 10:08:08 minidsp-shd systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 20 10:08:08 minidsp-shd systemd[1]: shairport-sync.service: Succeeded. Oct 20 10:08:08 minidsp-shd systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 20 10:08:08 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:08+02:00" level=debug msg="completed keyexchange" Oct 20 10:08:08 minidsp-shd systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 20 10:08:08 minidsp-shd sudo[1221]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:08 minidsp-shd sudo[1224]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:08 minidsp-shd volumio[789]: xcb_connection_has_error() returned true Oct 20 10:08:08 minidsp-shd volumio[789]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 20 10:08:08 minidsp-shd volumio[789]: SPOTIFY: BQDbbfuaaGDU3vfm3mwV2UAJvj_Vm-KMuAX5tYSXKpoo860JG29uOieVHXyswRPLYrP81ZAK3KJQfoLOD9D7sLH9Ot22T4qSPFvSFfaEKC1_qrPUT6xpwxqfObC8Q_5krcM2RL37lEKbdYJVG2Mezqabw8OsLtJz-DOV1XPsePMi8X-_LOQUqQrPxDeT_B0ATQQLnOi76ffafL1GcVY-D5yFJEt9b7WjctUtH3xY16MlUta5b2qdWkGlpJU Oct 20 10:08:08 minidsp-shd volumio[789]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 20 10:08:08 minidsp-shd volumio[789]: info: New Spotify access token = BQDbbfuaaGDU3vfm3mwV2UAJvj_Vm-KMuAX5tYSXKpoo860JG29uOieVHXyswRPLYrP81ZAK3KJQfoLOD9D7sLH9Ot22T4qSPFvSFfaEKC1_qrPUT6xpwxqfObC8Q_5krcM2RL37lEKbdYJVG2Mezqabw8OsLtJz-DOV1XPsePMi8X-_LOQUqQrPxDeT_B0ATQQLnOi76ffafL1GcVY-D5yFJEt9b7WjctUtH3xY16MlUta5b2qdWkGlpJU Oct 20 10:08:08 minidsp-shd volumio[789]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 20 10:08:08 minidsp-shd sudo[1231]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Oct 20 10:08:08 minidsp-shd sudo[1231]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:09 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Oct 20 10:08:09 minidsp-shd volumio[789]: info: CoreCommandRouter::volumiosetSourceActiveno-source Oct 20 10:08:09 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 20 10:08:09 minidsp-shd volumio[789]: Cannot find translation for source Presets Oct 20 10:08:09 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioStop Oct 20 10:08:09 minidsp-shd volumio[789]: info: CoreStateMachine::stop Oct 20 10:08:09 minidsp-shd systemd[1]: Started RAAT DAEMON. Oct 20 10:08:09 minidsp-shd volumio[789]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 20 10:08:09 minidsp-shd volumio[789]: info: Notifying Active Input {"trackType":"input","service":"inputs","title":"TOSLINK","disableUiControls":true,"albumart":"/albumart"} Oct 20 10:08:09 minidsp-shd volumio[789]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 20 10:08:09 minidsp-shd sudo[1231]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:09 minidsp-shd volumio[789]: info: Volumio BT Module successfully started Oct 20 10:08:09 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 20 10:08:09 minidsp-shd volumio[789]: info: Enabling external Volume Control Oct 20 10:08:09 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:09 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:09 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:09+02:00" level=debug msg="completed challenge" Oct 20 10:08:09 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:09+02:00" level=debug msg="authenticated as 1164747946" Oct 20 10:08:09 minidsp-shd volumio[789]: info: Raat Daemon started successfully Oct 20 10:08:09 minidsp-shd volumio[789]: info: Shairport-Sync Started Oct 20 10:08:09 minidsp-shd volumio[789]: Error adding Membership: Error: addMembership EINVAL Oct 20 10:08:09 minidsp-shd volumio[789]: info: Shairport-Sync Started Oct 20 10:08:09 minidsp-shd volumio[789]: info: Shairport-Sync Started Oct 20 10:08:09 minidsp-shd volumio[789]: info: TidalConnect service stoped! Oct 20 10:08:09 minidsp-shd volumio[789]: info: CoreCommandRouter::servicePushState Oct 20 10:08:09 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Oct 20 10:08:09 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 20 10:08:09 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Oct 20 10:08:09 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Oct 20 10:08:09 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Oct 20 10:08:09 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:09+02:00" level=debug msg="authenticated as 1164747946" Oct 20 10:08:09 minidsp-shd sudo[1250]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Oct 20 10:08:09 minidsp-shd sudo[1250]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:09 minidsp-shd volumiobt[1213]: pulseaudio: no process found Oct 20 10:08:09 minidsp-shd sudo[1250]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:09 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:09+02:00" level=debug msg="dealer connection opened" Oct 20 10:08:09 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:09+02:00" level=debug msg="initializing zeroconf session, username: 1164747946" Oct 20 10:08:09 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:09+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 20 10:08:09 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:09+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 20 10:08:09 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:09+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 20 10:08:09 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:09+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 20 10:08:09 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:09+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 505" Oct 20 10:08:09 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:09+02:00" level=debug msg="autoplay enabled: false" Oct 20 10:08:09 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:09+02:00" level=debug msg="received connection id: MTFhZmI2ZGItYzU0ZS00Y2QwLThmOGEtZDc5ZmQ4YTE2ZDE1K2RlYWxlcit0Y3A6Ly8wYWNhNThkOC5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArQzI2NDA5NjJCMEJFMDQ5RjJGNTIzMTE1QTI0NDZBRDEzMkU3OTE3MkE0MThFRTRCNTg1MDZCODc5MDkxRjgzNw==" Oct 20 10:08:09 minidsp-shd volumio[789]: info: Executing endpoint restartRAATSocket Oct 20 10:08:09 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Oct 20 10:08:09 minidsp-shd dbus-daemon[460]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.18' (uid=1000 pid=1255 comm="/usr/bin/pulseaudio --high-priority=true ") Oct 20 10:08:09 minidsp-shd systemd[1]: Starting RealtimeKit Scheduling Policy Service... Oct 20 10:08:09 minidsp-shd dbus-daemon[460]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Oct 20 10:08:09 minidsp-shd systemd[1]: Started RealtimeKit Scheduling Policy Service. Oct 20 10:08:09 minidsp-shd rtkit-daemon[1256]: Successfully called chroot. Oct 20 10:08:09 minidsp-shd rtkit-daemon[1256]: Successfully dropped privileges. Oct 20 10:08:09 minidsp-shd rtkit-daemon[1256]: Successfully limited resources. Oct 20 10:08:09 minidsp-shd rtkit-daemon[1256]: Running. Oct 20 10:08:09 minidsp-shd volumio[789]: info: MRS: Found cast device: Chromecast-Audio-4cae30823081f8544169b645ef26362c Oct 20 10:08:09 minidsp-shd volumio[789]: info: Adding audio output: Oct 20 10:08:09 minidsp-shd rtkit-daemon[1256]: Watchdog thread running. Oct 20 10:08:09 minidsp-shd dbus-daemon[460]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.19' (uid=0 pid=1256 comm="/usr/lib/rtkit/rtkit-daemon ") Oct 20 10:08:09 minidsp-shd rtkit-daemon[1256]: Canary thread running. Oct 20 10:08:09 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:09+02:00" level=debug msg="put connect state because NEW_DEVICE" Oct 20 10:08:09 minidsp-shd systemd[1]: Starting Authorization Manager... Oct 20 10:08:09 minidsp-shd volumio[789]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 20 10:08:10 minidsp-shd volumio[789]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Oct 20 10:08:10 minidsp-shd polkitd[1264]: started daemon version 0.105 using authority implementation `local' version `0.105' Oct 20 10:08:10 minidsp-shd dbus-daemon[460]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Oct 20 10:08:10 minidsp-shd systemd[1]: Started Authorization Manager. Oct 20 10:08:10 minidsp-shd volumio[789]: info: MRS: Found cast device: Altibox-TV-435455ce13cad7e711055c9a6762ab85 Oct 20 10:08:10 minidsp-shd volumio[789]: info: Adding audio output: Oct 20 10:08:10 minidsp-shd volumio[789]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 20 10:08:10 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioGetState Oct 20 10:08:10 minidsp-shd volumio[789]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 20 10:08:10 minidsp-shd volumio[789]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 20 10:08:10 minidsp-shd sudo[1269]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 20 10:08:10 minidsp-shd sudo[1269]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:10 minidsp-shd systemd[1]: Started Volumio Tidal Connect Service. Oct 20 10:08:10 minidsp-shd sudo[1269]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:10 minidsp-shd volumio[789]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Oct 20 10:08:10 minidsp-shd volumio[789]: info: msSurfaceDial volumioupdatevolume callback: {"vol":79,"dbVolume":-27,"mute":false,"disableVolumeControl":false} Oct 20 10:08:10 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Oct 20 10:08:10 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 20 10:08:10 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Oct 20 10:08:10 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Oct 20 10:08:10 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Oct 20 10:08:10 minidsp-shd volumio[789]: error: Help! Some callbacks for volumioPushState are crashing! Oct 20 10:08:10 minidsp-shd volumio[789]: error: Cannot read property 'sendVolumeMute' of undefined Oct 20 10:08:11 minidsp-shd volumio[789]: info: MRS: Getting audio outputs on start Oct 20 10:08:11 minidsp-shd volumio[789]: info: MRS: Requesting all other devices output Oct 20 10:08:11 minidsp-shd pulseaudio[1255]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Oct 20 10:08:11 minidsp-shd pulseaudio[1255]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Oct 20 10:08:11 minidsp-shd volumio[789]: 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=ecUt4evKqCAQ7kNvgEi_x2R&_nc_zt=24&_nc_ht=scontent-ams2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=Ad00hUTkMevPpSsFqOp0yvh&oh=00_AYAp-b-4WTvBuk-o0ijHu3ZitMQNb4taESwez04Fvj-AZw&oe=673B8E23","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=ecUt4evKqCAQ7kNvgEi_x2R&_nc_zt=24&_nc_ht=scontent-ams2-1.xx&edm=AP4hL3IEAAAA&_nc_gid=Ad00hUTkMevPpSsFqOp0yvh&oh=00_AYAiku04FGZMDJ0uQYPhqNseeYslPcMrmf285kjAt-AWHg&oe=673B8E23","width":64}],"product":"premium","type":"user","uri":"spotify:user:1164747946"} Oct 20 10:08:11 minidsp-shd volumiobt[1213]: Applying permissions Oct 20 10:08:11 minidsp-shd volumiobt[1213]: Setting BT discoverable and pairable Oct 20 10:08:11 minidsp-shd volumio[789]: info: Spotify Successfully logged in Oct 20 10:08:11 minidsp-shd pulseaudio[1255]: 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 Oct 20 10:08:11 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 20 10:08:11 minidsp-shd volumio[789]: info: [1729411691149] CoreMusicLibrary::Adding element Spotify Oct 20 10:08:11 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 20 10:08:11 minidsp-shd volumio[789]: Cannot find translation for source Presets Oct 20 10:08:11 minidsp-shd volumio[789]: Cannot find translation for source Spotify Oct 20 10:08:11 minidsp-shd volumiobt[1213]: [38B blob data] Oct 20 10:08:11 minidsp-shd volumiobt[1213]: Invalid command Oct 20 10:08:11 minidsp-shd volumiobt[1213]: [bluetooth]# agent on Oct 20 10:08:11 minidsp-shd volumiobt[1213]: [bluetooth]# discoverable on Oct 20 10:08:11 minidsp-shd volumiobt[1213]: No default controller available Oct 20 10:08:11 minidsp-shd volumiobt[1213]: [bluetooth]# pairable on Oct 20 10:08:11 minidsp-shd volumiobt[1213]: No default controller available Oct 20 10:08:11 minidsp-shd volumiobt[1213]: [bluetooth]# agent NoInputNoOutput Oct 20 10:08:11 minidsp-shd volumiobt[1213]: Failed to register agent object Oct 20 10:08:11 minidsp-shd volumiobt[1213]: [bluetooth]# default-agent Oct 20 10:08:11 minidsp-shd volumiobt[1213]: No agent is registered Oct 20 10:08:11 minidsp-shd volumiobt[1213]: [bluetooth]# quit Oct 20 10:08:11 minidsp-shd volumiobt[1213]: [61B blob data] Oct 20 10:08:11 minidsp-shd volumiobt[1213]: [62B blob data] Oct 20 10:08:11 minidsp-shd volumio[789]: info: go-librespot daemon successfully initialized Oct 20 10:08:11 minidsp-shd volumio[789]: info: msSurfaceDial volumioupdatevolume callback: {"vol":79,"dbVolume":-27,"mute":false,"disableVolumeControl":false} Oct 20 10:08:11 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Oct 20 10:08:11 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Oct 20 10:08:11 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Oct 20 10:08:11 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Oct 20 10:08:11 minidsp-shd volumio[789]: error: Help! Some callbacks for volumioPushState are crashing! Oct 20 10:08:11 minidsp-shd volumio[789]: error: Cannot read property 'sendVolumeMute' of undefined Oct 20 10:08:11 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Oct 20 10:08:11 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioGetState Oct 20 10:08:11 minidsp-shd volumio[789]: info: Executing endpoint tc_getconfig Oct 20 10:08:11 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Oct 20 10:08:11 minidsp-shd vtcs[1271]: STARTING TidalConnect services, version: 1.3.0.19 Oct 20 10:08:11 minidsp-shd volumio-remote-updater[472]: [2024-10-20 10:08:11] [connect] Successful connection Oct 20 10:08:11 minidsp-shd volumio-remote-updater[472]: [2024-10-20 10:08:11] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1729411691 101 Oct 20 10:08:11 minidsp-shd volumio[789]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 4 Oct 20 10:08:12 minidsp-shd vtcs[1271]: STARTED TidalConnect services. Oct 20 10:08:12 minidsp-shd volumio[789]: info: Executing endpoint tc_connect Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Oct 20 10:08:12 minidsp-shd volumio[789]: info: Connecting to TidalConnect Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreCommandRouter::servicePushState Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Oct 20 10:08:12 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Oct 20 10:08:12 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Oct 20 10:08:12 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Oct 20 10:08:12 minidsp-shd volumio[789]: 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} Oct 20 10:08:12 minidsp-shd volumio[789]: verbose: CURRENT POSITION 0 Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreStateMachine::syncState stateService stop Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreStateMachine::syncState currentStatus play Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Oct 20 10:08:12 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Oct 20 10:08:12 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreStateMachine::stPlaybackTimer Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreCommandRouter::servicePushState Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Oct 20 10:08:12 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Oct 20 10:08:12 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Oct 20 10:08:12 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Oct 20 10:08:12 minidsp-shd volumio[789]: 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} Oct 20 10:08:12 minidsp-shd volumio[789]: verbose: CURRENT POSITION 0 Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreStateMachine::syncState stateService stop Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreStateMachine::syncState currentStatus stop Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Oct 20 10:08:12 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Oct 20 10:08:12 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Oct 20 10:08:12 minidsp-shd volumio[789]: info: No code Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Oct 20 10:08:12 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Oct 20 10:08:12 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Oct 20 10:08:12 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Oct 20 10:08:13 minidsp-shd volumio[789]: info: TidalConnect service started! Oct 20 10:08:13 minidsp-shd mpd[1141]: Oct 20 10:08 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 20 10:08:13 minidsp-shd systemd[1]: Started Music Player Daemon. Oct 20 10:08:13 minidsp-shd volumio[789]: Upnp client error: Error: This socket has been ended by the other party Oct 20 10:08:13 minidsp-shd sudo[1126]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:13 minidsp-shd sudo[1137]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:13 minidsp-shd volumio[789]: info: Completed starting Core Plugins Oct 20 10:08:13 minidsp-shd volumio[789]: info: ------------------------------------------- Oct 20 10:08:13 minidsp-shd volumio[789]: info: ----- MyVolumio plugins startup ---- Oct 20 10:08:13 minidsp-shd volumio[789]: info: ------------------------------------------- Oct 20 10:08:13 minidsp-shd volumio[789]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 20 10:08:13 minidsp-shd volumio[789]: error: MPD error: The expression evaluated to a falsy value: Oct 20 10:08:13 minidsp-shd volumio[789]: assert.ok(self.idling) Oct 20 10:08:13 minidsp-shd volumio[789]: error: The expression evaluated to a falsy value: Oct 20 10:08:13 minidsp-shd volumio[789]: assert.ok(self.idling) Oct 20 10:08:13 minidsp-shd volumio[789]: info: MPD running with PID1141 Oct 20 10:08:13 minidsp-shd volumio[789]: ,establishing connection Oct 20 10:08:13 minidsp-shd volumio[789]: error: updateQueue error: null Oct 20 10:08:13 minidsp-shd volumio[789]: error: updateQueue error: null Oct 20 10:08:14 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:14+02:00" level=debug msg="handling transfer player command from 1c3f961463532dd05c7fdd38b2200608ba8c3c1e" Oct 20 10:08:14 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:14+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZF1EQqZlCxLOykhS" Oct 20 10:08:14 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:14+02:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:playlist:37i9dQZF1EQqZlCxLOykhS" Oct 20 10:08:14 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:14+02:00" level=warning msg="failed seeking to track in context spotify:playlist:37i9dQZF1EQqZlCxLOykhS" error="could not find track" Oct 20 10:08:14 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:14+02:00" level=debug msg="loading track (paused: false, position: 84124ms)" uri="spotify:track:11oBg7EA3BgPLWrIx4Rv7D" Oct 20 10:08:14 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:14+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 20 10:08:14 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:14+02:00" level=trace msg="emitting websocket event: will_play" Oct 20 10:08:14 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:14+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Oct 20 10:08:14 minidsp-shd volumio[789]: info: Initializing connection to go-librespot Websocket Oct 20 10:08:14 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:14+02:00" level=debug msg="new websocket client" Oct 20 10:08:14 minidsp-shd volumio[789]: info: Connection to go-librespot Websocket established Oct 20 10:08:14 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:14+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2822" Oct 20 10:08:14 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:14+02:00" level=debug msg="selected format OGG_VORBIS_320 (0d841c557dc909387b5fad490fd267805914918a)" uri="spotify:track:11oBg7EA3BgPLWrIx4Rv7D" Oct 20 10:08:14 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:14+02:00" level=debug msg="requested aes key for file 0d841c557dc909387b5fad490fd267805914918a, gid: 11oBg7EA3BgPLWrIx4Rv7D" Oct 20 10:08:14 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:14+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1867" Oct 20 10:08:14 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:14+02:00" level=debug msg="fetched first chunk of 23, total size is 11709552 bytes" uri="spotify:track:11oBg7EA3BgPLWrIx4Rv7D" Oct 20 10:08:14 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:14+02:00" level=debug msg="fetched chunk 1/22, size: 524288" uri="spotify:track:11oBg7EA3BgPLWrIx4Rv7D" Oct 20 10:08:15 minidsp-shd volumio[1124]: Generating RSA private key, 4096 bit long modulus (2 primes) Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=debug msg="fetched chunk 3/22, size: 524288" uri="spotify:track:11oBg7EA3BgPLWrIx4Rv7D" Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=debug msg="fetched chunk 2/22, size: 524288" uri="spotify:track:11oBg7EA3BgPLWrIx4Rv7D" Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=debug msg="fetched chunk 6/22, size: 524288" uri="spotify:track:11oBg7EA3BgPLWrIx4Rv7D" Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=debug msg="fetched chunk 8/22, size: 524288" uri="spotify:track:11oBg7EA3BgPLWrIx4Rv7D" Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=trace msg="seek to 84124ms (diff: 105ms, samples: 3709868, bytes: 3610296)" uri="spotify:track:11oBg7EA3BgPLWrIx4Rv7D" Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=debug msg="fetched chunk 9/22, size: 524288" uri="spotify:track:11oBg7EA3BgPLWrIx4Rv7D" Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=debug msg="fetched chunk 7/22, size: 524288" uri="spotify:track:11oBg7EA3BgPLWrIx4Rv7D" Oct 20 10:08:15 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 Oct 20 10:08:15 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 Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=debug msg="created new output device" Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=info msg="loaded track \"Legs (2008 Remaster)\" (paused: false, position: 84124ms, duration: 273906ms, prefetched: false)" uri="spotify:track:11oBg7EA3BgPLWrIx4Rv7D" Oct 20 10:08:15 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:15 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:15 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:15 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 20 10:08:15 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 20 10:08:15 minidsp-shd volumio[789]: info: Not Reporting Auto name since its the default one Oct 20 10:08:15 minidsp-shd volumio[789]: info: RAAT Overriding default device vendor model Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 20 10:08:15 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=trace msg="scheduling prefetch in 160s" Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=trace msg="emitting websocket event: metadata" Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=trace msg="emitting websocket event: active" Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=debug msg="sending successful reply for dealer request" Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 20 10:08:15 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:15+02:00" level=trace msg="emitting websocket event: playing" Oct 20 10:08:15 minidsp-shd volumio[789]: xcb_connection_has_error() returned true Oct 20 10:08:15 minidsp-shd volumio[789]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:11oBg7EA3BgPLWrIx4Rv7D","name":"Legs (2008 Remaster)","artist_names":["ZZ Top"],"album_name":"Eliminator","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02a2b4f98f60e3cacf3866b2e3","position":84124,"duration":273906,"release_date":"year:1983 month:3 day:23","track_number":6,"disc_number":1}} Oct 20 10:08:15 minidsp-shd volumio[789]: SPOTIFY: received: {"type":"active","data":null} Oct 20 10:08:15 minidsp-shd volumio[789]: info: Aligning Spotify Volume to Volumio Volume Oct 20 10:08:15 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioGetState Oct 20 10:08:15 minidsp-shd volumio[789]: info: Setting Spotify Volume from Volumio: 79 Oct 20 10:08:15 minidsp-shd volumio[789]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:11oBg7EA3BgPLWrIx4Rv7D","play_origin":"playlist"}} Oct 20 10:08:15 minidsp-shd volumio[789]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 20 10:08:15 minidsp-shd sudo[1319]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Oct 20 10:08:15 minidsp-shd volumio[789]: TypeError: Cannot read property 'service' of undefined Oct 20 10:08:15 minidsp-shd volumio[789]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:337:50) Oct 20 10:08:15 minidsp-shd volumio[789]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:263:18) Oct 20 10:08:15 minidsp-shd volumio[789]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Oct 20 10:08:15 minidsp-shd volumio[789]: at WebSocket.emit (events.js:400:28) Oct 20 10:08:15 minidsp-shd volumio[789]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Oct 20 10:08:15 minidsp-shd volumio[789]: at Receiver.emit (events.js:400:28) Oct 20 10:08:15 minidsp-shd volumio[789]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Oct 20 10:08:15 minidsp-shd volumio[789]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Oct 20 10:08:15 minidsp-shd volumio[789]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Oct 20 10:08:15 minidsp-shd volumio[789]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Oct 20 10:08:15 minidsp-shd volumio[789]: at writeOrBuffer (internal/streams/writable.js:358:12) Oct 20 10:08:15 minidsp-shd volumio[789]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Oct 20 10:08:15 minidsp-shd volumio[789]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Oct 20 10:08:15 minidsp-shd volumio[789]: at Socket.emit (events.js:400:28) Oct 20 10:08:15 minidsp-shd volumio[789]: at addChunk (internal/streams/readable.js:293:12) Oct 20 10:08:15 minidsp-shd volumio[789]: at readableAddChunk (internal/streams/readable.js:267:9) Oct 20 10:08:15 minidsp-shd volumio[789]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 20 10:08:15 minidsp-shd sudo[1319]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 20 10:08:15 minidsp-shd systemd[1]: Stopping RAAT DAEMON... Oct 20 10:08:15 minidsp-shd systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Oct 20 10:08:15 minidsp-shd systemd[1]: raat-daemon.service: Succeeded. Oct 20 10:08:15 minidsp-shd systemd[1]: Stopped RAAT DAEMON. Oct 20 10:08:15 minidsp-shd systemd[1]: Started RAAT DAEMON. Oct 20 10:08:15 minidsp-shd sudo[1319]: pam_unix(sudo:session): session closed for user root Oct 20 10:08:16 minidsp-shd go-librespot[1189]: time="2024-10-20T10:08:16+02:00" level=debug msg="fetched chunk 10/22, size: 524288" uri="spotify:track:11oBg7EA3BgPLWrIx4Rv7D" Oct 20 10:08:16 minidsp-shd sudo[1341]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-20 10:07 Oct 20 10:08:16 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"