Jan 12 15:13:00 volumio kernel: usb 1-1.2: New USB device found, idVendor=040d, idProduct=340b, bcdDevice= 0.10 Jan 12 15:13:00 volumio kernel: usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Jan 12 15:13:00 volumio kernel: usb 1-1.2: Product: FX-AUDIO-DAC-X6 Jan 12 15:13:00 volumio kernel: usb 1-1.2: Manufacturer: FX-AUDIO Jan 12 15:13:00 volumio kernel: input: FX-AUDIO FX-AUDIO-DAC-X6 as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.2/1-1.2:1.2/0003:040D:340B.0003/input/input2 Jan 12 15:13:00 volumio kernel: hid-generic 0003:040D:340B.0003: input,hidraw2: USB HID v1.00 Device [FX-AUDIO FX-AUDIO-DAC-X6] on usb-0000:01:00.0-1.2/input2 Jan 12 15:13:00 volumio kernel: usbcore: registered new interface driver snd-usb-audio Jan 12 15:13:00 volumio (udev-worker)[2515]: controlC5: Process '/usr/sbin/alsactl -E HOME=/run/alsa -E XDG_RUNTIME_DIR=/run/alsa/runtime restore 5' failed with exit code 99. Jan 12 15:13:00 volumio volumio[1178]: info: Jan 12 15:13:00 volumio volumio[1178]: ---------------------------- USB Audio Device Attached Jan 12 15:13:00 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Jan 12 15:13:10 volumio volumio[1178]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 12 15:13:10 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jan 12 15:13:10 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 15:13:10 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 12 15:13:10 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:10 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:10 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:10 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:10 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:10 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:10 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:10 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jan 12 15:13:10 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 12 15:13:16 volumio volumio[1178]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Jan 12 15:13:16 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Jan 12 15:13:16 volumio volumio[1178]: info: Preparing to save Alsa Options, stopping services first Jan 12 15:13:16 volumio volumio[1178]: info: CoreCommandRouter::volumioGetState Jan 12 15:13:16 volumio volumio[1178]: info: CorePlayQueue::getTrack 0 Jan 12 15:13:16 volumio volumio[1178]: info: CoreCommandRouter::volumioPause Jan 12 15:13:16 volumio volumio[1178]: info: CoreStateMachine::pause Jan 12 15:13:16 volumio volumio[1178]: info: Saving Audio Output to: {"output_device":{"value":"5","label":"FX-AUDIO-DAC-X6"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Jan 12 15:13:16 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 12 15:13:16 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 12 15:13:16 volumio volumio[1178]: info: Setting mixer PCM for card FX-AUDIO-DAC-X6 Jan 12 15:13:16 volumio volumio[1178]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jan 12 15:13:16 volumio volumio[1178]: info: Updating Volume Controller Parameters: Device: 5 Name: FX-AUDIO-DAC-X6 Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Jan 12 15:13:16 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jan 12 15:13:16 volumio volumio[1178]: info: Disabling external Volume Control Jan 12 15:13:16 volumio volumio[1178]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 12 15:13:16 volumio volumio[1178]: info: Preparing to generate the ALSA configuration file Jan 12 15:13:17 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jan 12 15:13:17 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 15:13:17 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 12 15:13:17 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:17 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:17 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:17 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:17 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:17 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:17 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:17 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jan 12 15:13:17 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 12 15:13:17 volumio volumio[1178]: info: VolumeController:: Volume=35 Mute =false Jan 12 15:13:17 volumio volumio[1178]: info: CoreStateMachine::pushState Jan 12 15:13:17 volumio volumio[1178]: info: CorePlayQueue::getTrack 0 Jan 12 15:13:17 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 15:13:17 volumio volumio[1178]: info: CoreCommandRouter::volumioPushState Jan 12 15:13:17 volumio volumio[1178]: info: Asound.conf file written Jan 12 15:13:17 volumio sudo[2591]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jan 12 15:13:17 volumio sudo[2591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 15:13:17 volumio sudo[2591]: pam_unix(sudo:session): session closed for user root Jan 12 15:13:17 volumio volumio[1178]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Jan 12 15:13:17 volumio volumio[1178]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Jan 12 15:13:17 volumio volumio[1178]: No state is present for card FXAUDIODACX6 Jan 12 15:13:17 volumio volumio[1178]: Found hardware: "USB-Audio" "USB Mixer" "USB040d:340b" "" "" Jan 12 15:13:17 volumio volumio[1178]: Hardware is initialized using a generic method Jan 12 15:13:17 volumio volumio[1178]: No state is present for card FXAUDIODACX6 Jan 12 15:13:17 volumio volumio[1178]: info: Output device has changed, restarting MPD Jan 12 15:13:17 volumio volumio[1178]: info: Output device has changed, restarting Shairport Sync Jan 12 15:13:17 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:17 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 15:13:17 volumio sudo[2598]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 15:13:17 volumio sudo[2598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 15:13:17 volumio sudo[2599]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 15:13:17 volumio sudo[2599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 15:13:17 volumio sudo[2598]: pam_unix(sudo:session): session closed for user root Jan 12 15:13:17 volumio volumio[1178]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 12 15:13:17 volumio volumio[1178]: info: Output device has changed, restarting MPD Jan 12 15:13:18 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 12 15:13:18 volumio volumio[1178]: info: Output device has changed, restarting Shairport Sync Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 15:13:18 volumio sudo[2607]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 15:13:18 volumio sudo[2607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 15:13:18 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 12 15:13:18 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 12 15:13:18 volumio systemd[1]: mpd.service: Consumed 1.482s CPU time. Jan 12 15:13:18 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 12 15:13:18 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 12 15:13:18 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 12 15:13:18 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 12 15:13:18 volumio sudo[2607]: pam_unix(sudo:session): session closed for user root Jan 12 15:13:18 volumio sudo[2609]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 15:13:18 volumio sudo[2609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 15:13:18 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 12 15:13:18 volumio volumio[1178]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 12 15:13:18 volumio volumio[1178]: info: MPD Permissions set Jan 12 15:13:18 volumio volumio[1178]: info: MPD Permissions set Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio sudo[2616]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 12 15:13:18 volumio sudo[2616]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 12 15:13:18 volumio sudo[2616]: pam_unix(sudo:session): session closed for user root Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 12 15:13:18 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 12 15:13:18 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 12 15:13:18 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 12 15:13:18 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 12 15:13:18 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 12 15:13:18 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 12 15:13:18 volumio sudo[2626]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 12 15:13:18 volumio sudo[2626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 12 15:13:18 volumio sudo[2626]: pam_unix(sudo:session): session closed for user root Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 15:13:18 volumio volumio[1178]: info: Starting Shairport Sync Jan 12 15:13:18 volumio volumio[1178]: info: Starting Shairport Sync Jan 12 15:13:18 volumio sudo[2645]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 12 15:13:18 volumio sudo[2645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 15:13:18 volumio sudo[2651]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 12 15:13:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 12 15:13:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 12 15:13:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 15:13:18 volumio systemd[1]: shairport-sync.service: Consumed 1.558s CPU time. Jan 12 15:13:18 volumio sudo[2651]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 15:13:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 15:13:19 volumio sudo[2645]: pam_unix(sudo:session): session closed for user root Jan 12 15:13:19 volumio volumio[1178]: info: Shairport-Sync Started Jan 12 15:13:19 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 12 15:13:19 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 12 15:13:19 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 15:13:19 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 15:13:19 volumio sudo[2651]: pam_unix(sudo:session): session closed for user root Jan 12 15:13:19 volumio volumio[1178]: info: Shairport-Sync Started Jan 12 15:13:20 volumio mpd[2637]: 2026-01-12T15:13:20 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 12 15:13:20 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 12 15:13:20 volumio sudo[2599]: pam_unix(sudo:session): session closed for user root Jan 12 15:13:20 volumio sudo[2609]: pam_unix(sudo:session): session closed for user root Jan 12 15:13:20 volumio volumio[1178]: error: MPD error: The expression evaluated to a falsy value: Jan 12 15:13:20 volumio volumio[1178]: assert.ok(self.idling) Jan 12 15:13:20 volumio volumio[1178]: error: The expression evaluated to a falsy value: Jan 12 15:13:20 volumio volumio[1178]: assert.ok(self.idling) Jan 12 15:13:20 volumio volumio[1178]: error: updateQueue error: null Jan 12 15:13:20 volumio volumio[1178]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Jan 12 15:13:20 volumio volumio[1178]: info: CoreStateMachine::getcurrentVolume Jan 12 15:13:20 volumio volumio[1178]: info: CoreCommandRouter::volumioRetrievevolume Jan 12 15:13:21 volumio volumio[1178]: info: VolumeController:: Volume=35 Mute =false Jan 12 15:13:21 volumio volumio[1178]: info: CoreStateMachine::pushState Jan 12 15:13:21 volumio volumio[1178]: info: CorePlayQueue::getTrack 0 Jan 12 15:13:21 volumio volumio[1178]: info: CoreCommandRouter::volumioPushState Jan 12 15:13:21 volumio volumio[1178]: info: CoreStateMachine::updateTrackBlock Jan 12 15:13:21 volumio volumio[1178]: info: CorePlayQueue::getTrackBlock Jan 12 15:13:21 volumio volumio[1178]: info: CoreCommandRouter::volumioRetrievevolume Jan 12 15:13:21 volumio volumio[1178]: info: VolumeController:: Volume=35 Mute =false Jan 12 15:13:21 volumio volumio[1178]: info: CoreStateMachine::pushState Jan 12 15:13:21 volumio volumio[1178]: info: CorePlayQueue::getTrack 0 Jan 12 15:13:21 volumio volumio[1178]: info: CoreCommandRouter::volumioPushState Jan 12 15:13:23 volumio sudo[2677]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 12 15:13:23 volumio sudo[2677]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 15:13:23 volumio sudo[2679]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 12 15:13:23 volumio sudo[2679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 15:13:23 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 12 15:13:23 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 12 15:13:23 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 12 15:13:23 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 12 15:13:23 volumio systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 12 15:13:23 volumio systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 12 15:13:23 volumio systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 12 15:13:23 volumio sudo[2677]: pam_unix(sudo:session): session closed for user root Jan 12 15:13:23 volumio systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 12 15:13:23 volumio volumio[1178]: info: Successfully started MPD Monitor Jan 12 15:13:23 volumio mpd_monitor.sh[2683]: MPD Monitor Service: Starting MPD Monitor Service Jan 12 15:13:23 volumio sudo[2679]: pam_unix(sudo:session): session closed for user root Jan 12 15:13:23 volumio volumio[1178]: info: Successfully started MPD Monitor Jan 12 15:13:27 volumio volumio[1178]: info: CoreCommandRouter::volumioGetState Jan 12 15:13:27 volumio volumio[1178]: info: CorePlayQueue::getTrack 0 Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 12 15:13:35 volumio volumio[1178]: info: Retrieving Cloud Streaming UI Jan 12 15:13:35 volumio volumio[1178]: info: Getting Tidal Cloud Configuration Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 12 15:13:35 volumio volumio[1178]: info: Getting Qobuz Cloud Configuration Jan 12 15:13:35 volumio volumio[1178]: info: Asking plugin for UI Config Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 12 15:13:35 volumio volumio[1178]: info: Getting Spotify Cloud Configuration Jan 12 15:13:35 volumio volumio[1178]: info: Asking plugin for UI Config Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 12 15:13:35 volumio volumio[1178]: info: Saving Spotify Acccount Jan 12 15:13:35 volumio volumio[1178]: info: Got Tidal Cloud Configuration Jan 12 15:13:35 volumio volumio[1178]: info: Got it Jan 12 15:13:35 volumio volumio[1178]: info: Got it Jan 12 15:13:35 volumio volumio[1178]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 12 15:13:35 volumio volumio[1178]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::volumioGetBrowseSources Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::volumioGetBrowseSources Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::volumioGetBrowseSources Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 15:13:35 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jan 12 15:13:38 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jan 12 15:13:38 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jan 12 15:13:39 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 15:13:40 volumio volumio[1178]: info: Executing SMB command: smbclient --no-pass --debuglevel=0 -L DATABASE.local. -m SMB3_11 Jan 12 15:13:41 volumio volumio[1178]: info: Error browsing device DATABASE for shares: Command failed: smbclient --no-pass --debuglevel=0 -L DATABASE.local. -m SMB3_11 Jan 12 15:13:43 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 15:13:47 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 15:13:51 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 15:13:55 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 15:13:59 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 15:14:03 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 15:14:06 volumio ntpd[1023]: CLOCK: time stepped by 0.417890 Jan 12 15:14:06 volumio ntpd[1023]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Jan 12 15:14:08 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 15:14:08 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: networkfs , addShare Jan 12 15:14:08 volumio volumio[1178]: info: Adding a new share Jan 12 15:14:08 volumio volumio[1178]: info: No correspondence found in configuration for share nas_music on IP 192.168.100.9 Jan 12 15:14:08 volumio volumio[1178]: info: Executing SMB command: smbclient --debuglevel=4 -L 192.168.100.9 -N -m SMB3_11 Jan 12 15:14:09 volumio volumio[1178]: info: Error browsing device nas_music for shares: Command failed: smbclient --debuglevel=4 -L 192.168.100.9 -N -m SMB3_11 Jan 12 15:14:09 volumio volumio[1178]: lp_load_ex: refreshing parameters Jan 12 15:14:09 volumio volumio[1178]: Initialising global parameters Jan 12 15:14:09 volumio volumio[1178]: Processing section "[global]" Jan 12 15:14:09 volumio volumio[1178]: doing parameter netbios name = Volumio Jan 12 15:14:09 volumio volumio[1178]: doing parameter server string = Volumio Audiophile Music Player Jan 12 15:14:09 volumio volumio[1178]: doing parameter workgroup = WORKGROUP Jan 12 15:14:09 volumio volumio[1178]: doing parameter security = user Jan 12 15:14:09 volumio volumio[1178]: doing parameter map to guest = Bad User Jan 12 15:14:09 volumio volumio[1178]: doing parameter encrypt passwords = yes Jan 12 15:14:09 volumio volumio[1178]: lpcfg_do_global_parameter: WARNING: The "encrypt passwords" option is deprecated Jan 12 15:14:09 volumio volumio[1178]: doing parameter wins support = yes Jan 12 15:14:09 volumio volumio[1178]: doing parameter local master = no Jan 12 15:14:09 volumio volumio[1178]: doing parameter preferred master = no Jan 12 15:14:09 volumio volumio[1178]: doing parameter os level = 30 Jan 12 15:14:09 volumio volumio[1178]: doing parameter fruit:model = AirPort Jan 12 15:14:09 volumio volumio[1178]: pm_process() returned Yes Jan 12 15:14:09 volumio volumio[1178]: added interface eth0 ip=192.168.100.123 bcast=192.168.100.255 netmask=255.255.255.0 Jan 12 15:14:09 volumio volumio[1178]: Client started (version 4.17.8-Raspbian). Jan 12 15:14:09 volumio volumio[1178]: Connecting to 192.168.100.9 at port 445 Jan 12 15:14:09 volumio volumio[1178]: session request ok Jan 12 15:14:09 volumio volumio[1178]: negotiated dialect[SMB3_11] against server[192.168.100.9] Jan 12 15:14:09 volumio volumio[1178]: GENSEC backend 'gssapi_spnego' registered Jan 12 15:14:09 volumio volumio[1178]: GENSEC backend 'gssapi_krb5' registered Jan 12 15:14:09 volumio volumio[1178]: GENSEC backend 'gssapi_krb5_sasl' registered Jan 12 15:14:09 volumio volumio[1178]: GENSEC backend 'spnego' registered Jan 12 15:14:09 volumio volumio[1178]: GENSEC backend 'schannel' registered Jan 12 15:14:09 volumio volumio[1178]: GENSEC backend 'ncalrpc_as_system' registered Jan 12 15:14:09 volumio volumio[1178]: GENSEC backend 'sasl-EXTERNAL' registered Jan 12 15:14:09 volumio volumio[1178]: GENSEC backend 'ntlmssp' registered Jan 12 15:14:09 volumio volumio[1178]: GENSEC backend 'ntlmssp_resume_ccache' registered Jan 12 15:14:09 volumio volumio[1178]: GENSEC backend 'http_basic' registered Jan 12 15:14:09 volumio volumio[1178]: GENSEC backend 'http_ntlm' registered Jan 12 15:14:09 volumio volumio[1178]: GENSEC backend 'http_negotiate' registered Jan 12 15:14:09 volumio volumio[1178]: GENSEC backend 'krb5' registered Jan 12 15:14:09 volumio volumio[1178]: GENSEC backend 'fake_gssapi_krb5' registered Jan 12 15:14:09 volumio volumio[1178]: Cannot do GSE to an IP address Jan 12 15:14:09 volumio volumio[1178]: Failed to start GENSEC client mech gse_krb5: NT_STATUS_INVALID_PARAMETER Jan 12 15:14:09 volumio volumio[1178]: Got challenge flags: Jan 12 15:14:09 volumio volumio[1178]: Got NTLMSSP neg_flags=0x628a8215 Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_UNICODE Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_REQUEST_TARGET Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_SIGN Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_NTLM Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_TARGET_TYPE_SERVER Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_TARGET_INFO Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_VERSION Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_128 Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_KEY_EXCH Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP: Set final flags: Jan 12 15:14:09 volumio volumio[1178]: Got NTLMSSP neg_flags=0x62008215 Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_UNICODE Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_REQUEST_TARGET Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_SIGN Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_NTLM Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_VERSION Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_128 Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_KEY_EXCH Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP Sign/Seal - Initialising with flags: Jan 12 15:14:09 volumio volumio[1178]: Got NTLMSSP neg_flags=0x62008215 Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_UNICODE Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_REQUEST_TARGET Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_SIGN Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_NTLM Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_VERSION Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_128 Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_KEY_EXCH Jan 12 15:14:09 volumio volumio[1178]: SPNEGO login failed: The attempted logon is invalid. This is either due to a bad username or authentication information. Jan 12 15:14:09 volumio volumio[1178]: Got challenge flags: Jan 12 15:14:09 volumio volumio[1178]: Got NTLMSSP neg_flags=0x628a8215 Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_UNICODE Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_REQUEST_TARGET Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_SIGN Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_NTLM Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_TARGET_TYPE_SERVER Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_TARGET_INFO Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_VERSION Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_128 Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_KEY_EXCH Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP: Set final flags: Jan 12 15:14:09 volumio volumio[1178]: Got NTLMSSP neg_flags=0x62008a15 Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_UNICODE Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_REQUEST_TARGET Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_SIGN Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_NTLM Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_ANONYMOUS Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_VERSION Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_128 Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_KEY_EXCH Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP Sign/Seal - Initialising with flags: Jan 12 15:14:09 volumio volumio[1178]: Got NTLMSSP neg_flags=0x62008a15 Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_UNICODE Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_REQUEST_TARGET Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_SIGN Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_NTLM Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_ANONYMOUS Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_VERSION Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_128 Jan 12 15:14:09 volumio volumio[1178]: NTLMSSP_NEGOTIATE_KEY_EXCH Jan 12 15:14:09 volumio volumio[1178]: SPNEGO login failed: The attempted logon is invalid. This is either due to a bad username or authentication information. Jan 12 15:14:09 volumio volumio[1178]: info: Detected device nas_music with version null Jan 12 15:14:09 volumio sudo[2791]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=mzlo,password=lo1853,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.100.9/music /mnt/NAS/nas_music Jan 12 15:14:09 volumio sudo[2791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 15:14:09 volumio kernel: netfs: FS-Cache loaded Jan 12 15:14:09 volumio kernel: Key type cifs.spnego registered Jan 12 15:14:09 volumio kernel: Key type cifs.idmap registered Jan 12 15:14:09 volumio kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. Jan 12 15:14:09 volumio kernel: CIFS: Attempting to mount //192.168.100.9/music Jan 12 15:14:10 volumio sudo[2791]: pam_unix(sudo:session): session closed for user root Jan 12 15:14:10 volumio volumio[1178]: verbose: ControllerMpd::sendMpdCommand status Jan 12 15:14:10 volumio volumio[1178]: info: Jan 12 15:14:10 volumio volumio[1178]: ---------------------------- MPD announces state update: update Jan 12 15:14:10 volumio volumio[1178]: info: ControllerMpd::getState Jan 12 15:14:10 volumio volumio[1178]: verbose: ControllerMpd::sendMpdCommand status Jan 12 15:14:10 volumio volumio[1178]: verbose: ControllerMpd::sendMpdCommand status Jan 12 15:14:10 volumio volumio[1178]: info: Jan 12 15:14:10 volumio volumio[1178]: ---------------------------- MPD announces state update: update Jan 12 15:14:10 volumio volumio[1178]: info: ControllerMpd::getState Jan 12 15:14:10 volumio volumio[1178]: verbose: ControllerMpd::sendMpdCommand status Jan 12 15:14:10 volumio volumio[1178]: info: [1768202050193] Database update started Jan 12 15:14:10 volumio volumio[1178]: info: sendMpdCommand status took 27 milliseconds Jan 12 15:14:10 volumio volumio[1178]: info: sendMpdCommand status took 27 milliseconds Jan 12 15:14:10 volumio volumio[1178]: info: sendMpdCommand status took 51 milliseconds Jan 12 15:14:10 volumio volumio[1178]: info: sendMpdCommand status took 50 milliseconds Jan 12 15:14:10 volumio volumio[1178]: verbose: ControllerMpd::parseState Jan 12 15:14:10 volumio volumio[1178]: info: Command Router : Notfying DB Updatetrue Jan 12 15:14:10 volumio volumio[1178]: verbose: ControllerMpd::parseState Jan 12 15:14:10 volumio volumio[1178]: verbose: ControllerMpd::parseState Jan 12 15:14:10 volumio volumio[1178]: info: Command Router : Notfying DB Updatetrue Jan 12 15:14:10 volumio volumio[1178]: info: CoreCommandRouter::Close All Modals sent Jan 12 15:14:10 volumio volumio[1178]: verbose: ControllerMpd::parseState Jan 12 15:14:10 volumio volumio[1178]: info: ControllerMpd::pushState Jan 12 15:14:10 volumio volumio[1178]: info: CoreCommandRouter::servicePushState Jan 12 15:14:10 volumio volumio[1178]: info: CoreStateMachine::pushState Jan 12 15:14:10 volumio volumio[1178]: info: CorePlayQueue::getTrack 0 Jan 12 15:14:10 volumio volumio[1178]: info: CoreCommandRouter::volumioPushState Jan 12 15:14:10 volumio volumio[1178]: info: CorePlayQueue::getTrack 0 Jan 12 15:14:10 volumio volumio[1178]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jan 12 15:14:10 volumio volumio[1178]: verbose: CURRENT POSITION 0 Jan 12 15:14:10 volumio volumio[1178]: info: CoreStateMachine::syncState stateService stop Jan 12 15:14:10 volumio volumio[1178]: info: CoreStateMachine::syncState currentStatus stop Jan 12 15:14:10 volumio volumio[1178]: info: CoreStateMachine::pushState Jan 12 15:14:10 volumio volumio[1178]: info: CorePlayQueue::getTrack 0 Jan 12 15:14:10 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 15:14:10 volumio volumio[1178]: info: CoreCommandRouter::volumioPushState Jan 12 15:14:10 volumio volumio[1178]: info: No code Jan 12 15:14:10 volumio volumio[1178]: info: CoreStateMachine::pushState Jan 12 15:14:10 volumio volumio[1178]: info: CorePlayQueue::getTrack 0 Jan 12 15:14:10 volumio volumio[1178]: info: CoreCommandRouter::volumioPushState Jan 12 15:14:10 volumio volumio[1178]: info: ControllerMpd::pushState Jan 12 15:14:10 volumio volumio[1178]: info: CoreCommandRouter::servicePushState Jan 12 15:14:10 volumio volumio[1178]: info: CoreStateMachine::pushState Jan 12 15:14:10 volumio volumio[1178]: info: CorePlayQueue::getTrack 0 Jan 12 15:14:10 volumio volumio[1178]: info: CoreCommandRouter::volumioPushState Jan 12 15:14:10 volumio volumio[1178]: info: CorePlayQueue::getTrack 0 Jan 12 15:14:10 volumio volumio[1178]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jan 12 15:14:10 volumio volumio[1178]: verbose: CURRENT POSITION 0 Jan 12 15:14:10 volumio volumio[1178]: info: CoreStateMachine::syncState stateService stop Jan 12 15:14:10 volumio volumio[1178]: info: CoreStateMachine::syncState currentStatus stop Jan 12 15:14:10 volumio volumio[1178]: info: CoreStateMachine::pushState Jan 12 15:14:10 volumio volumio[1178]: info: CorePlayQueue::getTrack 0 Jan 12 15:14:10 volumio volumio[1178]: info: CoreCommandRouter::volumioPushState Jan 12 15:14:10 volumio volumio[1178]: info: No code Jan 12 15:14:10 volumio volumio[1178]: info: CoreStateMachine::pushState Jan 12 15:14:10 volumio volumio[1178]: info: CorePlayQueue::getTrack 0 Jan 12 15:14:10 volumio volumio[1178]: info: CoreCommandRouter::volumioPushState Jan 12 15:14:10 volumio volumio[1178]: info: ------------------------------ 567ms Jan 12 15:14:10 volumio volumio[1178]: info: ------------------------------ 599ms Jan 12 15:14:11 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jan 12 15:14:12 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 15:14:12 volumio volumio[1178]: info: Enabling MyMusic plugin cd_controller Jan 12 15:14:12 volumio volumio[1178]: info: [MyVolumio PluginManager] Enabling and starting plugin music_service cd_controller Jan 12 15:14:12 volumio volumio[1178]: info: [MyVolumio PluginManager] Plugin music_service cd_controller not in user plan, not enabling Jan 12 15:14:12 volumio volumio[1178]: info: Error: Plugin music_service cd_controller not in user plan, not enabling Jan 12 15:14:12 volumio volumio[1178]: error: Could not Enable MyMusic Plugin: Error Jan 12 15:14:16 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 15:14:20 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 15:14:24 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 15:14:28 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 15:14:32 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jan 12 15:14:36 volumio volumio[1178]: info: CoreCommandRouter::volumioGetState Jan 12 15:14:36 volumio volumio[1178]: info: CorePlayQueue::getTrack 0 Jan 12 15:14:37 volumio volumio[1178]: info: CoreCommandRouter::volumioGetQueue Jan 12 15:14:37 volumio volumio[1178]: info: CoreStateMachine::getQueue Jan 12 15:14:37 volumio volumio[1178]: info: CorePlayQueue::getQueue Jan 12 15:14:38 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jan 12 15:14:38 volumio volumio[1178]: info: CURURI: music-library Jan 12 15:14:38 volumio volumio[1178]: info: Preload queue cleared Jan 12 15:14:39 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jan 12 15:14:39 volumio volumio[1178]: info: CURURI: music-library/NAS Jan 12 15:14:40 volumio volumio[1178]: info: Preload queue cleared Jan 12 15:14:41 volumio volumio[1178]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jan 12 15:14:41 volumio volumio[1178]: info: CURURI: music-library/NAS/nas_music Jan 12 15:14:41 volumio volumio[1178]: info: Preload queue cleared Jan 12 15:14:41 volumio volumio[1178]: info: Preloading song: music-library/NAS/nas_music/iptv.m3u Jan 12 15:14:41 volumio volumio[1178]: info: Exploding uri music-library/NAS/nas_music/iptv.m3u in service mpd Jan 12 15:14:42 volumio kernel: CIFS: VFS: \\192.168.100.9 Invalid mid allocation time Jan 12 15:14:42 volumio kernel: CIFS: VFS: \\192.168.100.9 Invalid mid allocation time Jan 12 15:14:42 volumio kernel: CIFS: VFS: \\192.168.100.9 Invalid mid allocation time Jan 12 15:14:42 volumio kernel: CIFS: VFS: \\192.168.100.9 Invalid mid allocation time Jan 12 15:14:42 volumio kernel: CIFS: VFS: \\192.168.100.9 Invalid mid allocation time Jan 12 15:14:44 volumio volumio[1178]: info: Preload queue cleared Jan 12 15:14:44 volumio volumio[1178]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 12 15:14:44 volumio volumio[1178]: info: CoreStateMachine::ClearQueue Jan 12 15:14:44 volumio volumio[1178]: info: CoreStateMachine::stop Jan 12 15:14:44 volumio volumio[1178]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 12 15:14:44 volumio volumio[1178]: info: CorePlayQueue::clearPlayQueue Jan 12 15:14:44 volumio volumio[1178]: info: CorePlayQueue::saveQueue Jan 12 15:14:44 volumio volumio[1178]: info: CoreCommandRouter::volumioPushQueue Jan 12 15:14:44 volumio volumio[1178]: info: CoreStateMachine::addQueueItems Jan 12 15:14:44 volumio volumio[1178]: info: CorePlayQueue::addQueueItems Jan 12 15:14:44 volumio volumio[1178]: info: Preload queue cleared Jan 12 15:14:44 volumio volumio[1178]: info: Adding Item to queue: music-library/NAS/nas_music/ZARD Jan 12 15:14:44 volumio volumio[1178]: info: Exploding uri music-library/NAS/nas_music/ZARD in service mpd Jan 12 15:14:44 volumio volumio[1178]: info: ALBUMART /albumart?cacheid=369&web=/Golden%20Best%2015th%20Anniversary%20DISC%201/extralarge&path=%2Fmnt%2FNAS%2Fnas_music%2FZARD%2FZARD-Golden%20Best%EF%BD%9E15Th%20Anniversary%EF%BD%9E(%E5%88%9D%E5%9B%9E%E9%99%90%E5%AE%9A%E7%9B%A4)(2%E6%9E%9A%E7%B5%84)%2FZARD%20-%20Golden%20Best%2015th%20Anniversary%20DISC%201).cue&metadata=false Jan 12 15:14:44 volumio volumio[1178]: info: URI /mnt/NAS/nas_music/ZARD/ZARD-Golden Best～15Th Anniversary～(初回限定盤)(2枚組)/ZARD - Golden Best 15th Anniversary DISC 1).cue Jan 12 15:14:44 volumio volumio[1178]: info: ALBUMART /albumart?cacheid=369&web=/Golden%20Best%2015th%20Anniversary%20DISC%201/extralarge&path=%2Fmnt%2FNAS%2Fnas_music%2FZARD%2FZARD-Golden%20Best%EF%BD%9E15Th%20Anniversary%EF%BD%9E(%E5%88%9D%E5%9B%9E%E9%99%90%E5%AE%9A%E7%9B%A4)(2%E6%9E%9A%E7%B5%84)%2FZARD%20-%20Golden%20Best%2015th%20Anniversary%20DISC%201).cue&metadata=false Jan 12 15:14:44 volumio volumio[1178]: info: URI /mnt/NAS/nas_music/ZARD/ZARD-Golden Best～15Th Anniversary～(初回限定盤)(2枚組)/ZARD - Golden Best 15th Anniversary DISC 1).cue Jan 12 15:14:44 volumio volumio[1178]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 15:14:44 volumio volumio[1178]: Error: Unable to resolve or reject the same promise twice Jan 12 15:14:44 volumio volumio[1178]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Jan 12 15:14:44 volumio volumio[1178]: at /volumio/app/plugins/music_service/mpd/index.js:2587:21 Jan 12 15:14:44 volumio volumio[1178]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3) Jan 12 15:14:44 volumio volumio[1178]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12) Jan 12 15:14:44 volumio volumio[1178]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12) Jan 12 15:14:44 volumio volumio[1178]: at Socket.emit (node:events:514:28) Jan 12 15:14:44 volumio volumio[1178]: at addChunk (node:internal/streams/readable:343:12) Jan 12 15:14:44 volumio volumio[1178]: at readableAddChunk (node:internal/streams/readable:312:11) Jan 12 15:14:44 volumio volumio[1178]: at Readable.push (node:internal/streams/readable:253:10) Jan 12 15:14:44 volumio volumio[1178]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23) Jan 12 15:14:44 volumio volumio[1178]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 15:14:44 volumio sudo[2950]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-12 15:13' Jan 12 15:14:44 volumio sudo[2950]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"