-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Sat 2024-05-11 13:44:39 CEST. -- May 11 13:43:52 minidsp-shd ntpd[777]: receive: Unexpected origin timestamp 0xe8e38a94.cfe4bb23 does not match aorg 0000000000.00000000 from server@194.58.207.148 xmt 0xe9e9d878.a6e43946 May 11 13:43:52 minidsp-shd ntpd[777]: receive: Unexpected origin timestamp 0xe8e38a94.cff1167d does not match aorg 0000000000.00000000 from server@194.58.207.20 xmt 0xe9e9d878.a6ebadaf May 11 13:43:52 minidsp-shd ntpd[777]: receive: Unexpected origin timestamp 0xe8e38a94.cf9a29d1 does not match aorg 0000000000.00000000 from server@193.182.111.13 xmt 0xe9e9d878.a70f41ab May 11 13:43:52 minidsp-shd ntpd[777]: receive: Unexpected origin timestamp 0xe8e38a94.cfcdaf49 does not match aorg 0000000000.00000000 from server@194.58.205.20 xmt 0xe9e9d878.a7ad32b5 May 11 13:43:52 minidsp-shd systemd[1]: Starting Daily apt download activities... May 11 13:43:54 minidsp-shd systemd[1]: apt-daily.service: Succeeded. May 11 13:43:54 minidsp-shd systemd[1]: Started Daily apt download activities. May 11 13:43:54 minidsp-shd systemd[1]: Starting Daily apt upgrade and clean activities... May 11 13:43:55 minidsp-shd systemd[1]: apt-daily-upgrade.service: Succeeded. May 11 13:43:55 minidsp-shd volumio[788]: info: Loading plugin "network"... May 11 13:43:55 minidsp-shd systemd[1]: Started Daily apt upgrade and clean activities. May 11 13:43:55 minidsp-shd volumio[788]: info: Refreshing Cached IP Addresses May 11 13:43:55 minidsp-shd sudo[927]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 11 13:43:55 minidsp-shd sudo[927]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:43:55 minidsp-shd sudo[927]: pam_unix(sudo:session): session closed for user root May 11 13:43:55 minidsp-shd volumio[788]: info: Loading plugin "services"... May 11 13:43:55 minidsp-shd sudo[929]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 11 13:43:55 minidsp-shd sudo[929]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:43:55 minidsp-shd volumio[788]: info: Loading plugin "alsa_controller"... May 11 13:43:55 minidsp-shd sudo[929]: pam_unix(sudo:session): session closed for user root May 11 13:43:55 minidsp-shd sudo[932]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 11 13:43:55 minidsp-shd sudo[932]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:43:55 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 11 13:43:55 minidsp-shd volumio[788]: info: Loading plugin "wizard"... May 11 13:43:55 minidsp-shd volumio[788]: info: Loading plugin "volumio_command_line_client"... May 11 13:43:55 minidsp-shd volumio[788]: info: Loading plugin "upnp"... May 11 13:43:55 minidsp-shd volumio[788]: info: [1715427835738] Starting Upmpd Daemon May 11 13:43:55 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 11 13:43:55 minidsp-shd volumio[788]: info: Loading plugin "my_music"... May 11 13:43:55 minidsp-shd volumio[788]: info: Loading plugin "mpd"... May 11 13:43:56 minidsp-shd volumio[788]: info: Creating MPD Configuration file May 11 13:43:56 minidsp-shd volumio[788]: info: Loading plugin "upnp_browser"... May 11 13:43:56 minidsp-shd sudo[938]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 11 13:43:56 minidsp-shd sudo[938]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:43:56 minidsp-shd sudo[938]: pam_unix(sudo:session): session closed for user root May 11 13:43:56 minidsp-shd sudo[940]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 11 13:43:56 minidsp-shd sudo[940]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:43:56 minidsp-shd systemd[1]: Stopping Music Player Daemon... May 11 13:43:57 minidsp-shd systemd[1]: mpd.service: Succeeded. May 11 13:43:57 minidsp-shd systemd[1]: Stopped Music Player Daemon. May 11 13:43:57 minidsp-shd systemd[1]: Starting Music Player Daemon... May 11 13:43:57 minidsp-shd volumio[788]: info: Loading plugin "networkfs"... May 11 13:43:57 minidsp-shd systemd[1]: systemd-fsckd.service: Succeeded. May 11 13:43:58 minidsp-shd volumio[788]: info: Starting Udev Watcher for removable devices May 11 13:43:58 minidsp-shd sudo[949]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=admin,password=TorPeder1!,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.100/Lindskog/musik /mnt/NAS/NAS May 11 13:43:58 minidsp-shd sudo[949]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:43:58 minidsp-shd kernel: FS-Cache: Loaded May 11 13:43:58 minidsp-shd sh[379]: timed out May 11 13:43:58 minidsp-shd sh[379]: dhcpcd exited May 11 13:43:58 minidsp-shd dhcpcd[412]: timed out May 11 13:43:58 minidsp-shd dhcpcd[412]: dhcpcd exited May 11 13:43:58 minidsp-shd sh[379]: ifup: failed to bring up eth0 May 11 13:43:58 minidsp-shd systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE May 11 13:43:58 minidsp-shd systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. May 11 13:43:58 minidsp-shd kernel: FS-Cache: Netfs 'cifs' registered for caching May 11 13:43:58 minidsp-shd kernel: Key type cifs.spnego registered May 11 13:43:58 minidsp-shd kernel: Key type cifs.idmap registered May 11 13:43:58 minidsp-shd kernel: CIFS: Attempting to mount //192.168.1.100/Lindskog/musik May 11 13:43:58 minidsp-shd kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount. May 11 13:43:58 minidsp-shd volumio[788]: info: Ignoring mount for partition: BOOT May 11 13:43:58 minidsp-shd volumio[788]: info: Ignoring mount for partition: volumio May 11 13:43:58 minidsp-shd volumio[788]: info: Ignoring mount for partition: volumio_data May 11 13:43:58 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 11 13:43:58 minidsp-shd volumio[788]: info: Loading plugin "bluetooth"... May 11 13:43:59 minidsp-shd volumio[788]: info: [1715427839507] Starting BluetoothController May 11 13:43:59 minidsp-shd volumio[788]: info: Loading plugin "alarm-clock"... May 11 13:44:00 minidsp-shd sudo[949]: pam_unix(sudo:session): session closed for user root May 11 13:44:00 minidsp-shd sudo[932]: pam_unix(sudo:session): session closed for user root May 11 13:44:00 minidsp-shd volumio[788]: info: Loading plugin "manifestui"... May 11 13:44:00 minidsp-shd mpd[946]: May 11 13:44 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 11 13:44:00 minidsp-shd volumio[788]: info: Loading plugin "metavolumio"... May 11 13:44:00 minidsp-shd mpd[946]: May 11 13:44 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured May 11 13:44:00 minidsp-shd mpd[946]: May 11 13:44 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured May 11 13:44:00 minidsp-shd systemd[1]: Started Music Player Daemon. May 11 13:44:00 minidsp-shd sudo[940]: pam_unix(sudo:session): session closed for user root May 11 13:44:03 minidsp-shd volumio[788]: info: Loading plugin "airplay_emulation"... May 11 13:44:03 minidsp-shd volumio[788]: info: Starting Shairport Sync May 11 13:44:03 minidsp-shd volumio[788]: info: Loading plugin "cd_controller"... May 11 13:44:03 minidsp-shd volumio[788]: info: Loading plugin "last_100"... May 11 13:44:03 minidsp-shd volumio[788]: info: Loading plugin "raat"... May 11 13:44:04 minidsp-shd volumio[788]: info: RAAT Plugin loaded May 11 13:44:04 minidsp-shd volumio[788]: info: Adding restartRAATSocket REST API Endpoint May 11 13:44:04 minidsp-shd volumio[788]: info: Adding restartRAATSocket REST Endpoint for plugin: music_service/raat May 11 13:44:04 minidsp-shd volumio[788]: info: Loading plugin "streaming_services"... May 11 13:44:06 minidsp-shd volumio[788]: info: Starting Streaming Service Transparent Proxy May 11 13:44:06 minidsp-shd volumio[788]: info: Loading plugin "tidalconnect"... May 11 13:44:06 minidsp-shd volumio[788]: info: Loading plugin "webradio"... May 11 13:44:07 minidsp-shd volumio[788]: info: Loading plugin "i2s_dacs"... May 11 13:44:07 minidsp-shd volumio[788]: info: I2S DAC not set, start Auto-detection May 11 13:44:07 minidsp-shd volumio[788]: info: Loading plugin "volumiodiscovery"... May 11 13:44:07 minidsp-shd volumio[788]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 11 13:44:07 minidsp-shd volumio[788]: *** WARNING *** Please fix your application to use the native API of Avahi! May 11 13:44:07 minidsp-shd node[788]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 11 13:44:07 minidsp-shd volumio[788]: *** WARNING *** For more information see May 11 13:44:07 minidsp-shd volumio[788]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 11 13:44:07 minidsp-shd volumio[788]: *** WARNING *** Please fix your application to use the native API of Avahi! May 11 13:44:07 minidsp-shd volumio[788]: *** WARNING *** For more information see May 11 13:44:07 minidsp-shd node[788]: *** WARNING *** Please fix your application to use the native API of Avahi! May 11 13:44:07 minidsp-shd node[788]: *** WARNING *** For more information see May 11 13:44:07 minidsp-shd node[788]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 11 13:44:07 minidsp-shd node[788]: *** WARNING *** Please fix your application to use the native API of Avahi! May 11 13:44:07 minidsp-shd node[788]: *** WARNING *** For more information see May 11 13:44:07 minidsp-shd volumio[788]: info: Applying required configuration parameters for plugin volumiodiscovery May 11 13:44:07 minidsp-shd volumio[788]: info: Discovery: Started advertising with name: miniDSP SHD May 11 13:44:07 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 11 13:44:07 minidsp-shd volumio[788]: info: Loading plugin "spop"... May 11 13:44:07 minidsp-shd volumio-remote-updater[453]: [2024-05-11 13:44:07] [connect] Successful connection May 11 13:44:08 minidsp-shd volumio[788]: STREAMING PROXY: Starting server on port 3245 May 11 13:44:08 minidsp-shd volumio[788]: Node JS runtime: 14 May 11 13:44:10 minidsp-shd volumio[788]: info: Loading plugin "multiroom"... May 11 13:44:13 minidsp-shd volumio[788]: info: Applying required configuration parameters for plugin multiroom May 11 13:44:13 minidsp-shd sudo[991]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod +x /volumio/app/plugins/audio_interface/multiroom/scripts/check_snapcast May 11 13:44:13 minidsp-shd sudo[991]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:13 minidsp-shd sudo[991]: pam_unix(sudo:session): session closed for user root May 11 13:44:13 minidsp-shd sudo[993]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom May 11 13:44:13 minidsp-shd sudo[993]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:13 minidsp-shd sudo[993]: pam_unix(sudo:session): session closed for user root May 11 13:44:13 minidsp-shd volumio[788]: info: MRS: MultiRoom plugin initialized May 11 13:44:13 minidsp-shd volumio[788]: info: MRS: STOPPING SNAPCLIENT May 11 13:44:13 minidsp-shd volumio[788]: info: MRS: Snap server stop May 11 13:44:13 minidsp-shd sudo[1011]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient May 11 13:44:13 minidsp-shd volumio[788]: info: MRS: STOPPING volumioStreaming May 11 13:44:13 minidsp-shd sudo[1011]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:13 minidsp-shd sudo[1013]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver May 11 13:44:13 minidsp-shd sudo[1013]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:13 minidsp-shd sudo[1011]: pam_unix(sudo:session): session closed for user root May 11 13:44:13 minidsp-shd sudo[1016]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming May 11 13:44:13 minidsp-shd sudo[1016]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:13 minidsp-shd volumio[788]: info: Loading plugin "outputs"... May 11 13:44:13 minidsp-shd volumio[788]: info: Loading plugin "albumart"... May 11 13:44:13 minidsp-shd sudo[1020]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* May 11 13:44:13 minidsp-shd sudo[1020]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:13 minidsp-shd sudo[1013]: pam_unix(sudo:session): session closed for user root May 11 13:44:13 minidsp-shd sudo[1020]: pam_unix(sudo:session): session closed for user root May 11 13:44:13 minidsp-shd sudo[1016]: pam_unix(sudo:session): session closed for user root May 11 13:44:13 minidsp-shd volumio[788]: info: Loading plugin "ms_surface_dial"... May 11 13:44:14 minidsp-shd volumio[788]: Forking 3 albumart workers May 11 13:44:15 minidsp-shd volumio[788]: info: Applying required configuration parameters for plugin ms_surface_dial May 11 13:44:15 minidsp-shd volumio[788]: info: Plugin example_plugin is not enabled May 11 13:44:15 minidsp-shd volumio[788]: info: Loading plugin "hi_res_audio"... May 11 13:44:16 minidsp-shd volumio[788]: Starting albumart workers May 11 13:44:16 minidsp-shd volumio[788]: Starting albumart workers May 11 13:44:16 minidsp-shd volumio[788]: Starting albumart workers May 11 13:44:18 minidsp-shd volumio[788]: info: Applying required configuration parameters for plugin hi_res_audio May 11 13:44:18 minidsp-shd volumio[788]: info: Loading plugin "inputs"... May 11 13:44:19 minidsp-shd volumio[788]: info: Loading plugin "qobuz"... May 11 13:44:22 minidsp-shd volumio[788]: info: Loading plugin "tidal"... May 11 13:44:22 minidsp-shd volumio-remote-updater[453]: [2024-05-11 13:44:22] [connect] Successful connection May 11 13:44:24 minidsp-shd volumio[788]: info: Loading plugin "oem_helper"... May 11 13:44:26 minidsp-shd volumio[788]: info: Applying required configuration parameters for plugin oem_helper May 11 13:44:26 minidsp-shd volumio[788]: info: Loading plugin "updater_comm"... May 11 13:44:26 minidsp-shd volumio[788]: info: Plugin mpdemulation is not enabled May 11 13:44:26 minidsp-shd volumio[788]: info: Loading plugin "rest_api"... May 11 13:44:26 minidsp-shd volumio[788]: info: Loading plugin "websocket"... May 11 13:44:26 minidsp-shd volumio[788]: info: Loading i18n strings for locale sv May 11 13:44:26 minidsp-shd volumio[788]: Updating browse sources language May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::initPlayerControls May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 11 13:44:27 minidsp-shd volumio[788]: Express server listening on port 3000 May 11 13:44:27 minidsp-shd volumio[788]: [Metrics] WebUI: 38s 816.66ms May 11 13:44:27 minidsp-shd volumio[788]: info: CoreStateMachine::resetVolumioState May 11 13:44:27 minidsp-shd volumio[788]: info: CoreStateMachine::getcurrentVolume May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::volumioRetrievevolume May 11 13:44:27 minidsp-shd volumio[788]: info: CoreStateMachine::pushState May 11 13:44:27 minidsp-shd volumio[788]: info: CorePlayQueue::getTrack 0 May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::volumioPushState May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 11 13:44:27 minidsp-shd sudo[1078]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 11 13:44:27 minidsp-shd sudo[1078]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: inputs , getVolume May 11 13:44:27 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: inputs , getDSP May 11 13:44:27 minidsp-shd sudo[1078]: pam_unix(sudo:session): session closed for user root May 11 13:44:27 minidsp-shd sudo[1080]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 11 13:44:27 minidsp-shd sudo[1080]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:27 minidsp-shd sudo[1080]: pam_unix(sudo:session): session closed for user root May 11 13:44:27 minidsp-shd volumio[788]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' May 11 13:44:27 minidsp-shd volumio[788]: info: Completed loading Core Plugins May 11 13:44:27 minidsp-shd volumio[788]: info: Preparing to generate the ALSA configuration file May 11 13:44:27 minidsp-shd volumio[788]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Hardware May 11 13:44:27 minidsp-shd volumio[788]: info: MRS: Removed streaming files May 11 13:44:27 minidsp-shd volumio[788]: info: MRS: volumioStreaming STOPPED May 11 13:44:27 minidsp-shd volumio[788]: info: MRS: SNAPSERVER STOPPED May 11 13:44:27 minidsp-shd volumio[788]: info: MRS: SNAPCLIENT STOPPED May 11 13:44:27 minidsp-shd volumio[788]: info: Snap server and client installed May 11 13:44:27 minidsp-shd volumio[788]: info: MPD Permissions set May 11 13:44:28 minidsp-shd volumio[788]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 11 13:44:28 minidsp-shd volumio[788]: info: Reading ALSA contributions from plugins. May 11 13:44:28 minidsp-shd volumio[788]: info: MPD running with PID946 May 11 13:44:28 minidsp-shd volumio[788]: ,establishing connection May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:28 minidsp-shd volumio[788]: info: Reloading queue from file May 11 13:44:28 minidsp-shd volumio[788]: error: updateQueue error: null May 11 13:44:28 minidsp-shd volumio[788]: info: CoreStateMachine::setRepeat false single undefined May 11 13:44:28 minidsp-shd volumio[788]: info: CoreStateMachine::pushState May 11 13:44:28 minidsp-shd volumio[788]: info: CorePlayQueue::getTrack 0 May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::volumioPushState May 11 13:44:28 minidsp-shd volumio[788]: info: CoreStateMachine::setRandom null May 11 13:44:28 minidsp-shd volumio[788]: info: CoreStateMachine::pushState May 11 13:44:28 minidsp-shd volumio[788]: info: CorePlayQueue::getTrack 0 May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::volumioPushState May 11 13:44:28 minidsp-shd volumio[788]: error: updateQueue error: null May 11 13:44:28 minidsp-shd volumio[788]: info: Asound.conf file unchanged, so no further update is needed May 11 13:44:28 minidsp-shd volumio[788]: info: Output device has changed, restarting MPD May 11 13:44:28 minidsp-shd sudo[1097]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 11 13:44:28 minidsp-shd sudo[1097]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:28 minidsp-shd systemd[1]: Started UPnP Renderer front-end to MPD. May 11 13:44:28 minidsp-shd sudo[1100]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 11 13:44:28 minidsp-shd sudo[1100]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:28 minidsp-shd volumio[788]: info: Output device has changed, restarting Shairport Sync May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 11 13:44:28 minidsp-shd sudo[1100]: pam_unix(sudo:session): session closed for user root May 11 13:44:28 minidsp-shd sudo[1097]: pam_unix(sudo:session): session closed for user root May 11 13:44:28 minidsp-shd sudo[1104]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 11 13:44:28 minidsp-shd sudo[1104]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:28 minidsp-shd systemd[1]: Stopping Music Player Daemon... May 11 13:44:28 minidsp-shd volumio[788]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 11 13:44:28 minidsp-shd systemd[1]: mpd.service: Succeeded. May 11 13:44:28 minidsp-shd volumio[788]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 11 13:44:28 minidsp-shd systemd[1]: Stopped Music Player Daemon. May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:28 minidsp-shd systemd[1]: Starting Music Player Daemon... May 11 13:44:28 minidsp-shd volumio[788]: info: ___________ START PLUGINS ___________ May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 11 13:44:28 minidsp-shd volumio[788]: info: [1715427868976] CoreMusicLibrary::Adding element Media Servers May 11 13:44:28 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 11 13:44:29 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 11 13:44:29 minidsp-shd volumio[788]: info: Adding Manifest REST API Endpoints May 11 13:44:29 minidsp-shd volumio[788]: info: Adding manifestui REST Endpoint for plugin: miscellanea/manifestui May 11 13:44:29 minidsp-shd volumio[788]: info: Adding METAVOLUMIO REST API Endpoints May 11 13:44:29 minidsp-shd volumio[788]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio May 11 13:44:29 minidsp-shd volumio[788]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio May 11 13:44:29 minidsp-shd volumio[788]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio May 11 13:44:29 minidsp-shd volumio[788]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio May 11 13:44:29 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:29 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 11 13:44:29 minidsp-shd sudo[1113]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name miniDSP SHD May 11 13:44:29 minidsp-shd sudo[1113]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:29 minidsp-shd sudo[1113]: pam_unix(sudo:session): session closed for user root May 11 13:44:29 minidsp-shd volumio[788]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 11 13:44:29 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:29 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 11 13:44:29 minidsp-shd volumio[788]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 11 13:44:29 minidsp-shd volumio[788]: info: Preparing CD Folders May 11 13:44:29 minidsp-shd volumio[788]: info: Adding CD REST API Endpoints May 11 13:44:29 minidsp-shd volumio[788]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller May 11 13:44:29 minidsp-shd volumio[788]: info: Starting UDEV Watcher for CD May 11 13:44:29 minidsp-shd volumio[788]: info: Detecting CD presence with UDEV May 11 13:44:29 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices May 11 13:44:29 minidsp-shd volumio[788]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 11 13:44:29 minidsp-shd volumio[788]: info: [1715427869829] CoreMusicLibrary::Adding element Last_100 May 11 13:44:29 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 11 13:44:29 minidsp-shd volumio[788]: info: Starting RAAT Plugin May 11 13:44:29 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections May 11 13:44:29 minidsp-shd volumio[788]: info: Additional UI Settings Added for plugin music_service/raat May 11 13:44:29 minidsp-shd volumio[788]: info: Streaming services startup May 11 13:44:29 minidsp-shd volumio[788]: info: Starting Streaming Daemon May 11 13:44:29 minidsp-shd sudo[1126]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 11 13:44:29 minidsp-shd sudo[1126]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:30 minidsp-shd sudo[1126]: pam_unix(sudo:session): session closed for user root May 11 13:44:30 minidsp-shd volumio[788]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 11 13:44:30 minidsp-shd volumio[788]: info: [1715427870077] CoreMusicLibrary::Adding element Webradio May 11 13:44:30 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 11 13:44:30 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 11 13:44:30 minidsp-shd sudo[1133]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 11 13:44:30 minidsp-shd sudo[1133]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:30 minidsp-shd volumio[788]: info: Creating Spotify config file May 11 13:44:30 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus May 11 13:44:30 minidsp-shd sudo[1133]: pam_unix(sudo:session): session closed for user root May 11 13:44:30 minidsp-shd volumio[788]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 11 13:44:30 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:30 minidsp-shd dbus-daemon[442]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.8' (uid=1000 pid=788 comm="/usr/bin/node /volumio/index.js ") May 11 13:44:30 minidsp-shd volumio[788]: error: Hi Res Audio Failed Login: Missing Login Data May 11 13:44:30 minidsp-shd volumio[788]: info: Adding HIGHRESAUDIO REST API Endpoints May 11 13:44:30 minidsp-shd volumio[788]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio May 11 13:44:30 minidsp-shd systemd[1]: Starting Bluetooth service... May 11 13:44:30 minidsp-shd bluetoothd[1139]: Bluetooth daemon 5.23 May 11 13:44:30 minidsp-shd dbus-daemon[442]: [system] Successfully activated service 'org.bluez' May 11 13:44:30 minidsp-shd systemd[1]: Started Bluetooth service. May 11 13:44:30 minidsp-shd bluetoothd[1139]: Starting SDP server May 11 13:44:30 minidsp-shd bluetoothd[1139]: kernel lacks bnep-protocol support May 11 13:44:30 minidsp-shd bluetoothd[1139]: System does not support network plugin May 11 13:44:30 minidsp-shd bluetoothd[1139]: Bluetooth management interface 1.14 initialized May 11 13:44:30 minidsp-shd dbus-daemon[442]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.11' (uid=0 pid=1139 comm="/usr/local/libexec/bluetooth/bluetoothd ") May 11 13:44:30 minidsp-shd systemd[1]: Starting Hostname Service... May 11 13:44:30 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 11 13:44:30 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 11 13:44:30 minidsp-shd volumio[788]: info: Volumio Calling Home May 11 13:44:30 minidsp-shd volumio[788]: info: Stopping AccessToken refresher cron for QOBUZ May 11 13:44:30 minidsp-shd volumio[788]: info: AccessToken refresher cron started for QOBUZ May 11 13:44:30 minidsp-shd volumio[788]: info: Stopping AccessToken refresher cron May 11 13:44:31 minidsp-shd volumio[788]: info: AccessToken refresher cron started May 11 13:44:31 minidsp-shd volumio[788]: info: Adding TIDAL REST API Endpoints May 11 13:44:31 minidsp-shd volumio[788]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal May 11 13:44:31 minidsp-shd volumio[788]: info: Adding QOBUZ REST API Endpoints May 11 13:44:31 minidsp-shd volumio[788]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz May 11 13:44:31 minidsp-shd dbus-daemon[442]: [system] Successfully activated service 'org.freedesktop.hostname1' May 11 13:44:31 minidsp-shd systemd[1]: Started Hostname Service. May 11 13:44:31 minidsp-shd volumio[788]: info: Discovery: adding 01b6c6df-a455-48e5-a1b1-7b6285c0b557 May 11 13:44:31 minidsp-shd volumio[788]: info: Discovery: Found device miniDSP SHD May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::volumioGetState May 11 13:44:31 minidsp-shd volumio[788]: info: CorePlayQueue::getTrack 0 May 11 13:44:31 minidsp-shd volumio[788]: info: MRS: Pushing multiroomSync output for this device May 11 13:44:31 minidsp-shd volumio[788]: info: MRS: Pushing multiroomSync output May 11 13:44:31 minidsp-shd volumio[788]: info: Adding audio output: May 11 13:44:31 minidsp-shd volumio[788]: info: Adding audio output: May 11 13:44:31 minidsp-shd volumio[788]: info: Serial port opened successfully May 11 13:44:31 minidsp-shd volumio[788]: error: Cannot start Volumio Streaming Daemon May 11 13:44:31 minidsp-shd volumio[788]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 11 13:44:31 minidsp-shd volumio[788]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 11 13:44:31 minidsp-shd volumio[788]: info: RAAT Albumart path created successfully May 11 13:44:31 minidsp-shd volumio[788]: error: Cannot set new Bluetooth Name : Error: Command failed: /usr/bin/sudo /bin/hciconfig hci0 name 'miniDSP SHD' May 11 13:44:31 minidsp-shd volumio[788]: Can't get device info: No such device May 11 13:44:31 minidsp-shd volumio[788]: info: MPD Permissions set May 11 13:44:31 minidsp-shd volumio[788]: info: Upmpdcli Daemon Started May 11 13:44:31 minidsp-shd volumio[788]: [28B blob data] May 11 13:44:31 minidsp-shd volumio[788]: info: Serial Data: PUSH MVOL 188 May 11 13:44:31 minidsp-shd volumio[788]: info: msSurfaceDial volumioupdatevolume callback: {"vol":74,"dbVolume":-33.5,"disableVolumeControl":false} May 11 13:44:31 minidsp-shd volumio[788]: info: CoreStateMachine::pushState May 11 13:44:31 minidsp-shd volumio[788]: info: CorePlayQueue::getTrack 0 May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::volumioPushState May 11 13:44:31 minidsp-shd volumio[788]: info: MRS: Pushing multiroomSync output update for this device May 11 13:44:31 minidsp-shd volumio[788]: info: MRS: Pushing multiroomSync output May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume May 11 13:44:31 minidsp-shd volumio[788]: info: Ignoring ROON Volume update because of undefined data May 11 13:44:31 minidsp-shd volumio[788]: info: msSurfaceDial Managed Objs {"/org/bluez":{"org.freedesktop.DBus.Introspectable":{},"org.bluez.AgentManager1":{},"org.bluez.ProfileManager1":{}}} May 11 13:44:31 minidsp-shd volumio[788]: info: [msSurfaceDial init()] check /org/bluez May 11 13:44:31 minidsp-shd volumio[788]: info: [msSurfaceDial init()] Adapter: null; SurfaceDial: null May 11 13:44:31 minidsp-shd volumio[788]: info: msSurfaceDial BluetoothSurfaceDial init() - ready! May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::Reload Ui May 11 13:44:31 minidsp-shd volumio[788]: info: Volumio called home May 11 13:44:31 minidsp-shd volumio[788]: info: Spotify config file written May 11 13:44:31 minidsp-shd volumio[788]: [27B blob data] May 11 13:44:31 minidsp-shd volumio[788]: info: Serial Data: PUSH DSP 0111111 May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: raat , updateDSP May 11 13:44:31 minidsp-shd volumio[788]: info: updateDSP function in raat called! May 11 13:44:31 minidsp-shd volumio[788]: info: Updating RAAT Signal Path May 11 13:44:31 minidsp-shd volumio[788]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined May 11 13:44:31 minidsp-shd volumio[788]: [29B blob data] May 11 13:44:31 minidsp-shd volumio[788]: info: Serial Data: PUSH MODEL 1 May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: raat , reconfigureAndRestartRaat May 11 13:44:31 minidsp-shd volumio[788]: info: Reconfiguring and Restarting RAAT Plugin May 11 13:44:31 minidsp-shd sudo[1156]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 11 13:44:31 minidsp-shd sudo[1156]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:31 minidsp-shd systemd[1]: Started go-librespot Daemon. May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 11 13:44:31 minidsp-shd volumio[788]: info: Not Reporting Auto name since its the default one May 11 13:44:31 minidsp-shd volumio[788]: info: RAAT Overriding default device vendor model May 11 13:44:31 minidsp-shd go-librespot[1162]: Librespot-go daemon starting... May 11 13:44:31 minidsp-shd volumio[788]: info: Adding MINIDSP Inputs May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 11 13:44:31 minidsp-shd volumio[788]: info: [1715427871719] CoreMusicLibrary::Adding element Inputs May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 11 13:44:31 minidsp-shd volumio[788]: info: [1715427871728] CoreMusicLibrary::Adding element Presets May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 11 13:44:31 minidsp-shd sudo[1156]: pam_unix(sudo:session): session closed for user root May 11 13:44:31 minidsp-shd volumio[788]: Cannot find translation for source Presets May 11 13:44:31 minidsp-shd volumio[788]: (node:788) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. May 11 13:44:31 minidsp-shd volumio[788]: (Use `node --trace-deprecation ...` to show where the warning was created) May 11 13:44:31 minidsp-shd volumio[788]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 1 May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 11 13:44:31 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:32 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:32+02:00" level=info msg="generated new device id: 4712bf41c8e6de69e7e947d172b41d0139e003e3" May 11 13:44:32 minidsp-shd sudo[1178]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service May 11 13:44:32 minidsp-shd sudo[1178]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:32 minidsp-shd systemd[1]: Started Volumio Bluetooth Module. May 11 13:44:32 minidsp-shd sudo[1178]: pam_unix(sudo:session): session closed for user root May 11 13:44:32 minidsp-shd volumio[788]: info: Starting Shairport Sync May 11 13:44:32 minidsp-shd sudo[1183]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* May 11 13:44:32 minidsp-shd sudo[1183]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:32 minidsp-shd volumiobt[1182]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory May 11 13:44:32 minidsp-shd sudo[1183]: pam_unix(sudo:session): session closed for user root May 11 13:44:32 minidsp-shd volumio[788]: info: Starting Shairport Sync May 11 13:44:32 minidsp-shd volumio[788]: info: Starting Shairport Sync May 11 13:44:32 minidsp-shd sudo[1187]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 11 13:44:32 minidsp-shd sudo[1187]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:32 minidsp-shd sudo[1189]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 11 13:44:32 minidsp-shd sudo[1189]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:32 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable May 11 13:44:32 minidsp-shd systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 11 13:44:32 minidsp-shd systemd[1]: shairport-sync.service: Succeeded. May 11 13:44:32 minidsp-shd systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 11 13:44:32 minidsp-shd sudo[1193]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 11 13:44:32 minidsp-shd sudo[1193]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:32 minidsp-shd systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 11 13:44:32 minidsp-shd sudo[1187]: pam_unix(sudo:session): session closed for user root May 11 13:44:32 minidsp-shd sudo[1189]: pam_unix(sudo:session): session closed for user root May 11 13:44:32 minidsp-shd volumio[788]: xcb_connection_has_error() returned true May 11 13:44:32 minidsp-shd systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 11 13:44:32 minidsp-shd systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 11 13:44:32 minidsp-shd systemd[1]: shairport-sync.service: Succeeded. May 11 13:44:32 minidsp-shd systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 11 13:44:32 minidsp-shd volumio[788]: info: MRS: Found cast device: Nest-Audio-283b174f0407f2a35ed3b5e88d8e02cb May 11 13:44:32 minidsp-shd volumio[788]: info: Adding audio output: May 11 13:44:32 minidsp-shd systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 11 13:44:32 minidsp-shd sudo[1193]: pam_unix(sudo:session): session closed for user root May 11 13:44:32 minidsp-shd sudo[1200]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service May 11 13:44:32 minidsp-shd sudo[1200]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:33 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:33+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" May 11 13:44:33 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:33+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 11 13:44:33 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:33+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 11 13:44:33 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:33+02:00" level=debug msg="zeroconf server listening on port 33497" May 11 13:44:33 minidsp-shd volumio[788]: ------------------------------------ BT MESSAGE: BT STATUS: running May 11 13:44:33 minidsp-shd systemd[1]: Started RAAT DAEMON. May 11 13:44:33 minidsp-shd sudo[1200]: pam_unix(sudo:session): session closed for user root May 11 13:44:33 minidsp-shd volumio[788]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 11 13:44:33 minidsp-shd volumio[788]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 11 13:44:33 minidsp-shd mpd[1122]: May 11 13:44 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 11 13:44:33 minidsp-shd volumio[788]: ------------------------------------ BT MESSAGE: BT STATUS: running May 11 13:44:33 minidsp-shd volumio[788]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 11 13:44:33 minidsp-shd mpd[1122]: May 11 13:44 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured May 11 13:44:33 minidsp-shd mpd[1122]: May 11 13:44 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured May 11 13:44:33 minidsp-shd systemd[1]: Started Music Player Daemon. May 11 13:44:33 minidsp-shd sudo[1104]: pam_unix(sudo:session): session closed for user root May 11 13:44:33 minidsp-shd volumio[788]: info: Volumio BT Module successfully started May 11 13:44:33 minidsp-shd volumio[788]: error: MPD error: Error: This socket has been ended by the other party May 11 13:44:33 minidsp-shd volumio[788]: error: This socket has been ended by the other party {"code":"EPIPE"} May 11 13:44:33 minidsp-shd volumio[788]: error: MPD error: Error: This socket has been ended by the other party May 11 13:44:33 minidsp-shd volumio[788]: error: This socket has been ended by the other party {"code":"EPIPE"} May 11 13:44:33 minidsp-shd volumio[788]: error: MPD error: Error: This socket has been ended by the other party May 11 13:44:33 minidsp-shd volumio[788]: error: This socket has been ended by the other party {"code":"EPIPE"} May 11 13:44:33 minidsp-shd volumio[788]: error: MPD error: Error: This socket has been ended by the other party May 11 13:44:33 minidsp-shd volumio[788]: error: This socket has been ended by the other party {"code":"EPIPE"} May 11 13:44:33 minidsp-shd volumio[788]: error: MPD error: Error: This socket has been ended by the other party May 11 13:44:33 minidsp-shd volumio[788]: error: This socket has been ended by the other party {"code":"EPIPE"} May 11 13:44:33 minidsp-shd volumio[788]: error: MPD error: Error: This socket has been ended by the other party May 11 13:44:33 minidsp-shd volumio[788]: error: This socket has been ended by the other party {"code":"EPIPE"} May 11 13:44:33 minidsp-shd volumio[788]: error: MPD error: Error: This socket has been ended by the other party May 11 13:44:33 minidsp-shd volumio[788]: error: This socket has been ended by the other party {"code":"EPIPE"} May 11 13:44:33 minidsp-shd volumio[788]: error: MPD error: Error: This socket has been ended by the other party May 11 13:44:33 minidsp-shd volumio[788]: error: This socket has been ended by the other party {"code":"EPIPE"} May 11 13:44:33 minidsp-shd volumio[788]: error: MPD error: Error: This socket has been ended by the other party May 11 13:44:33 minidsp-shd volumio[788]: error: This socket has been ended by the other party {"code":"EPIPE"} May 11 13:44:33 minidsp-shd volumio[788]: info: MRS: Found cast device: Chromecast-Ultra-337307295589ba3195d22bc470fad773 May 11 13:44:33 minidsp-shd volumio[788]: info: Adding audio output: May 11 13:44:33 minidsp-shd volumio[788]: Upnp client error: Error: This socket has been ended by the other party May 11 13:44:33 minidsp-shd volumio[788]: info: Raat Daemon started successfully May 11 13:44:33 minidsp-shd volumio[788]: info: Shairport-Sync Started May 11 13:44:33 minidsp-shd volumio[788]: Error adding Membership: Error: addMembership EINVAL May 11 13:44:33 minidsp-shd sudo[1218]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio May 11 13:44:33 minidsp-shd volumio[788]: info: Shairport-Sync Started May 11 13:44:33 minidsp-shd volumio[788]: info: Shairport-Sync Started May 11 13:44:33 minidsp-shd sudo[1218]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:33 minidsp-shd volumio[788]: info: TidalConnect service stoped! May 11 13:44:33 minidsp-shd volumiobt[1182]: pulseaudio: no process found May 11 13:44:33 minidsp-shd sudo[1218]: pam_unix(sudo:session): session closed for user root May 11 13:44:33 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 11 13:44:33 minidsp-shd volumio[788]: info: Enabling external Volume Control May 11 13:44:33 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:33 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 13:44:33 minidsp-shd volumio[788]: [30B blob data] May 11 13:44:33 minidsp-shd volumio[788]: info: Serial Data: PUSH SOURCE 7 May 11 13:44:33 minidsp-shd volumio[788]: info: CoreCommandRouter::volumiosetSourceActiveno-source May 11 13:44:33 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 11 13:44:33 minidsp-shd volumio[788]: Cannot find translation for source Presets May 11 13:44:33 minidsp-shd volumio[788]: [30B blob data] May 11 13:44:33 minidsp-shd volumio[788]: info: Serial Data: PUSH PRESET 1 May 11 13:44:33 minidsp-shd volumio[788]: info: MRS: Found cast device: Google-Nest-Mini-cc979e945a1a0b01715b51e4939926cd May 11 13:44:33 minidsp-shd volumio[788]: info: Adding audio output: May 11 13:44:33 minidsp-shd dbus-daemon[442]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.21' (uid=1000 pid=1226 comm="/usr/bin/pulseaudio --high-priority=true ") May 11 13:44:33 minidsp-shd systemd[1]: Starting RealtimeKit Scheduling Policy Service... May 11 13:44:33 minidsp-shd dbus-daemon[442]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' May 11 13:44:33 minidsp-shd systemd[1]: Started RealtimeKit Scheduling Policy Service. May 11 13:44:33 minidsp-shd rtkit-daemon[1227]: Successfully called chroot. May 11 13:44:33 minidsp-shd rtkit-daemon[1227]: Successfully dropped privileges. May 11 13:44:33 minidsp-shd rtkit-daemon[1227]: Successfully limited resources. May 11 13:44:33 minidsp-shd rtkit-daemon[1227]: Running. May 11 13:44:33 minidsp-shd rtkit-daemon[1227]: Watchdog thread running. May 11 13:44:33 minidsp-shd dbus-daemon[442]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.22' (uid=0 pid=1227 comm="/usr/lib/rtkit/rtkit-daemon ") May 11 13:44:33 minidsp-shd rtkit-daemon[1227]: Canary thread running. May 11 13:44:33 minidsp-shd systemd[1]: Starting Authorization Manager... May 11 13:44:33 minidsp-shd volumio[788]: info: Executing endpoint restartRAATSocket May 11 13:44:33 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection May 11 13:44:33 minidsp-shd polkitd[1230]: started daemon version 0.105 using authority implementation `local' version `0.105' May 11 13:44:33 minidsp-shd volumio[788]: info: MRS: Found cast device: Google-Home-Mini-3264f4da418302b5edda976495bb7848 May 11 13:44:33 minidsp-shd dbus-daemon[442]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' May 11 13:44:33 minidsp-shd volumio[788]: info: Adding audio output: May 11 13:44:33 minidsp-shd systemd[1]: Started Authorization Manager. May 11 13:44:33 minidsp-shd volumio[788]: ------------------------------------ BT MESSAGE: BT STATUS: running May 11 13:44:34 minidsp-shd volumio[788]: ------------------------------------ BT MESSAGE: BT STATUS: running May 11 13:44:34 minidsp-shd volumio[788]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 May 11 13:44:34 minidsp-shd volumio[788]: info: MRS: Found cast device: Google-Home-Mini-4974f21e20b254dda0902b919fb29f1b May 11 13:44:34 minidsp-shd volumio[788]: info: Adding audio output: May 11 13:44:34 minidsp-shd volumio[788]: error: updateQueue error: null May 11 13:44:34 minidsp-shd volumio[788]: info: CoreCommandRouter::volumioGetState May 11 13:44:34 minidsp-shd volumio[788]: info: CorePlayQueue::getTrack 0 May 11 13:44:34 minidsp-shd volumio[788]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 11 13:44:34 minidsp-shd volumio[788]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect May 11 13:44:34 minidsp-shd sudo[1242]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 11 13:44:34 minidsp-shd sudo[1242]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 13:44:34 minidsp-shd systemd[1]: Started Volumio Tidal Connect Service. May 11 13:44:34 minidsp-shd sudo[1242]: pam_unix(sudo:session): session closed for user root May 11 13:44:34 minidsp-shd volumio[788]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 May 11 13:44:34 minidsp-shd pulseaudio[1226]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 May 11 13:44:34 minidsp-shd pulseaudio[1226]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 May 11 13:44:34 minidsp-shd volumiobt[1182]: Applying permissions May 11 13:44:34 minidsp-shd volumiobt[1182]: Setting BT discoverable and pairable May 11 13:44:34 minidsp-shd pulseaudio[1226]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files May 11 13:44:34 minidsp-shd volumio[788]: [28B blob data] May 11 13:44:34 minidsp-shd volumio[788]: info: Serial Data: PUSH MUTE FALSE May 11 13:44:34 minidsp-shd volumio[788]: info: msSurfaceDial volumioupdatevolume callback: {"vol":74,"dbVolume":-33.5,"mute":false,"disableVolumeControl":false} May 11 13:44:34 minidsp-shd volumio[788]: info: CoreStateMachine::pushState May 11 13:44:34 minidsp-shd volumio[788]: info: CorePlayQueue::getTrack 0 May 11 13:44:34 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 13:44:34 minidsp-shd volumio[788]: info: CoreCommandRouter::volumioPushState May 11 13:44:34 minidsp-shd volumio[788]: info: MRS: Pushing multiroomSync output update for this device May 11 13:44:34 minidsp-shd volumio[788]: info: MRS: Pushing multiroomSync output May 11 13:44:34 minidsp-shd volumiobt[1182]: [38B blob data] May 11 13:44:34 minidsp-shd volumiobt[1182]: Invalid command May 11 13:44:34 minidsp-shd volumiobt[1182]: [bluetooth]# agent on May 11 13:44:34 minidsp-shd volumiobt[1182]: [bluetooth]# discoverable on May 11 13:44:34 minidsp-shd volumiobt[1182]: No default controller available May 11 13:44:34 minidsp-shd volumiobt[1182]: [bluetooth]# pairable on May 11 13:44:34 minidsp-shd volumiobt[1182]: No default controller available May 11 13:44:34 minidsp-shd volumio[788]: error: Help! Some callbacks for volumioPushState are crashing! May 11 13:44:34 minidsp-shd volumio[788]: error: Cannot read property 'sendVolumeMute' of undefined May 11 13:44:34 minidsp-shd volumiobt[1182]: [bluetooth]# agent NoInputNoOutput May 11 13:44:34 minidsp-shd volumiobt[1182]: Failed to register agent object May 11 13:44:34 minidsp-shd volumiobt[1182]: [bluetooth]# default-agent May 11 13:44:34 minidsp-shd volumiobt[1182]: No agent is registered May 11 13:44:34 minidsp-shd volumiobt[1182]: [bluetooth]# quit May 11 13:44:34 minidsp-shd volumiobt[1182]: [61B blob data] May 11 13:44:34 minidsp-shd volumiobt[1182]: [62B blob data] May 11 13:44:35 minidsp-shd volumio[788]: info: MRS: Found cast device: Chromecast-HD-031bed75f5f202f8673ddf5a886e4713 May 11 13:44:35 minidsp-shd volumio[788]: info: Adding audio output: May 11 13:44:35 minidsp-shd volumio[788]: info: go-librespot daemon successfully initialized May 11 13:44:35 minidsp-shd volumio[788]: info: MRS: Found cast device: Google-Nest-Mini-1db8f5ac5dfc13b07c6fece18a9a6f28 May 11 13:44:35 minidsp-shd volumio[788]: info: Adding audio output: May 11 13:44:35 minidsp-shd volumio[1101]: Generating RSA private key, 4096 bit long modulus (2 primes) May 11 13:44:35 minidsp-shd volumio[788]: info: MRS: Getting audio outputs on start May 11 13:44:35 minidsp-shd volumio[788]: info: MRS: Requesting all other devices output May 11 13:44:35 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:35+02:00" level=debug msg="obtained new client token: AABm29Y8KTcg1OYs91KKLR+8zqPXgoddQu6+Pmy5tFKVk1cGdvVMXb/den6h7SLdUyiHDgrnq6eX/f1SbhGJun5re5ajxuz7aMSiQ4Po1GvTQKwwTc9E8nsjzbTyT3DoOw59isA/KZhjPJhQK/GEI/17Y+ky0kwYaIuF4LFuTjk7Mss7waEGHtr2VOQdW1+DsQD5nUzVnSEah/WgSAlWQSAl1jZL0p3tkuyLaUUcd2kzBxAjpKRYTrfPQFN00w==" May 11 13:44:35 minidsp-shd volumio[788]: info: Executing endpoint tc_getconfig May 11 13:44:35 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 11 13:44:35 minidsp-shd vtcs[1245]: STARTING TidalConnect services, version: 1.3.0.19 May 11 13:44:35 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:35+02:00" level=debug msg="completed keyexchange" May 11 13:44:35 minidsp-shd volumio[788]: [28B blob data] May 11 13:44:35 minidsp-shd volumio[788]: info: Serial Data: PUSH MVOL 188 May 11 13:44:35 minidsp-shd volumio[788]: info: msSurfaceDial volumioupdatevolume callback: {"vol":74,"dbVolume":-33.5,"mute":false,"disableVolumeControl":false} May 11 13:44:35 minidsp-shd volumio[788]: info: CoreStateMachine::pushState May 11 13:44:35 minidsp-shd volumio[788]: info: CorePlayQueue::getTrack 0 May 11 13:44:35 minidsp-shd volumio[788]: info: CoreCommandRouter::volumioPushState May 11 13:44:35 minidsp-shd volumio[788]: info: MRS: Pushing multiroomSync output update for this device May 11 13:44:35 minidsp-shd volumio[788]: info: MRS: Pushing multiroomSync output May 11 13:44:35 minidsp-shd volumio[788]: error: Help! Some callbacks for volumioPushState are crashing! May 11 13:44:35 minidsp-shd volumio[788]: error: Cannot read property 'sendVolumeMute' of undefined May 11 13:44:35 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume May 11 13:44:35 minidsp-shd vtcs[1245]: STARTED TidalConnect services. May 11 13:44:35 minidsp-shd volumio[788]: info: Executing endpoint tc_connect May 11 13:44:35 minidsp-shd volumio[788]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect May 11 13:44:35 minidsp-shd volumio[788]: info: Connecting to TidalConnect May 11 13:44:35 minidsp-shd volumio[788]: info: CoreCommandRouter::servicePushState May 11 13:44:35 minidsp-shd volumio[788]: info: CoreStateMachine::pushState May 11 13:44:35 minidsp-shd volumio[788]: info: CorePlayQueue::getTrack 0 May 11 13:44:35 minidsp-shd volumio[788]: info: CoreCommandRouter::volumioPushState May 11 13:44:35 minidsp-shd volumio[788]: info: MRS: Pushing multiroomSync output update for this device May 11 13:44:35 minidsp-shd volumio[788]: info: MRS: Pushing multiroomSync output May 11 13:44:35 minidsp-shd volumio[788]: info: CorePlayQueue::getTrack 0 May 11 13:44:35 minidsp-shd volumio[788]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect May 11 13:44:35 minidsp-shd volumio[788]: info: CoreCommandRouter::servicePushState May 11 13:44:35 minidsp-shd volumio[788]: info: CoreStateMachine::pushState May 11 13:44:35 minidsp-shd volumio[788]: info: CorePlayQueue::getTrack 0 May 11 13:44:35 minidsp-shd volumio[788]: info: CoreCommandRouter::volumioPushState May 11 13:44:35 minidsp-shd volumio[788]: info: MRS: Pushing multiroomSync output update for this device May 11 13:44:35 minidsp-shd volumio[788]: info: MRS: Pushing multiroomSync output May 11 13:44:35 minidsp-shd volumio[788]: info: CorePlayQueue::getTrack 0 May 11 13:44:35 minidsp-shd volumio[788]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect May 11 13:44:36 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:36+02:00" level=debug msg="completed challenge" May 11 13:44:36 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:36+02:00" level=debug msg="authenticated as emilin88" May 11 13:44:36 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:36+02:00" level=debug msg="authenticated as emilin88" May 11 13:44:36 minidsp-shd volumio[1101]: .................++++ May 11 13:44:36 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:36+02:00" level=debug msg="dealer connection opened" May 11 13:44:36 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:36+02:00" level=info msg="accepted zeroconf user emilin88 from SM-G991B" May 11 13:44:36 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:36+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 11 13:44:36 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:36+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 11 13:44:36 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:36+02:00" level=debug msg="received connection id: MTg5OTFmYjQtMjA4Zi00ZWE4LWExOGYtYzk0MDE0Y2M1NDkxK2RlYWxlcit0Y3A6Ly9nZXc0LWRlYWxlci1hLXBqN24uZ2V3NC5zcG90aWZ5Lm5ldDo1NzAwKzU4RkRGMkJERTEzNTQ3Mzk5NUUzQ0U5MjdENkQyNjhGMEQ5Q0MzNDA4QjA4NkQ0MTk1MzE2RkE0Njg1OUVCOTI=" May 11 13:44:36 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:36+02:00" level=debug msg="put connect state because NEW_DEVICE" May 11 13:44:36 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:36+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 11 13:44:36 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:36+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 11 13:44:36 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:36+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" May 11 13:44:36 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:36+02:00" level=debug msg="handling transfer player command from ef15f6de66f274953e56d840bed829543da9677c" May 11 13:44:36 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:36+02:00" level=debug msg="loading track spotify:track:6ZZA5LtiMyhmo4jU3oldOZ (paused: false, position: 86558ms)" May 11 13:44:37 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:37+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 11 13:44:37 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:37+02:00" level=trace msg="emitting websocket event: will_play" May 11 13:44:37 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:37+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" May 11 13:44:37 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:37+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:6ZZA5LtiMyhmo4jU3oldOZ" May 11 13:44:37 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:37+02:00" level=debug msg="requested aes key for file e21028976913d73eeac7298329926e783a33b0e4, gid: 6ZZA5LtiMyhmo4jU3oldOZ" May 11 13:44:37 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:37+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1549" May 11 13:44:37 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:37+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1327" May 11 13:44:37 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:37+02:00" level=debug msg="fetched first chunk of 21, total size is 10680204 bytes" May 11 13:44:37 minidsp-shd volumio-remote-updater[453]: [2024-05-11 13:44:37] [connect] Successful connection May 11 13:44:37 minidsp-shd volumio-remote-updater[453]: [2024-05-11 13:44:37] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1715427877 101 May 11 13:44:37 minidsp-shd volumio[788]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 4 May 11 13:44:37 minidsp-shd volumio[788]: info: TidalConnect service started! May 11 13:44:37 minidsp-shd volumio[788]: info: Completed starting Core Plugins May 11 13:44:37 minidsp-shd volumio[788]: info: ------------------------------------------- May 11 13:44:37 minidsp-shd volumio[788]: info: ----- MyVolumio plugins startup ---- May 11 13:44:37 minidsp-shd volumio[788]: info: ------------------------------------------- May 11 13:44:37 minidsp-shd volumio[788]: info: [MyVolumio PluginManager] Fetching plans data.... May 11 13:44:37 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:37+02:00" level=debug msg="fetched chunk 2/20, size: 524288" May 11 13:44:37 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:37+02:00" level=debug msg="fetched chunk 1/20, size: 524288" May 11 13:44:38 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:38+02:00" level=debug msg="fetched chunk 7/20, size: 524288" May 11 13:44:38 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:38+02:00" level=trace msg="seek to 86558ms (diff: 112ms, samples: 3817207, bytes: 3917806)" May 11 13:44:38 minidsp-shd go-librespot[1162]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:257:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 65536, but target_pcm volumioOutput has buffer size 4096 May 11 13:44:38 minidsp-shd go-librespot[1162]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:268:(_snd_pcm_volumioswitch_hw_params) PCM volumioMultiRoomServer has buffer size 65536, but target_pcm volumioOutput has buffer size 4096 May 11 13:44:38 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:38+02:00" level=info msg="loaded track \"Egoist\" (uri: spotify:track:6ZZA5LtiMyhmo4jU3oldOZ, paused: false, position: 86558ms, duration: 245586ms)" May 11 13:44:38 minidsp-shd volumio[788]: info: Initializing connection to go-librespot Websocket May 11 13:44:38 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:38+02:00" level=debug msg="fetched chunk 8/20, size: 524288" May 11 13:44:38 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:38+02:00" level=debug msg="new websocket client" May 11 13:44:38 minidsp-shd volumio[788]: info: Connection to go-librespot Websocket established May 11 13:44:38 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:38+02:00" level=debug msg="fetched chunk 3/20, size: 524288" May 11 13:44:38 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:38+02:00" level=debug msg="fetched chunk 10/20, size: 524288" May 11 13:44:38 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:38+02:00" level=debug msg="fetched chunk 9/20, size: 524288" May 11 13:44:38 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:38+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 11 13:44:38 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:38+02:00" level=trace msg="emitting websocket event: metadata" May 11 13:44:38 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:38+02:00" level=trace msg="emitting websocket event: active" May 11 13:44:38 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:38+02:00" level=debug msg="sending successful reply for delaer request" May 11 13:44:38 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:38+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 11 13:44:38 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:38+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 11 13:44:38 minidsp-shd volumio[788]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6ZZA5LtiMyhmo4jU3oldOZ","name":"Egoist","artist_names":["kent"],"album_name":"Egoist","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02b856803795d4e9a43d1b61e8","position":86558,"duration":245586}} May 11 13:44:38 minidsp-shd volumio[788]: SPOTIFY: received: {"type":"active","data":null} May 11 13:44:38 minidsp-shd volumio[788]: info: Aligning Spotify Volume to Volumio Volume May 11 13:44:38 minidsp-shd volumio[788]: info: CoreCommandRouter::volumioGetState May 11 13:44:38 minidsp-shd volumio[788]: info: CorePlayQueue::getTrack 0 May 11 13:44:38 minidsp-shd volumio[788]: info: Setting Spotify Volume from Volumio: 74 May 11 13:44:38 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:38+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 11 13:44:38 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:38+02:00" level=trace msg="emitting websocket event: playing" May 11 13:44:38 minidsp-shd go-librespot[1162]: time="2024-05-11T13:44:38+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 11 13:44:38 minidsp-shd volumio[788]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6ZZA5LtiMyhmo4jU3oldOZ","play_origin":"playlist"}} May 11 13:44:38 minidsp-shd volumio[788]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 11 13:44:38 minidsp-shd volumio[788]: TypeError: Cannot read property 'service' of undefined May 11 13:44:38 minidsp-shd volumio[788]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:322:50) May 11 13:44:38 minidsp-shd volumio[788]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:248:18) May 11 13:44:38 minidsp-shd volumio[788]: at WebSocket.message (/data/plugins/music_service/spop/index.js:175:14) May 11 13:44:38 minidsp-shd volumio[788]: at WebSocket.emit (events.js:400:28) May 11 13:44:38 minidsp-shd volumio[788]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1192:20) May 11 13:44:38 minidsp-shd volumio[788]: at Receiver.emit (events.js:400:28) May 11 13:44:38 minidsp-shd volumio[788]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:560:14) May 11 13:44:38 minidsp-shd volumio[788]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:478:17) May 11 13:44:38 minidsp-shd volumio[788]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:22) May 11 13:44:38 minidsp-shd volumio[788]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:180:18 May 11 13:44:38 minidsp-shd volumio[788]: at internal/process/task_queues.js:141:7 May 11 13:44:38 minidsp-shd volumio[788]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) May 11 13:44:38 minidsp-shd volumio[788]: at AsyncResource.runMicrotask (internal/process/task_queues.js:138:8) May 11 13:44:38 minidsp-shd volumio[788]: at processTicksAndRejections (internal/process/task_queues.js:95:5) May 11 13:44:38 minidsp-shd volumio[788]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 11 13:44:39 minidsp-shd sudo[1292]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-11 13:43 May 11 13:44:39 minidsp-shd sudo[1292]: 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="7e5bc423b057039c2496981dbecdd0b660d33233" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="04e9a9e8b062662f28de34cf850e35e627a06ce0" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 25 Oct 2023 02:37:14 PM CEST" VOLUMIO_VERSION="3.571" VOLUMIO_HARDWARE="nanopineo3" VOLUMIO_DEVICENAME="Nanopi Neo3" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="2287b8b3b1254bad4697c09494cc2ac1"