-- Logs begin at Sat 2023-12-23 03:15:59 AEDT, end at Sat 2024-08-31 12:43:49 AEST. -- Aug 31 12:43:00 minidsp-shd ntpd[774]: receive: Unexpected origin timestamp 0xe93034d7.d031bbd5 does not match aorg 0000000000.00000000 from server@112.213.32.219 xmt 0xea7d01b4.2dfdd1d1 Aug 31 12:43:00 minidsp-shd ntpd[774]: receive: Unexpected origin timestamp 0xe93034d7.d06cd221 does not match aorg 0000000000.00000000 from server@27.124.125.251 xmt 0xea7d01b4.2e2e935a Aug 31 12:43:00 minidsp-shd ntpd[774]: receive: Unexpected origin timestamp 0xe93034d7.d0783679 does not match aorg 0000000000.00000000 from server@220.158.215.20 xmt 0xea7d01b4.2de0a817 Aug 31 12:43:00 minidsp-shd ntpd[774]: receive: Unexpected origin timestamp 0xe93034d7.d049bdb1 does not match aorg 0000000000.00000000 from server@159.196.3.239 xmt 0xea7d01b4.2f812f76 Aug 31 12:43:00 minidsp-shd systemd[1]: Starting Daily apt download activities... Aug 31 12:43:00 minidsp-shd ntpd[774]: receive: Unexpected origin timestamp 0xe93034d7.d07412d6 does not match aorg 0000000000.00000000 from server@129.250.35.250 xmt 0xea7d01b4.3fa84009 Aug 31 12:43:00 minidsp-shd ntpd[774]: receive: Unexpected origin timestamp 0xe93034d7.d05fed49 does not match aorg 0000000000.00000000 from server@27.124.125.252 xmt 0xea7d01b4.519a1591 Aug 31 12:43:01 minidsp-shd volumio[789]: info: Loading plugin "network"... Aug 31 12:43:01 minidsp-shd volumio[789]: info: Refreshing Cached IP Addresses Aug 31 12:43:01 minidsp-shd sudo[858]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 12:43:01 minidsp-shd sudo[858]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:01 minidsp-shd sudo[858]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:01 minidsp-shd volumio[789]: info: Loading plugin "services"... Aug 31 12:43:01 minidsp-shd sudo[861]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 12:43:01 minidsp-shd sudo[861]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:01 minidsp-shd volumio[789]: info: Loading plugin "alsa_controller"... Aug 31 12:43:01 minidsp-shd sudo[861]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:01 minidsp-shd sudo[865]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 31 12:43:01 minidsp-shd sudo[865]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:01 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 12:43:01 minidsp-shd volumio[789]: info: Loading plugin "wizard"... Aug 31 12:43:01 minidsp-shd volumio[789]: info: Loading plugin "volumio_command_line_client"... Aug 31 12:43:01 minidsp-shd volumio[789]: info: Loading plugin "upnp"... Aug 31 12:43:01 minidsp-shd volumio[789]: info: [1725072181527] Starting Upmpd Daemon Aug 31 12:43:01 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 12:43:01 minidsp-shd volumio[789]: info: Loading plugin "my_music"... Aug 31 12:43:01 minidsp-shd volumio[789]: info: Loading plugin "mpd"... Aug 31 12:43:01 minidsp-shd systemd[1]: apt-daily.service: Succeeded. Aug 31 12:43:01 minidsp-shd systemd[1]: Started Daily apt download activities. Aug 31 12:43:01 minidsp-shd systemd[1]: Starting Daily apt upgrade and clean activities... Aug 31 12:43:01 minidsp-shd volumio-remote-updater[453]: [2024-08-31 12:43:01] [connect] Successful connection Aug 31 12:43:02 minidsp-shd volumio[789]: info: Creating MPD Configuration file Aug 31 12:43:02 minidsp-shd volumio[789]: info: Loading plugin "upnp_browser"... Aug 31 12:43:02 minidsp-shd sudo[920]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 12:43:02 minidsp-shd sudo[920]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:02 minidsp-shd sudo[920]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:02 minidsp-shd sudo[923]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 12:43:02 minidsp-shd sudo[923]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:02 minidsp-shd systemd[1]: Stopping Music Player Daemon... Aug 31 12:43:02 minidsp-shd systemd[1]: mpd.service: Succeeded. Aug 31 12:43:02 minidsp-shd systemd[1]: Stopped Music Player Daemon. Aug 31 12:43:02 minidsp-shd systemd[1]: Starting Music Player Daemon... Aug 31 12:43:02 minidsp-shd systemd[1]: apt-daily-upgrade.service: Succeeded. Aug 31 12:43:02 minidsp-shd systemd[1]: Started Daily apt upgrade and clean activities. Aug 31 12:43:03 minidsp-shd volumio[789]: info: Loading plugin "networkfs"... Aug 31 12:43:04 minidsp-shd volumio[789]: info: Starting Udev Watcher for removable devices Aug 31 12:43:04 minidsp-shd sudo[944]: 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.1.15/Media/Music /mnt/NAS/TrueNAS Aug 31 12:43:04 minidsp-shd sudo[944]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:04 minidsp-shd kernel: FS-Cache: Loaded Aug 31 12:43:04 minidsp-shd kernel: FS-Cache: Netfs 'cifs' registered for caching Aug 31 12:43:04 minidsp-shd kernel: Key type cifs.spnego registered Aug 31 12:43:04 minidsp-shd kernel: Key type cifs.idmap registered Aug 31 12:43:04 minidsp-shd kernel: CIFS: Attempting to mount //192.168.1.15/Media/Music Aug 31 12:43:04 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. Aug 31 12:43:04 minidsp-shd kernel: CIFS VFS: \\192.168.1.15 failed to connect to IPC (rc=-13) Aug 31 12:43:04 minidsp-shd kernel: CIFS VFS: cifs_mount failed w/return code = -13 Aug 31 12:43:04 minidsp-shd sudo[944]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:04 minidsp-shd volumio[789]: info: Ignoring mount for partition: BOOT Aug 31 12:43:04 minidsp-shd volumio[789]: info: Ignoring mount for partition: volumio Aug 31 12:43:04 minidsp-shd volumio[789]: info: Ignoring mount for partition: volumio_data Aug 31 12:43:04 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 12:43:04 minidsp-shd volumio[789]: info: Loading plugin "bluetooth"... Aug 31 12:43:05 minidsp-shd sudo[865]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:05 minidsp-shd volumio[789]: info: [1725072185441] Starting BluetoothController Aug 31 12:43:05 minidsp-shd volumio[789]: info: Loading plugin "alarm-clock"... Aug 31 12:43:06 minidsp-shd volumio[789]: info: Loading plugin "manifestui"... Aug 31 12:43:06 minidsp-shd mpd[941]: Aug 31 12:43 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 12:43:06 minidsp-shd mpd[941]: Aug 31 12:43 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Aug 31 12:43:06 minidsp-shd mpd[941]: Aug 31 12:43 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Aug 31 12:43:06 minidsp-shd volumio[789]: info: Loading plugin "metavolumio"... Aug 31 12:43:06 minidsp-shd systemd[1]: Started Music Player Daemon. Aug 31 12:43:06 minidsp-shd sudo[923]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:07 minidsp-shd systemd[1]: systemd-fsckd.service: Succeeded. Aug 31 12:43:08 minidsp-shd sh[381]: timed out Aug 31 12:43:08 minidsp-shd sh[381]: dhcpcd exited Aug 31 12:43:08 minidsp-shd dhcpcd[402]: timed out Aug 31 12:43:08 minidsp-shd sh[381]: ifup: failed to bring up eth0 Aug 31 12:43:08 minidsp-shd dhcpcd[402]: dhcpcd exited Aug 31 12:43:08 minidsp-shd systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Aug 31 12:43:08 minidsp-shd systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Aug 31 12:43:08 minidsp-shd volumio[789]: info: Loading plugin "airplay_emulation"... Aug 31 12:43:08 minidsp-shd volumio[789]: info: Starting Shairport Sync Aug 31 12:43:08 minidsp-shd volumio[789]: info: Loading plugin "cd_controller"... Aug 31 12:43:09 minidsp-shd volumio[789]: info: Loading plugin "last_100"... Aug 31 12:43:09 minidsp-shd volumio[789]: info: Loading plugin "raat"... Aug 31 12:43:09 minidsp-shd volumio[789]: info: RAAT Plugin loaded Aug 31 12:43:09 minidsp-shd volumio[789]: info: Adding restartRAATSocket REST API Endpoint Aug 31 12:43:09 minidsp-shd volumio[789]: info: Adding restartRAATSocket REST Endpoint for plugin: music_service/raat Aug 31 12:43:09 minidsp-shd volumio[789]: info: Loading plugin "streaming_services"... Aug 31 12:43:12 minidsp-shd volumio[789]: info: Starting Streaming Service Transparent Proxy Aug 31 12:43:12 minidsp-shd volumio[789]: info: Loading plugin "tidalconnect"... Aug 31 12:43:12 minidsp-shd volumio[789]: info: Loading plugin "webradio"... Aug 31 12:43:13 minidsp-shd volumio[789]: info: Loading plugin "i2s_dacs"... Aug 31 12:43:13 minidsp-shd volumio[789]: info: I2S DAC not set, start Auto-detection Aug 31 12:43:13 minidsp-shd volumio[789]: info: Loading plugin "volumiodiscovery"... Aug 31 12:43:13 minidsp-shd volumio[789]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 12:43:13 minidsp-shd node[789]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 31 12:43:13 minidsp-shd node[789]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 12:43:13 minidsp-shd volumio[789]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 12:43:13 minidsp-shd volumio[789]: *** WARNING *** For more information see Aug 31 12:43:13 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. Aug 31 12:43:13 minidsp-shd volumio[789]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 12:43:13 minidsp-shd volumio[789]: *** WARNING *** For more information see Aug 31 12:43:13 minidsp-shd node[789]: *** WARNING *** For more information see Aug 31 12:43:13 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. Aug 31 12:43:13 minidsp-shd node[789]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 31 12:43:13 minidsp-shd node[789]: *** WARNING *** For more information see Aug 31 12:43:13 minidsp-shd volumio[789]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 31 12:43:13 minidsp-shd volumio[789]: info: Discovery: Started advertising with name: miniDSP SHD Aug 31 12:43:13 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 12:43:13 minidsp-shd volumio[789]: info: Loading plugin "spop"... Aug 31 12:43:14 minidsp-shd volumio[789]: STREAMING PROXY: Starting server on port 3245 Aug 31 12:43:14 minidsp-shd volumio[789]: Node JS runtime: 14 Aug 31 12:43:16 minidsp-shd volumio[789]: info: Loading plugin "ytmusic"... Aug 31 12:43:16 minidsp-shd volumio-remote-updater[453]: [2024-08-31 12:43:16] [connect] Successful connection Aug 31 12:43:18 minidsp-shd volumio[789]: info: Loading plugin "multiroom"... Aug 31 12:43:21 minidsp-shd volumio[789]: info: Applying required configuration parameters for plugin multiroom Aug 31 12:43:21 minidsp-shd sudo[986]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod +x /volumio/app/plugins/audio_interface/multiroom/scripts/check_snapcast Aug 31 12:43:21 minidsp-shd sudo[986]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:21 minidsp-shd sudo[986]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:21 minidsp-shd sudo[988]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Aug 31 12:43:21 minidsp-shd sudo[988]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:21 minidsp-shd sudo[988]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:21 minidsp-shd volumio[789]: info: MRS: MultiRoom plugin initialized Aug 31 12:43:21 minidsp-shd volumio[789]: info: MRS: STOPPING SNAPCLIENT Aug 31 12:43:21 minidsp-shd volumio[789]: info: MRS: Snap server stop Aug 31 12:43:21 minidsp-shd sudo[1006]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Aug 31 12:43:21 minidsp-shd sudo[1006]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:21 minidsp-shd volumio[789]: info: MRS: STOPPING volumioStreaming Aug 31 12:43:21 minidsp-shd sudo[1008]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Aug 31 12:43:21 minidsp-shd sudo[1008]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:21 minidsp-shd sudo[1006]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:21 minidsp-shd sudo[1011]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Aug 31 12:43:21 minidsp-shd sudo[1011]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:21 minidsp-shd volumio[789]: info: Loading plugin "outputs"... Aug 31 12:43:21 minidsp-shd sudo[1014]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Aug 31 12:43:21 minidsp-shd sudo[1014]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:21 minidsp-shd volumio[789]: info: Loading plugin "albumart"... Aug 31 12:43:21 minidsp-shd sudo[1014]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:21 minidsp-shd sudo[1008]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:21 minidsp-shd sudo[1011]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:21 minidsp-shd volumio[789]: info: Loading plugin "ms_surface_dial"... Aug 31 12:43:22 minidsp-shd volumio[789]: Forking 3 albumart workers Aug 31 12:43:22 minidsp-shd volumio[789]: info: Applying required configuration parameters for plugin ms_surface_dial Aug 31 12:43:22 minidsp-shd volumio[789]: info: Plugin example_plugin is not enabled Aug 31 12:43:22 minidsp-shd volumio[789]: info: Loading plugin "hi_res_audio"... Aug 31 12:43:24 minidsp-shd volumio[789]: Starting albumart workers Aug 31 12:43:24 minidsp-shd volumio[789]: Starting albumart workers Aug 31 12:43:24 minidsp-shd volumio[789]: Starting albumart workers Aug 31 12:43:26 minidsp-shd volumio[789]: info: Applying required configuration parameters for plugin hi_res_audio Aug 31 12:43:26 minidsp-shd volumio[789]: info: Loading plugin "inputs"... Aug 31 12:43:27 minidsp-shd volumio[789]: info: Loading plugin "qobuz"... Aug 31 12:43:30 minidsp-shd volumio[789]: info: Loading plugin "tidal"... Aug 31 12:43:31 minidsp-shd volumio-remote-updater[453]: [2024-08-31 12:43:31] [connect] Successful connection Aug 31 12:43:32 minidsp-shd volumio[789]: info: Loading plugin "oem_helper"... Aug 31 12:43:34 minidsp-shd volumio[789]: info: Applying required configuration parameters for plugin oem_helper Aug 31 12:43:34 minidsp-shd volumio[789]: info: Loading plugin "updater_comm"... Aug 31 12:43:34 minidsp-shd volumio[789]: info: Plugin mpdemulation is not enabled Aug 31 12:43:34 minidsp-shd volumio[789]: info: Loading plugin "rest_api"... Aug 31 12:43:34 minidsp-shd volumio[789]: info: Loading plugin "websocket"... Aug 31 12:43:34 minidsp-shd volumio[789]: info: Loading i18n strings for locale en Aug 31 12:43:34 minidsp-shd volumio[789]: Updating browse sources language Aug 31 12:43:34 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreCommandRouter::initPlayerControls Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 12:43:35 minidsp-shd volumio[789]: Express server listening on port 3000 Aug 31 12:43:35 minidsp-shd volumio[789]: [Metrics] WebUI: 40s 476.55ms Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreStateMachine::resetVolumioState Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreStateMachine::getcurrentVolume Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioRetrievevolume Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Aug 31 12:43:35 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 12:43:35 minidsp-shd sudo[1073]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 12:43:35 minidsp-shd sudo[1073]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: inputs , getVolume Aug 31 12:43:35 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: inputs , getDSP Aug 31 12:43:35 minidsp-shd sudo[1073]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:35 minidsp-shd sudo[1075]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 12:43:35 minidsp-shd sudo[1075]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:35 minidsp-shd sudo[1075]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:35 minidsp-shd volumio[789]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Aug 31 12:43:35 minidsp-shd volumio[789]: info: Completed loading Core Plugins Aug 31 12:43:35 minidsp-shd volumio[789]: info: Preparing to generate the ALSA configuration file Aug 31 12:43:35 minidsp-shd volumio[789]: info: Cannot read play queue from file Aug 31 12:43:35 minidsp-shd volumio[789]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Hardware Aug 31 12:43:35 minidsp-shd volumio[789]: info: MRS: Removed streaming files Aug 31 12:43:35 minidsp-shd volumio[789]: info: MRS: volumioStreaming STOPPED Aug 31 12:43:35 minidsp-shd volumio[789]: info: MRS: SNAPSERVER STOPPED Aug 31 12:43:35 minidsp-shd volumio[789]: info: MRS: SNAPCLIENT STOPPED Aug 31 12:43:35 minidsp-shd volumio[789]: info: Snap server and client installed Aug 31 12:43:35 minidsp-shd volumio[789]: info: Cannot mount NAS TrueNAS at system boot, trial number 1 ,retrying in 5 seconds Aug 31 12:43:35 minidsp-shd volumio[789]: info: MPD Permissions set Aug 31 12:43:35 minidsp-shd volumio[789]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Aug 31 12:43:35 minidsp-shd volumio[789]: info: Reading ALSA contributions from plugins. Aug 31 12:43:36 minidsp-shd volumio-remote-updater[453]: [2024-08-31 12:43:36] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1725072211 101 Aug 31 12:43:36 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: 1 Aug 31 12:43:36 minidsp-shd volumio[789]: info: MPD running with PID941 Aug 31 12:43:36 minidsp-shd volumio[789]: ,establishing connection Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:36 minidsp-shd volumio[789]: error: updateQueue error: null Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreStateMachine::setRepeat null single undefined Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Aug 31 12:43:36 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreStateMachine::setRandom null Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Aug 31 12:43:36 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Aug 31 12:43:36 minidsp-shd volumio[789]: error: updateQueue error: null Aug 31 12:43:36 minidsp-shd volumio[789]: info: Asound.conf file unchanged, so no further update is needed Aug 31 12:43:36 minidsp-shd volumio[789]: info: Output device has changed, restarting MPD Aug 31 12:43:36 minidsp-shd sudo[1092]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 31 12:43:36 minidsp-shd sudo[1092]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:36 minidsp-shd systemd[1]: Started UPnP Renderer front-end to MPD. Aug 31 12:43:36 minidsp-shd sudo[1095]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 31 12:43:36 minidsp-shd sudo[1095]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:36 minidsp-shd volumio[789]: info: Output device has changed, restarting Shairport Sync Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 12:43:36 minidsp-shd sudo[1095]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:36 minidsp-shd sudo[1092]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:36 minidsp-shd sudo[1099]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 31 12:43:36 minidsp-shd sudo[1099]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:36 minidsp-shd systemd[1]: Stopping Music Player Daemon... Aug 31 12:43:36 minidsp-shd volumio[789]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 12:43:36 minidsp-shd systemd[1]: mpd.service: Succeeded. Aug 31 12:43:36 minidsp-shd volumio[789]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Aug 31 12:43:36 minidsp-shd systemd[1]: Stopped Music Player Daemon. Aug 31 12:43:36 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:36 minidsp-shd systemd[1]: Starting Music Player Daemon... Aug 31 12:43:37 minidsp-shd volumio[789]: info: ___________ START PLUGINS ___________ Aug 31 12:43:37 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 12:43:37 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 12:43:37 minidsp-shd volumio[789]: info: [1725072217064] CoreMusicLibrary::Adding element Media Servers Aug 31 12:43:37 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 12:43:37 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 31 12:43:37 minidsp-shd volumio[789]: info: Adding Manifest REST API Endpoints Aug 31 12:43:37 minidsp-shd volumio[789]: info: Adding manifestui REST Endpoint for plugin: miscellanea/manifestui Aug 31 12:43:37 minidsp-shd volumio[789]: info: Adding METAVOLUMIO REST API Endpoints Aug 31 12:43:37 minidsp-shd volumio[789]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Aug 31 12:43:37 minidsp-shd volumio[789]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Aug 31 12:43:37 minidsp-shd volumio[789]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Aug 31 12:43:37 minidsp-shd volumio[789]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Aug 31 12:43:37 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:37 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 12:43:37 minidsp-shd sudo[1109]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name miniDSP SHD Aug 31 12:43:37 minidsp-shd sudo[1109]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:37 minidsp-shd sudo[1109]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:37 minidsp-shd volumio[789]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 12:43:37 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:37 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 12:43:37 minidsp-shd volumio[789]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 31 12:43:37 minidsp-shd volumio[789]: info: Preparing CD Folders Aug 31 12:43:37 minidsp-shd volumio[789]: info: Adding CD REST API Endpoints Aug 31 12:43:37 minidsp-shd volumio[789]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Aug 31 12:43:37 minidsp-shd volumio[789]: info: Starting UDEV Watcher for CD Aug 31 12:43:37 minidsp-shd volumio[789]: info: Detecting CD presence with UDEV Aug 31 12:43:37 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Aug 31 12:43:37 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 12:43:37 minidsp-shd volumio[789]: info: [1725072217907] CoreMusicLibrary::Adding element Last_100 Aug 31 12:43:37 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 12:43:37 minidsp-shd volumio[789]: info: Starting RAAT Plugin Aug 31 12:43:37 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Aug 31 12:43:37 minidsp-shd volumio[789]: info: Additional UI Settings Added for plugin music_service/raat Aug 31 12:43:37 minidsp-shd volumio[789]: info: Streaming services startup Aug 31 12:43:37 minidsp-shd volumio[789]: info: Starting Streaming Daemon Aug 31 12:43:38 minidsp-shd sudo[1121]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 31 12:43:38 minidsp-shd sudo[1121]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:38 minidsp-shd sudo[1121]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:38 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 12:43:38 minidsp-shd volumio[789]: info: [1725072218158] CoreMusicLibrary::Adding element Webradio Aug 31 12:43:38 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 12:43:38 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 12:43:38 minidsp-shd sudo[1128]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Aug 31 12:43:38 minidsp-shd sudo[1128]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:38 minidsp-shd volumio[789]: info: Creating Spotify config file Aug 31 12:43:38 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:38 minidsp-shd sudo[1128]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:38 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Aug 31 12:43:38 minidsp-shd volumio[789]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Aug 31 12:43:38 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:38 minidsp-shd dbus-daemon[470]: [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 ") Aug 31 12:43:38 minidsp-shd volumio[789]: error: Hi Res Audio Failed Login: Missing Login Data Aug 31 12:43:38 minidsp-shd volumio[789]: info: Adding HIGHRESAUDIO REST API Endpoints Aug 31 12:43:38 minidsp-shd volumio[789]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Aug 31 12:43:38 minidsp-shd systemd[1]: Starting Bluetooth service... Aug 31 12:43:38 minidsp-shd bluetoothd[1134]: Bluetooth daemon 5.23 Aug 31 12:43:38 minidsp-shd dbus-daemon[470]: [system] Successfully activated service 'org.bluez' Aug 31 12:43:38 minidsp-shd systemd[1]: Started Bluetooth service. Aug 31 12:43:38 minidsp-shd bluetoothd[1134]: Starting SDP server Aug 31 12:43:38 minidsp-shd bluetoothd[1134]: kernel lacks bnep-protocol support Aug 31 12:43:38 minidsp-shd bluetoothd[1134]: System does not support network plugin Aug 31 12:43:38 minidsp-shd bluetoothd[1134]: Bluetooth management interface 1.14 initialized Aug 31 12:43:38 minidsp-shd dbus-daemon[470]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.11' (uid=0 pid=1134 comm="/usr/local/libexec/bluetooth/bluetoothd ") Aug 31 12:43:38 minidsp-shd systemd[1]: Starting Hostname Service... Aug 31 12:43:38 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 12:43:38 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 12:43:38 minidsp-shd volumio[789]: info: Volumio Calling Home Aug 31 12:43:39 minidsp-shd dbus-daemon[470]: [system] Successfully activated service 'org.freedesktop.hostname1' Aug 31 12:43:39 minidsp-shd systemd[1]: Started Hostname Service. Aug 31 12:43:39 minidsp-shd volumio[789]: info: Stopping AccessToken refresher cron for QOBUZ Aug 31 12:43:39 minidsp-shd volumio[789]: info: AccessToken refresher cron started for QOBUZ Aug 31 12:43:39 minidsp-shd volumio[789]: info: Stopping AccessToken refresher cron Aug 31 12:43:39 minidsp-shd volumio[789]: info: AccessToken refresher cron started Aug 31 12:43:39 minidsp-shd volumio[789]: info: Adding TIDAL REST API Endpoints Aug 31 12:43:39 minidsp-shd volumio[789]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Aug 31 12:43:39 minidsp-shd volumio[789]: info: Adding QOBUZ REST API Endpoints Aug 31 12:43:39 minidsp-shd volumio[789]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Aug 31 12:43:39 minidsp-shd volumio[789]: info: Discovery: adding 0a70e76f-34b3-4957-9d6b-2cbc7c12d50f Aug 31 12:43:39 minidsp-shd volumio[789]: info: Discovery: Found device miniDSP SHD Aug 31 12:43:39 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioGetState Aug 31 12:43:39 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:39 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output for this device Aug 31 12:43:39 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Aug 31 12:43:39 minidsp-shd volumio[789]: info: Adding audio output: Aug 31 12:43:39 minidsp-shd volumio[789]: info: Adding audio output: Aug 31 12:43:39 minidsp-shd volumio[789]: info: Serial port opened successfully Aug 31 12:43:39 minidsp-shd volumio[789]: error: Cannot start Volumio Streaming Daemon Aug 31 12:43:39 minidsp-shd volumio[789]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 31 12:43:39 minidsp-shd volumio[789]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 31 12:43:39 minidsp-shd volumio[789]: info: RAAT Albumart path created successfully Aug 31 12:43:39 minidsp-shd volumio[789]: error: Cannot set new Bluetooth Name : Error: Command failed: /usr/bin/sudo /bin/hciconfig hci0 name 'miniDSP SHD' Aug 31 12:43:39 minidsp-shd volumio[789]: Can't get device info: No such device Aug 31 12:43:39 minidsp-shd volumio[789]: info: MPD Permissions set Aug 31 12:43:39 minidsp-shd volumio[789]: info: Upmpdcli Daemon Started Aug 31 12:43:39 minidsp-shd volumio[789]: [28B blob data] Aug 31 12:43:39 minidsp-shd volumio[789]: info: Serial Data: PUSH MVOL 195 Aug 31 12:43:39 minidsp-shd volumio[789]: info: msSurfaceDial volumioupdatevolume callback: {"vol":76,"dbVolume":-30,"disableVolumeControl":false} Aug 31 12:43:39 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Aug 31 12:43:39 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:39 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 12:43:39 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Aug 31 12:43:39 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Aug 31 12:43:39 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Aug 31 12:43:39 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Aug 31 12:43:39 minidsp-shd volumio[789]: info: Ignoring ROON Volume update because of undefined data Aug 31 12:43:39 minidsp-shd volumio[789]: info: msSurfaceDial Managed Objs {"/org/bluez":{"org.freedesktop.DBus.Introspectable":{},"org.bluez.AgentManager1":{},"org.bluez.ProfileManager1":{}}} Aug 31 12:43:39 minidsp-shd volumio[789]: info: [msSurfaceDial init()] check /org/bluez Aug 31 12:43:39 minidsp-shd volumio[789]: info: [msSurfaceDial init()] Adapter: null; SurfaceDial: null Aug 31 12:43:39 minidsp-shd volumio[789]: info: msSurfaceDial BluetoothSurfaceDial init() - ready! Aug 31 12:43:39 minidsp-shd volumio[789]: info: CoreCommandRouter::Reload Ui Aug 31 12:43:39 minidsp-shd volumio[789]: info: Volumio called home Aug 31 12:43:39 minidsp-shd volumio[789]: info: Spotify config file written Aug 31 12:43:39 minidsp-shd volumio[789]: [27B blob data] Aug 31 12:43:39 minidsp-shd volumio[789]: info: Serial Data: PUSH DSP 0111111 Aug 31 12:43:39 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: raat , updateDSP Aug 31 12:43:39 minidsp-shd volumio[789]: info: updateDSP function in raat called! Aug 31 12:43:39 minidsp-shd volumio[789]: info: Updating RAAT Signal Path Aug 31 12:43:39 minidsp-shd volumio[789]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Aug 31 12:43:39 minidsp-shd volumio[789]: [29B blob data] Aug 31 12:43:39 minidsp-shd volumio[789]: info: Serial Data: PUSH MODEL 1 Aug 31 12:43:39 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: raat , reconfigureAndRestartRaat Aug 31 12:43:39 minidsp-shd volumio[789]: info: Reconfiguring and Restarting RAAT Plugin Aug 31 12:43:39 minidsp-shd sudo[1151]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 31 12:43:39 minidsp-shd sudo[1151]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:39 minidsp-shd systemd[1]: Started go-librespot Daemon. Aug 31 12:43:39 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:39 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:39 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:39 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:39 minidsp-shd sudo[1151]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:39 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 12:43:39 minidsp-shd go-librespot[1157]: Librespot-go daemon starting... Aug 31 12:43:39 minidsp-shd volumio[789]: info: Not Reporting Auto name since its the default one Aug 31 12:43:39 minidsp-shd volumio[789]: info: RAAT Overriding default device vendor model Aug 31 12:43:39 minidsp-shd volumio[789]: info: Adding MINIDSP Inputs Aug 31 12:43:39 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 12:43:39 minidsp-shd volumio[789]: info: [1725072219967] CoreMusicLibrary::Adding element Inputs Aug 31 12:43:39 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 12:43:39 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 12:43:39 minidsp-shd volumio[789]: info: [1725072219977] CoreMusicLibrary::Adding element Presets Aug 31 12:43:39 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 12:43:39 minidsp-shd volumio[789]: Cannot find translation for source Presets Aug 31 12:43:39 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. Aug 31 12:43:39 minidsp-shd volumio[789]: (Use `node --trace-deprecation ...` to show where the warning was created) Aug 31 12:43:40 minidsp-shd volumio[789]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Aug 31 12:43:40 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:40 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:40 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:40 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:40 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:40 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:40 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:40 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:40 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 31 12:43:40 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 31 12:43:40 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:40+10:00" level=info msg="generated new device id: 786a306008e2e308ff5c943c987e232cf9005442" Aug 31 12:43:40 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:40 minidsp-shd sudo[1173]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Aug 31 12:43:40 minidsp-shd sudo[1173]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:40 minidsp-shd systemd[1]: Started Volumio Bluetooth Module. Aug 31 12:43:40 minidsp-shd sudo[1173]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:40 minidsp-shd sudo[1177]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Aug 31 12:43:40 minidsp-shd sudo[1177]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:40 minidsp-shd volumiobt[1176]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Aug 31 12:43:40 minidsp-shd sudo[1177]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:40 minidsp-shd volumio[789]: info: Volumio BT Module successfully started Aug 31 12:43:40 minidsp-shd mpd[1115]: Aug 31 12:43 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 31 12:43:40 minidsp-shd mpd[1115]: Aug 31 12:43 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Aug 31 12:43:40 minidsp-shd mpd[1115]: Aug 31 12:43 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Aug 31 12:43:40 minidsp-shd volumio[789]: info: Starting Shairport Sync Aug 31 12:43:40 minidsp-shd systemd[1]: Started Music Player Daemon. Aug 31 12:43:40 minidsp-shd sudo[1099]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:40 minidsp-shd sudo[1182]: 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.1.15/Media/Music /mnt/NAS/TrueNAS Aug 31 12:43:40 minidsp-shd sudo[1182]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:40 minidsp-shd volumio[789]: info: Starting Shairport Sync Aug 31 12:43:40 minidsp-shd kernel: CIFS: Attempting to mount //192.168.1.15/Media/Music Aug 31 12:43:40 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. Aug 31 12:43:41 minidsp-shd sudo[1187]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 12:43:41 minidsp-shd sudo[1187]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:41 minidsp-shd volumio[789]: info: Starting Shairport Sync Aug 31 12:43:41 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:41+10:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 31 12:43:41 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:41+10:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 31 12:43:41 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:41+10:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 31 12:43:41 minidsp-shd sudo[1192]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 12:43:41 minidsp-shd kernel: CIFS VFS: \\192.168.1.15 failed to connect to IPC (rc=-13) Aug 31 12:43:41 minidsp-shd sudo[1192]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:41 minidsp-shd systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 31 12:43:41 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Aug 31 12:43:41 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:41+10:00" level=debug msg="zeroconf server listening on port 42057" Aug 31 12:43:41 minidsp-shd systemd[1]: shairport-sync.service: Succeeded. Aug 31 12:43:41 minidsp-shd systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 31 12:43:41 minidsp-shd kernel: CIFS VFS: cifs_mount failed w/return code = -13 Aug 31 12:43:41 minidsp-shd sudo[1182]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:41 minidsp-shd systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 31 12:43:41 minidsp-shd sudo[1196]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 31 12:43:41 minidsp-shd sudo[1196]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:41 minidsp-shd sudo[1187]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:41 minidsp-shd systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 31 12:43:41 minidsp-shd systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Aug 31 12:43:41 minidsp-shd systemd[1]: shairport-sync.service: Succeeded. Aug 31 12:43:41 minidsp-shd systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 31 12:43:41 minidsp-shd systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 31 12:43:41 minidsp-shd sudo[1192]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:41 minidsp-shd sudo[1196]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:41 minidsp-shd volumio[789]: xcb_connection_has_error() returned true Aug 31 12:43:41 minidsp-shd sudo[1203]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Aug 31 12:43:41 minidsp-shd sudo[1203]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:41 minidsp-shd volumio[789]: ------------------------------------ BT MESSAGE: BT STATUS: running Aug 31 12:43:41 minidsp-shd volumio[789]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Aug 31 12:43:41 minidsp-shd systemd[1]: Started RAAT DAEMON. Aug 31 12:43:41 minidsp-shd sudo[1203]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:41 minidsp-shd volumio[789]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Aug 31 12:43:41 minidsp-shd volumio[789]: ------------------------------------ BT MESSAGE: BT STATUS: running Aug 31 12:43:41 minidsp-shd volumio[789]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Aug 31 12:43:41 minidsp-shd volumio[789]: error: MPD error: Error: This socket has been ended by the other party Aug 31 12:43:41 minidsp-shd volumio[789]: error: This socket has been ended by the other party {"code":"EPIPE"} Aug 31 12:43:41 minidsp-shd volumio[789]: error: MPD error: Error: This socket has been ended by the other party Aug 31 12:43:41 minidsp-shd volumio[789]: error: This socket has been ended by the other party {"code":"EPIPE"} Aug 31 12:43:41 minidsp-shd volumio[789]: error: MPD error: Error: This socket has been ended by the other party Aug 31 12:43:41 minidsp-shd volumio[789]: error: This socket has been ended by the other party {"code":"EPIPE"} Aug 31 12:43:41 minidsp-shd volumio[789]: error: MPD error: Error: This socket has been ended by the other party Aug 31 12:43:41 minidsp-shd volumio[789]: error: This socket has been ended by the other party {"code":"EPIPE"} Aug 31 12:43:41 minidsp-shd volumio[789]: error: MPD error: Error: This socket has been ended by the other party Aug 31 12:43:41 minidsp-shd volumio[789]: error: This socket has been ended by the other party {"code":"EPIPE"} Aug 31 12:43:41 minidsp-shd volumio[789]: error: MPD error: Error: This socket has been ended by the other party Aug 31 12:43:41 minidsp-shd volumio[789]: error: This socket has been ended by the other party {"code":"EPIPE"} Aug 31 12:43:41 minidsp-shd volumio[789]: error: MPD error: Error: This socket has been ended by the other party Aug 31 12:43:41 minidsp-shd volumio[789]: error: This socket has been ended by the other party {"code":"EPIPE"} Aug 31 12:43:41 minidsp-shd volumio[789]: error: MPD error: Error: This socket has been ended by the other party Aug 31 12:43:41 minidsp-shd volumio[789]: error: This socket has been ended by the other party {"code":"EPIPE"} Aug 31 12:43:41 minidsp-shd volumio[789]: error: MPD error: Error: This socket has been ended by the other party Aug 31 12:43:41 minidsp-shd volumio[789]: error: This socket has been ended by the other party {"code":"EPIPE"} Aug 31 12:43:41 minidsp-shd volumio[789]: info: MRS: Found cast device: Chromecast-b275b48723cc7f85328556289e61a9f4 Aug 31 12:43:41 minidsp-shd volumio[789]: info: Adding audio output: Aug 31 12:43:41 minidsp-shd volumio[789]: info: MRS: Found cast device: Google-Cast-Group-a71d87e2b81e4810bfb8f863796f6ebd Aug 31 12:43:41 minidsp-shd volumio[789]: info: Adding audio output: Aug 31 12:43:41 minidsp-shd volumio[789]: [30B blob data] Aug 31 12:43:41 minidsp-shd volumio[789]: info: Serial Data: PUSH SOURCE 7 Aug 31 12:43:41 minidsp-shd volumio[789]: info: CoreCommandRouter::volumiosetSourceActiveno-source Aug 31 12:43:41 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 12:43:41 minidsp-shd volumio[789]: Cannot find translation for source Presets Aug 31 12:43:41 minidsp-shd volumio[789]: info: MRS: Found cast device: Google-Home-60b50ca9fcbf6fb649b497b007798097 Aug 31 12:43:41 minidsp-shd volumio[789]: info: Adding audio output: Aug 31 12:43:41 minidsp-shd volumio[789]: Upnp client error: Error: This socket has been ended by the other party Aug 31 12:43:41 minidsp-shd volumio[789]: info: Raat Daemon started successfully Aug 31 12:43:41 minidsp-shd volumio[789]: info: Shairport-Sync Started Aug 31 12:43:41 minidsp-shd volumio[789]: Error adding Membership: Error: addMembership EINVAL Aug 31 12:43:41 minidsp-shd volumio[789]: info: Shairport-Sync Started Aug 31 12:43:41 minidsp-shd volumio[789]: info: Shairport-Sync Started Aug 31 12:43:41 minidsp-shd volumio[789]: info: TidalConnect service stoped! Aug 31 12:43:41 minidsp-shd sudo[1217]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Aug 31 12:43:41 minidsp-shd sudo[1217]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:41 minidsp-shd volumiobt[1176]: pulseaudio: no process found Aug 31 12:43:41 minidsp-shd volumio[789]: info: Cannot mount NAS TrueNAS at system boot, trial number 2 ,retrying in 5 seconds Aug 31 12:43:41 minidsp-shd sudo[1217]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:41 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Aug 31 12:43:41 minidsp-shd volumio[789]: info: Enabling external Volume Control Aug 31 12:43:41 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:41 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:41 minidsp-shd dbus-daemon[470]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.19' (uid=1000 pid=1225 comm="/usr/bin/pulseaudio --high-priority=true ") Aug 31 12:43:41 minidsp-shd systemd[1]: Starting RealtimeKit Scheduling Policy Service... Aug 31 12:43:42 minidsp-shd dbus-daemon[470]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Aug 31 12:43:42 minidsp-shd systemd[1]: Started RealtimeKit Scheduling Policy Service. Aug 31 12:43:42 minidsp-shd rtkit-daemon[1226]: Successfully called chroot. Aug 31 12:43:42 minidsp-shd rtkit-daemon[1226]: Successfully dropped privileges. Aug 31 12:43:42 minidsp-shd rtkit-daemon[1226]: Successfully limited resources. Aug 31 12:43:42 minidsp-shd rtkit-daemon[1226]: Running. Aug 31 12:43:42 minidsp-shd rtkit-daemon[1226]: Watchdog thread running. Aug 31 12:43:42 minidsp-shd rtkit-daemon[1226]: Canary thread running. Aug 31 12:43:42 minidsp-shd dbus-daemon[470]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.20' (uid=0 pid=1226 comm="/usr/lib/rtkit/rtkit-daemon ") Aug 31 12:43:42 minidsp-shd systemd[1]: Starting Authorization Manager... Aug 31 12:43:42 minidsp-shd volumio[789]: info: Executing endpoint restartRAATSocket Aug 31 12:43:42 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Aug 31 12:43:42 minidsp-shd polkitd[1229]: started daemon version 0.105 using authority implementation `local' version `0.105' Aug 31 12:43:42 minidsp-shd dbus-daemon[470]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Aug 31 12:43:42 minidsp-shd systemd[1]: Started Authorization Manager. Aug 31 12:43:42 minidsp-shd volumio[789]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Aug 31 12:43:42 minidsp-shd volumio[789]: ------------------------------------ BT MESSAGE: BT STATUS: running Aug 31 12:43:42 minidsp-shd volumio[789]: ------------------------------------ BT MESSAGE: BT STATUS: running Aug 31 12:43:42 minidsp-shd volumio[789]: error: updateQueue error: null Aug 31 12:43:42 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioGetState Aug 31 12:43:42 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:42 minidsp-shd volumio[789]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Aug 31 12:43:42 minidsp-shd volumio[789]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Aug 31 12:43:42 minidsp-shd sudo[1241]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Aug 31 12:43:42 minidsp-shd sudo[1241]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:42 minidsp-shd systemd[1]: Started Volumio Tidal Connect Service. Aug 31 12:43:42 minidsp-shd sudo[1241]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:42 minidsp-shd volumio[789]: info: CoreCommandRouter::servicePushState Aug 31 12:43:42 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Aug 31 12:43:42 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:42 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Aug 31 12:43:42 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Aug 31 12:43:42 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Aug 31 12:43:42 minidsp-shd volumio[789]: error: Help! Some callbacks for volumioPushState are crashing! Aug 31 12:43:42 minidsp-shd volumio[789]: error: Cannot read property 'sendVolumeMute' of undefined Aug 31 12:43:42 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:42 minidsp-shd volumio[789]: verbose: STATE SERVICE {"status":"stop","service":"raat","title":"","artist":"","album":"","albumart":"/albumart?web=100/extralarge&path=/tmp/raat/albumart/7e97257c319135d0044d546cd01ef5b8.jpg","uri":"","trackType":"","seek":0,"duration":0,"samplerate":"","bitdepth":"","channels":2,"disableUiControls":false,"push_time":0} Aug 31 12:43:42 minidsp-shd volumio[789]: verbose: CURRENT POSITION 0 Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreStateMachine::syncState stateService stop Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreStateMachine::syncState currentStatus stop Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Aug 31 12:43:43 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Aug 31 12:43:43 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Aug 31 12:43:43 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Aug 31 12:43:43 minidsp-shd volumio[789]: error: Help! Some callbacks for volumioPushState are crashing! Aug 31 12:43:43 minidsp-shd volumio[789]: error: Cannot read property 'sendVolumeMute' of undefined Aug 31 12:43:43 minidsp-shd volumio[789]: info: No code Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Aug 31 12:43:43 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Aug 31 12:43:43 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Aug 31 12:43:43 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Aug 31 12:43:43 minidsp-shd volumio[789]: error: Help! Some callbacks for volumioPushState are crashing! Aug 31 12:43:43 minidsp-shd volumio[789]: error: Cannot read property 'sendVolumeMute' of undefined Aug 31 12:43:43 minidsp-shd pulseaudio[1225]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Aug 31 12:43:43 minidsp-shd pulseaudio[1225]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreCommandRouter::servicePushState Aug 31 12:43:43 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:43 minidsp-shd volumio[789]: verbose: STATE SERVICE {"status":"pause","service":"raat","title":"Liberate Me","artist":"DVSR","album":"West Technique (CD)","albumart":"/albumart","uri":"","trackType":"","seek":218000,"duration":253,"samplerate":"","bitdepth":"","channels":2,"disableUiControls":false,"push_time":0} Aug 31 12:43:43 minidsp-shd volumio[789]: verbose: CURRENT POSITION 0 Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreStateMachine::syncState stateService pause Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreStateMachine::syncState currentStatus stop Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Aug 31 12:43:43 minidsp-shd volumiobt[1176]: Applying permissions Aug 31 12:43:43 minidsp-shd volumiobt[1176]: Setting BT discoverable and pairable Aug 31 12:43:43 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Aug 31 12:43:43 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Aug 31 12:43:43 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Aug 31 12:43:43 minidsp-shd volumio[789]: error: Help! Some callbacks for volumioPushState are crashing! Aug 31 12:43:43 minidsp-shd pulseaudio[1225]: 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 Aug 31 12:43:43 minidsp-shd volumio[789]: error: Cannot read property 'sendVolumeMute' of undefined Aug 31 12:43:43 minidsp-shd volumio[789]: info: Updating RAAT Signal Path Aug 31 12:43:43 minidsp-shd volumiobt[1176]: [38B blob data] Aug 31 12:43:43 minidsp-shd volumiobt[1176]: Invalid command Aug 31 12:43:43 minidsp-shd volumiobt[1176]: [bluetooth]# agent on Aug 31 12:43:43 minidsp-shd volumiobt[1176]: [bluetooth]# discoverable on Aug 31 12:43:43 minidsp-shd volumiobt[1176]: No default controller available Aug 31 12:43:43 minidsp-shd volumiobt[1176]: [bluetooth]# pairable on Aug 31 12:43:43 minidsp-shd volumio[789]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 4 Aug 31 12:43:43 minidsp-shd volumiobt[1176]: No default controller available Aug 31 12:43:43 minidsp-shd volumiobt[1176]: [bluetooth]# agent NoInputNoOutput Aug 31 12:43:43 minidsp-shd volumiobt[1176]: Failed to register agent object Aug 31 12:43:43 minidsp-shd volumiobt[1176]: [bluetooth]# default-agent Aug 31 12:43:43 minidsp-shd volumiobt[1176]: No agent is registered Aug 31 12:43:43 minidsp-shd volumiobt[1176]: [bluetooth]# quit Aug 31 12:43:43 minidsp-shd volumiobt[1176]: [61B blob data] Aug 31 12:43:43 minidsp-shd volumiobt[1176]: [62B blob data] Aug 31 12:43:43 minidsp-shd volumio[789]: info: go-librespot daemon successfully initialized Aug 31 12:43:43 minidsp-shd volumio[789]: info: MRS: Getting audio outputs on start Aug 31 12:43:43 minidsp-shd volumio[1096]: Generating RSA private key, 4096 bit long modulus (2 primes) Aug 31 12:43:43 minidsp-shd volumio[789]: info: MRS: Requesting all other devices output Aug 31 12:43:43 minidsp-shd volumio[789]: info: Executing endpoint tc_getconfig Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Aug 31 12:43:43 minidsp-shd vtcs[1243]: STARTING TidalConnect services, version: 1.3.0.19 Aug 31 12:43:43 minidsp-shd vtcs[1243]: STARTED TidalConnect services. Aug 31 12:43:43 minidsp-shd volumio[789]: info: Executing endpoint tc_connect Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Aug 31 12:43:43 minidsp-shd volumio[789]: info: Connecting to TidalConnect Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreCommandRouter::servicePushState Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Aug 31 12:43:43 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Aug 31 12:43:43 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:43+10:00" level=debug msg="obtained new client token: AACb0jk76LtGnvpSLeY/ZhXgp8zWBdub8gzzStZiX7n9BYsqk8Y147Yv2f/q0tK9luyVmKHS/LhkMzPm4Ss+P+hKn7xYPhLfkJEduH5w2QNnH6wrnQJLY4mIJCnqJnuzt0+gwpBgZ/m8+7jfdNUdzMzZjKzp69QUviRIggLBBwg2AnFX/nsCgqL4pHhg5E2pj8tuRM+X5OHNYjP/iyQApFn3MBXofkN8fGFC1UByms8ZH7B6X6r1F0nt/CuRDC8=" Aug 31 12:43:43 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Aug 31 12:43:43 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Aug 31 12:43:43 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:43 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} Aug 31 12:43:43 minidsp-shd volumio[789]: verbose: CURRENT POSITION 0 Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreStateMachine::syncState stateService stop Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreStateMachine::syncState currentStatus stop Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Aug 31 12:43:43 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Aug 31 12:43:43 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Aug 31 12:43:43 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Aug 31 12:43:43 minidsp-shd volumio[789]: info: No code Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Aug 31 12:43:43 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:43 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Aug 31 12:43:44 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Aug 31 12:43:44 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Aug 31 12:43:44 minidsp-shd volumio[789]: info: CoreCommandRouter::servicePushState Aug 31 12:43:44 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Aug 31 12:43:44 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:44 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Aug 31 12:43:44 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Aug 31 12:43:44 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Aug 31 12:43:44 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:44 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} Aug 31 12:43:44 minidsp-shd volumio[789]: verbose: CURRENT POSITION 0 Aug 31 12:43:44 minidsp-shd volumio[789]: info: CoreStateMachine::syncState stateService stop Aug 31 12:43:44 minidsp-shd volumio[789]: info: CoreStateMachine::syncState currentStatus stop Aug 31 12:43:44 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Aug 31 12:43:44 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:44 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Aug 31 12:43:44 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Aug 31 12:43:44 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Aug 31 12:43:44 minidsp-shd volumio[789]: info: No code Aug 31 12:43:44 minidsp-shd volumio[789]: info: CoreStateMachine::pushState Aug 31 12:43:44 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:44 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioPushState Aug 31 12:43:44 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output update for this device Aug 31 12:43:44 minidsp-shd volumio[789]: info: MRS: Pushing multiroomSync output Aug 31 12:43:44 minidsp-shd volumio[789]: info: Serial Data: PUSH PRESET 2 Aug 31 12:43:44 minidsp-shd volumio[789]: [30B blob data] Aug 31 12:43:44 minidsp-shd volumio[789]: info: Serial Data: PUSH PRESET 2 Aug 31 12:43:44 minidsp-shd volumio[789]: [28B blob data] Aug 31 12:43:44 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:44+10:00" level=debug msg="completed keyexchange" Aug 31 12:43:44 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:44+10:00" level=debug msg="completed challenge" Aug 31 12:43:44 minidsp-shd volumio[1096]: ..................++++ Aug 31 12:43:45 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:45+10:00" level=debug msg="authenticated as 1231805191" Aug 31 12:43:45 minidsp-shd volumio[789]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 12:43:45 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 31 12:43:45 minidsp-shd volumio[789]: info: [1725072225109] CoreMusicLibrary::Adding element YouTube Music Aug 31 12:43:45 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 12:43:45 minidsp-shd volumio[789]: Cannot find translation for source Presets Aug 31 12:43:45 minidsp-shd volumio[789]: Cannot find translation for source YouTube Music Aug 31 12:43:45 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:45+10:00" level=debug msg="authenticated as 1231805191" Aug 31 12:43:45 minidsp-shd volumio[789]: error: [ytmusic] Error in ConfigModel._fetchSettingsPage(): Request to https://www.youtube.com/youtubei/vtrue/account/get_setting?key=AIzaSyAO_FJ2SlqU8Q4STEHLGCilw_Y9_11qcW8&prettyPrint=false&alt=json failed with status 400 Error: Request to https://www.youtube.com/youtubei/vtrue/account/get_setting?key=AIzaSyAO_FJ2SlqU8Q4STEHLGCilw_Y9_11qcW8&prettyPrint=false&alt=json failed with status 400 Aug 31 12:43:45 minidsp-shd volumio[789]: at HTTPClient. (/data/plugins/music_service/ytmusic/node_modules/volumio-youtubei.js/bundle/node.cjs:22010:13) Aug 31 12:43:45 minidsp-shd volumio[789]: at Generator.next () Aug 31 12:43:45 minidsp-shd volumio[789]: at fulfilled (/data/plugins/music_service/ytmusic/node_modules/volumio-youtubei.js/bundle/node.cjs:215:30) Aug 31 12:43:45 minidsp-shd volumio[789]: at runMicrotasks () Aug 31 12:43:45 minidsp-shd volumio[789]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Aug 31 12:43:45 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:45+10:00" level=debug msg="dealer connection opened" Aug 31 12:43:45 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:45+10:00" level=info msg="accepted zeroconf user 1231805191 from Nicole's S10" Aug 31 12:43:45 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:45+10:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Aug 31 12:43:45 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:45+10:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Aug 31 12:43:45 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:45+10:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Aug 31 12:43:45 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:45+10:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Aug 31 12:43:45 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:45+10:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Aug 31 12:43:45 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:45+10:00" level=debug msg="received connection id: OTIyOGJkZDktNDE5OS00NGU0LTlhZDctODFjOTMwMjI0MjVmK2RlYWxlcit0Y3A6Ly8wYWM5NDgyOC5pcC5nYWUyLnNwb3RpZnkubmV0OjU3MDArRUUwMUQ1RkI1MUVGQTA3QjJERUQwN0M4MEFGQUYzNjRFQjhEMzczMEQ3MUQ5MDlENjMxMjQ3NTVERUQ4RjVCNQ==" Aug 31 12:43:45 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:45+10:00" level=debug msg="put connect state because NEW_DEVICE" Aug 31 12:43:45 minidsp-shd volumio[789]: info: TidalConnect service started! Aug 31 12:43:45 minidsp-shd volumio[789]: info: Completed starting Core Plugins Aug 31 12:43:45 minidsp-shd volumio[789]: info: ------------------------------------------- Aug 31 12:43:45 minidsp-shd volumio[789]: info: ----- MyVolumio plugins startup ---- Aug 31 12:43:45 minidsp-shd volumio[789]: info: ------------------------------------------- Aug 31 12:43:45 minidsp-shd volumio[789]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 31 12:43:46 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:46+10:00" level=debug msg="handling transfer player command from ea406ebf3e7a852b2a8130250d86cd1e4898c153" Aug 31 12:43:46 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:46+10:00" level=trace msg="fetched new page 0 with 20 items (list: 20)" Aug 31 12:43:46 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:46+10:00" level=debug msg="loading track spotify:track:7AGlwqzUDIAZfVl6dnqWvw (paused: true, position: 5344ms)" Aug 31 12:43:46 minidsp-shd volumio[789]: info: Initializing connection to go-librespot Websocket Aug 31 12:43:46 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:46+10:00" level=debug msg="new websocket client" Aug 31 12:43:46 minidsp-shd volumio[789]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 31 12:43:46 minidsp-shd volumio[789]: info: Connection to go-librespot Websocket established Aug 31 12:43:46 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:46+10:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 12:43:46 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:46+10:00" level=trace msg="emitting websocket event: will_play" Aug 31 12:43:46 minidsp-shd volumio[789]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7AGlwqzUDIAZfVl6dnqWvw","play_origin":"playlist"}} Aug 31 12:43:46 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:46+10:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Aug 31 12:43:46 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:46+10:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:7AGlwqzUDIAZfVl6dnqWvw" Aug 31 12:43:46 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:46+10:00" level=debug msg="requested aes key for file 8b0cd6743fdbe4ecea0312df870d47e695870c5c, gid: 7AGlwqzUDIAZfVl6dnqWvw" Aug 31 12:43:46 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:46+10:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1353" Aug 31 12:43:46 minidsp-shd volumio[789]: error: [ytmusic] Error in ConfigModel._fetchSettingsPage(): Request to https://www.youtube.com/youtubei/vtrue/account/get_setting?key=AIzaSyAO_FJ2SlqU8Q4STEHLGCilw_Y9_11qcW8&prettyPrint=false&alt=json failed with status 400 Error: Request to https://www.youtube.com/youtubei/vtrue/account/get_setting?key=AIzaSyAO_FJ2SlqU8Q4STEHLGCilw_Y9_11qcW8&prettyPrint=false&alt=json failed with status 400 Aug 31 12:43:46 minidsp-shd volumio[789]: at HTTPClient. (/data/plugins/music_service/ytmusic/node_modules/volumio-youtubei.js/bundle/node.cjs:22010:13) Aug 31 12:43:46 minidsp-shd volumio[789]: at Generator.next () Aug 31 12:43:46 minidsp-shd volumio[789]: at fulfilled (/data/plugins/music_service/ytmusic/node_modules/volumio-youtubei.js/bundle/node.cjs:215:30) Aug 31 12:43:46 minidsp-shd volumio[789]: at runMicrotasks () Aug 31 12:43:46 minidsp-shd volumio[789]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Aug 31 12:43:46 minidsp-shd sudo[1280]: 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.1.15/Media/Music /mnt/NAS/TrueNAS Aug 31 12:43:46 minidsp-shd sudo[1280]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:46 minidsp-shd kernel: CIFS: Attempting to mount //192.168.1.15/Media/Music Aug 31 12:43:46 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. Aug 31 12:43:47 minidsp-shd kernel: CIFS VFS: \\192.168.1.15 failed to connect to IPC (rc=-13) Aug 31 12:43:47 minidsp-shd kernel: CIFS VFS: cifs_mount failed w/return code = -13 Aug 31 12:43:47 minidsp-shd sudo[1280]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:47 minidsp-shd volumio[789]: info: Cannot mount NAS TrueNAS at system boot, trial number 3 ,retrying in 5 seconds Aug 31 12:43:47 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:47+10:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1131" Aug 31 12:43:47 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:47+10:00" level=debug msg="fetched first chunk of 20, total size is 10132509 bytes" Aug 31 12:43:47 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:47+10:00" level=trace msg="seek to 5344ms (diff: 116ms, samples: 235670, bytes: 201719)" Aug 31 12:43:47 minidsp-shd go-librespot[1157]: 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 Aug 31 12:43:47 minidsp-shd go-librespot[1157]: 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 Aug 31 12:43:47 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:47+10:00" level=info msg="loaded track \"Let Them Bells Ring\" (uri: spotify:track:7AGlwqzUDIAZfVl6dnqWvw, paused: true, position: 5344ms, duration: 248003ms)" Aug 31 12:43:47 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:47+10:00" level=debug msg="fetched chunk 2/19, size: 524288" Aug 31 12:43:48 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:48+10:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 12:43:48 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:48+10:00" level=trace msg="emitting websocket event: metadata" Aug 31 12:43:48 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:48+10:00" level=trace msg="emitting websocket event: active" Aug 31 12:43:48 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:48+10:00" level=debug msg="sending successful reply for delaer request" Aug 31 12:43:48 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:48+10:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Aug 31 12:43:48 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:48+10:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Aug 31 12:43:48 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:48 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:48 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:48 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:48+10:00" level=debug msg="fetched chunk 3/19, size: 524288" Aug 31 12:43:48 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 31 12:43:48 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 31 12:43:48 minidsp-shd volumio[789]: info: Not Reporting Auto name since its the default one Aug 31 12:43:48 minidsp-shd volumio[789]: info: RAAT Overriding default device vendor model Aug 31 12:43:48 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:48+10:00" level=debug msg="fetched chunk 1/19, size: 524288" Aug 31 12:43:48 minidsp-shd volumio[789]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7AGlwqzUDIAZfVl6dnqWvw","name":"Let Them Bells Ring","artist_names":["Confidence Man"],"album_name":"fabric presents Confidence Man (Mixed)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02b9026c30ce998f748a3f0e93","position":5344,"duration":248003,"release_date":"year:2024 month:8 day:23","track_number":1,"disc_number":1}} Aug 31 12:43:48 minidsp-shd volumio[789]: SPOTIFY: received: {"type":"active","data":null} Aug 31 12:43:48 minidsp-shd volumio[789]: info: Aligning Spotify Volume to Volumio Volume Aug 31 12:43:48 minidsp-shd volumio[789]: info: CoreCommandRouter::volumioGetState Aug 31 12:43:48 minidsp-shd volumio[789]: info: CorePlayQueue::getTrack 0 Aug 31 12:43:48 minidsp-shd volumio[789]: info: Setting Spotify Volume from Volumio: 76 Aug 31 12:43:48 minidsp-shd volumio[789]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Aug 31 12:43:48 minidsp-shd volumio[789]: xcb_connection_has_error() returned true Aug 31 12:43:48 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:48+10:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 12:43:48 minidsp-shd go-librespot[1157]: time="2024-08-31T12:43:48+10:00" level=trace msg="emitting websocket event: paused" Aug 31 12:43:48 minidsp-shd sudo[1295]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Aug 31 12:43:48 minidsp-shd volumio[789]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:7AGlwqzUDIAZfVl6dnqWvw","play_origin":"playlist"}} Aug 31 12:43:48 minidsp-shd sudo[1295]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 12:43:48 minidsp-shd volumio[789]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 12:43:48 minidsp-shd volumio[789]: TypeError: Cannot read property 'service' of undefined Aug 31 12:43:48 minidsp-shd volumio[789]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Aug 31 12:43:48 minidsp-shd volumio[789]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:270:18) Aug 31 12:43:48 minidsp-shd volumio[789]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Aug 31 12:43:48 minidsp-shd volumio[789]: at WebSocket.emit (events.js:400:28) Aug 31 12:43:48 minidsp-shd volumio[789]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1203:20) Aug 31 12:43:48 minidsp-shd volumio[789]: at Receiver.emit (events.js:400:28) Aug 31 12:43:48 minidsp-shd volumio[789]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:608:16 Aug 31 12:43:48 minidsp-shd volumio[789]: at internal/process/task_queues.js:141:7 Aug 31 12:43:48 minidsp-shd volumio[789]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) Aug 31 12:43:48 minidsp-shd volumio[789]: at AsyncResource.runMicrotask (internal/process/task_queues.js:138:8) Aug 31 12:43:48 minidsp-shd volumio[789]: at runMicrotasks () Aug 31 12:43:48 minidsp-shd volumio[789]: at processTicksAndRejections (internal/process/task_queues.js:95:5) Aug 31 12:43:48 minidsp-shd volumio[789]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 12:43:48 minidsp-shd systemd[1]: Stopping RAAT DAEMON... Aug 31 12:43:48 minidsp-shd systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Aug 31 12:43:48 minidsp-shd systemd[1]: raat-daemon.service: Succeeded. Aug 31 12:43:48 minidsp-shd systemd[1]: Stopped RAAT DAEMON. Aug 31 12:43:48 minidsp-shd systemd[1]: Started RAAT DAEMON. Aug 31 12:43:48 minidsp-shd sudo[1295]: pam_unix(sudo:session): session closed for user root Aug 31 12:43:49 minidsp-shd sudo[1316]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-31 12:42 Aug 31 12:43:49 minidsp-shd sudo[1316]: 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="0ef0dad44cf35fd5ee48d6a73038e6bc20ae89b6" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="c3dc2d8d6304822135b544ac297e3e2762b5a352" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 22 Dec 2023 05:15:59 PM CET" VOLUMIO_VERSION="3.587" VOLUMIO_HARDWARE="nanopineo3" VOLUMIO_DEVICENAME="Nanopi Neo3" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="f010d4b01401ad12eb6b0a9727693491"