-- Logs begin at Thu 2019-02-14 17:11:58 +07, end at Sat 2025-05-24 08:27:27 +07. -- May 24 08:26:00 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 24 08:26:00 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 24 08:26:00 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 24 08:26:02 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 24 08:26:06 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 24 08:26:06 volumio9 volumio[8002]: info: BOOT COMPLETED May 24 08:26:10 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 24 08:26:14 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 24 08:26:14 volumio9 go-librespot[8339]: time="2025-05-24T08:26:14+07:00" level=debug msg="fetched chunk 5/18, size: 524288" May 24 08:26:18 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 24 08:26:22 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: networkfs , addShare May 24 08:26:22 volumio9 volumio[8002]: info: Adding a new share May 24 08:26:22 volumio9 volumio[8002]: info: Checking key NasMounts.56883b36-8b56-4468-ac6c-38225f9d8b30 May 24 08:26:22 volumio9 volumio[8002]: info: Checking key NasMounts.8d2e2dcb-f65c-4099-bead-4963fb9a197e May 24 08:26:22 volumio9 volumio[8002]: info: No correspondence found in configuration for share Hires on IP 192.168.1.12 May 24 08:26:22 volumio9 volumio[8002]: info: Executing SMB command: smbclient --debuglevel=4 -L 192.168.1.12 -N May 24 08:26:22 volumio9 volumio[8002]: info: Error browsing device Hires for shares: Command failed: smbclient --debuglevel=4 -L 192.168.1.12 -N May 24 08:26:22 volumio9 volumio[8002]: lp_load_ex: refreshing parameters May 24 08:26:22 volumio9 volumio[8002]: Initialising global parameters May 24 08:26:22 volumio9 volumio[8002]: Processing section "[global]" May 24 08:26:22 volumio9 volumio[8002]: doing parameter netbios name = Volumio9 May 24 08:26:22 volumio9 volumio[8002]: doing parameter server string = Audiophile Music Player May 24 08:26:22 volumio9 volumio[8002]: doing parameter workgroup = WORKGROUP May 24 08:26:22 volumio9 volumio[8002]: doing parameter security = user May 24 08:26:22 volumio9 volumio[8002]: doing parameter map to guest = Bad User May 24 08:26:22 volumio9 volumio[8002]: doing parameter encrypt passwords = yes May 24 08:26:22 volumio9 volumio[8002]: doing parameter wins support = yes May 24 08:26:22 volumio9 volumio[8002]: doing parameter local master = no May 24 08:26:22 volumio9 volumio[8002]: doing parameter preferred master = no May 24 08:26:22 volumio9 volumio[8002]: doing parameter os level = 30 May 24 08:26:22 volumio9 volumio[8002]: pm_process() returned Yes May 24 08:26:22 volumio9 volumio[8002]: directory_create_or_exist_strict: invalid ownership on directory /var/run/samba/msg.lock May 24 08:26:22 volumio9 volumio[8002]: cmdline_messaging_context: Unable to initialize messaging context. May 24 08:26:22 volumio9 volumio[8002]: Unable to initialize messaging context May 24 08:26:22 volumio9 volumio[8002]: lp_load_ex: refreshing parameters May 24 08:26:22 volumio9 volumio[8002]: Initialising global parameters May 24 08:26:22 volumio9 volumio[8002]: Processing section "[global]" May 24 08:26:22 volumio9 volumio[8002]: doing parameter netbios name = Volumio9 May 24 08:26:22 volumio9 volumio[8002]: doing parameter server string = Audiophile Music Player May 24 08:26:22 volumio9 volumio[8002]: doing parameter workgroup = WORKGROUP May 24 08:26:22 volumio9 volumio[8002]: doing parameter security = user May 24 08:26:22 volumio9 volumio[8002]: doing parameter map to guest = Bad User May 24 08:26:22 volumio9 volumio[8002]: doing parameter encrypt passwords = yes May 24 08:26:22 volumio9 volumio[8002]: doing parameter wins support = yes May 24 08:26:22 volumio9 volumio[8002]: doing parameter local master = no May 24 08:26:22 volumio9 volumio[8002]: doing parameter preferred master = no May 24 08:26:22 volumio9 volumio[8002]: doing parameter os level = 30 May 24 08:26:22 volumio9 volumio[8002]: pm_process() returned Yes May 24 08:26:22 volumio9 volumio[8002]: added interface eth0 ip=192.168.1.6 bcast=192.168.1.255 netmask=255.255.255.0 May 24 08:26:22 volumio9 volumio[8002]: Client started (version 4.9.5-Debian). May 24 08:26:22 volumio9 volumio[8002]: Connecting to 192.168.1.12 at port 445 May 24 08:26:22 volumio9 volumio[8002]: session request ok May 24 08:26:22 volumio9 volumio[8002]: negotiated dialect[SMB3_11] against server[192.168.1.12] May 24 08:26:22 volumio9 volumio[8002]: got OID=1.3.6.1.4.1.311.2.2.10 May 24 08:26:22 volumio9 volumio[8002]: GENSEC backend 'gssapi_spnego' registered May 24 08:26:22 volumio9 volumio[8002]: GENSEC backend 'gssapi_krb5' registered May 24 08:26:22 volumio9 volumio[8002]: GENSEC backend 'gssapi_krb5_sasl' registered May 24 08:26:22 volumio9 volumio[8002]: GENSEC backend 'spnego' registered May 24 08:26:22 volumio9 volumio[8002]: GENSEC backend 'schannel' registered May 24 08:26:22 volumio9 volumio[8002]: GENSEC backend 'naclrpc_as_system' registered May 24 08:26:22 volumio9 volumio[8002]: GENSEC backend 'sasl-EXTERNAL' registered May 24 08:26:22 volumio9 volumio[8002]: GENSEC backend 'ntlmssp' registered May 24 08:26:22 volumio9 volumio[8002]: GENSEC backend 'ntlmssp_resume_ccache' registered May 24 08:26:22 volumio9 volumio[8002]: GENSEC backend 'http_basic' registered May 24 08:26:22 volumio9 volumio[8002]: GENSEC backend 'http_ntlm' registered May 24 08:26:22 volumio9 volumio[8002]: GENSEC backend 'http_negotiate' registered May 24 08:26:22 volumio9 volumio[8002]: GENSEC backend 'krb5' registered May 24 08:26:22 volumio9 volumio[8002]: GENSEC backend 'fake_gssapi_krb5' registered May 24 08:26:22 volumio9 volumio[8002]: Got challenge flags: May 24 08:26:22 volumio9 volumio[8002]: Got NTLMSSP neg_flags=0x628a8215 May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_UNICODE May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_REQUEST_TARGET May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_SIGN May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_NTLM May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_TARGET_TYPE_SERVER May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_TARGET_INFO May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_VERSION May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_128 May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_KEY_EXCH May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP: Set final flags: May 24 08:26:22 volumio9 volumio[8002]: Got NTLMSSP neg_flags=0x62008215 May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_UNICODE May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_REQUEST_TARGET May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_SIGN May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_NTLM May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_VERSION May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_128 May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_KEY_EXCH May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP Sign/Seal - Initialising with flags: May 24 08:26:22 volumio9 volumio[8002]: Got NTLMSSP neg_flags=0x62008215 May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_UNICODE May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_REQUEST_TARGET May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_SIGN May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_NTLM May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_VERSION May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_128 May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_KEY_EXCH May 24 08:26:22 volumio9 volumio[8002]: SPNEGO login failed: The attempted logon is invalid. This is either due to a bad username or authentication information. May 24 08:26:22 volumio9 volumio[8002]: got OID=1.3.6.1.4.1.311.2.2.10 May 24 08:26:22 volumio9 volumio[8002]: Got challenge flags: May 24 08:26:22 volumio9 volumio[8002]: Got NTLMSSP neg_flags=0x628a8215 May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_UNICODE May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_REQUEST_TARGET May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_SIGN May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_NTLM May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_TARGET_TYPE_SERVER May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_TARGET_INFO May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_VERSION May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_128 May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_KEY_EXCH May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP: Set final flags: May 24 08:26:22 volumio9 volumio[8002]: Got NTLMSSP neg_flags=0x62008a15 May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_UNICODE May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_REQUEST_TARGET May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_SIGN May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_NTLM May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_ANONYMOUS May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_VERSION May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_128 May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_KEY_EXCH May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP Sign/Seal - Initialising with flags: May 24 08:26:22 volumio9 volumio[8002]: Got NTLMSSP neg_flags=0x62008a15 May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_UNICODE May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_REQUEST_TARGET May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_SIGN May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_NTLM May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_ANONYMOUS May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_VERSION May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_128 May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_KEY_EXCH May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP Sign/Seal - Initialising with flags: May 24 08:26:22 volumio9 volumio[8002]: Got NTLMSSP neg_flags=0x62008a15 May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_UNICODE May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_REQUEST_TARGET May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_SIGN May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_NTLM May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_ANONYMOUS May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_VERSION May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_128 May 24 08:26:22 volumio9 volumio[8002]: NTLMSSP_NEGOTIATE_KEY_EXCH May 24 08:26:22 volumio9 volumio[8002]: session setup ok May 24 08:26:22 volumio9 volumio[8002]: info: Detected device Hires with version null May 24 08:26:22 volumio9 sudo[8588]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=Santichai,password=MmXp3152,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.12/Hires /mnt/NAS/Hires May 24 08:26:22 volumio9 sudo[8588]: pam_unix(sudo:session): session opened for user root by (uid=0) May 24 08:26:22 volumio9 kernel: CIFS: Attempting to mount //192.168.1.12/Hires May 24 08:26:22 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 24 08:26:22 volumio9 sudo[8588]: pam_unix(sudo:session): session closed for user root May 24 08:26:22 volumio9 volumio[8002]: verbose: ControllerMpd::sendMpdCommand status May 24 08:26:22 volumio9 volumio[8002]: info: May 24 08:26:22 volumio9 volumio[8002]: ---------------------------- MPD announces state update: update May 24 08:26:22 volumio9 volumio[8002]: info: ControllerMpd::getState May 24 08:26:22 volumio9 volumio[8002]: verbose: ControllerMpd::sendMpdCommand status May 24 08:26:22 volumio9 volumio[8002]: verbose: ControllerMpd::sendMpdCommand status May 24 08:26:22 volumio9 volumio[8002]: info: May 24 08:26:22 volumio9 volumio[8002]: ---------------------------- MPD announces state update: update May 24 08:26:22 volumio9 volumio[8002]: info: ControllerMpd::getState May 24 08:26:22 volumio9 volumio[8002]: verbose: ControllerMpd::sendMpdCommand status May 24 08:26:22 volumio9 volumio[8002]: verbose: ControllerMpd::sendMpdCommand status May 24 08:26:22 volumio9 volumio[8002]: info: May 24 08:26:22 volumio9 volumio[8002]: ---------------------------- MPD announces state update: update May 24 08:26:22 volumio9 volumio[8002]: info: ControllerMpd::getState May 24 08:26:22 volumio9 volumio[8002]: verbose: ControllerMpd::sendMpdCommand status May 24 08:26:22 volumio9 volumio[8002]: info: sendMpdCommand status took 8 milliseconds May 24 08:26:22 volumio9 volumio[8002]: info: sendMpdCommand status took 5 milliseconds May 24 08:26:22 volumio9 volumio[8002]: info: sendMpdCommand status took 6 milliseconds May 24 08:26:22 volumio9 volumio[8002]: info: sendMpdCommand status took 5 milliseconds May 24 08:26:22 volumio9 volumio[8002]: info: sendMpdCommand status took 4 milliseconds May 24 08:26:22 volumio9 volumio[8002]: info: sendMpdCommand status took 3 milliseconds May 24 08:26:22 volumio9 volumio[8002]: verbose: ControllerMpd::parseState May 24 08:26:23 volumio9 volumio[8002]: info: Command Router : Notfying DB Updatetrue May 24 08:26:23 volumio9 volumio[8002]: verbose: ControllerMpd::parseState May 24 08:26:23 volumio9 volumio[8002]: verbose: ControllerMpd::parseState May 24 08:26:23 volumio9 volumio[8002]: info: Command Router : Notfying DB Updatetrue May 24 08:26:23 volumio9 volumio[8002]: info: CoreCommandRouter::Close All Modals sent May 24 08:26:23 volumio9 volumio[8002]: verbose: ControllerMpd::parseState May 24 08:26:23 volumio9 volumio[8002]: verbose: ControllerMpd::parseState May 24 08:26:23 volumio9 volumio[8002]: info: Command Router : Notfying DB Updatetrue May 24 08:26:23 volumio9 volumio[8002]: info: CoreCommandRouter::Close All Modals sent May 24 08:26:23 volumio9 volumio[8002]: verbose: ControllerMpd::parseState May 24 08:26:23 volumio9 volumio[8002]: info: ControllerMpd::pushState May 24 08:26:23 volumio9 volumio[8002]: info: CoreCommandRouter::servicePushState May 24 08:26:23 volumio9 volumio[8002]: info: CoreStateMachine::pushState May 24 08:26:23 volumio9 volumio[8002]: info: CorePlayQueue::getTrack 0 May 24 08:26:23 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 08:26:23 volumio9 volumio[8002]: info: CoreCommandRouter::volumioPushState May 24 08:26:23 volumio9 volumio[8002]: info: CorePlayQueue::getTrack 0 May 24 08:26:23 volumio9 volumio[8002]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd May 24 08:26:23 volumio9 volumio[8002]: info: ControllerMpd::pushState May 24 08:26:23 volumio9 volumio[8002]: info: CoreCommandRouter::servicePushState May 24 08:26:23 volumio9 volumio[8002]: info: CoreStateMachine::pushState May 24 08:26:23 volumio9 volumio[8002]: info: CorePlayQueue::getTrack 0 May 24 08:26:23 volumio9 volumio[8002]: info: CoreCommandRouter::volumioPushState May 24 08:26:23 volumio9 volumio[8002]: info: CorePlayQueue::getTrack 0 May 24 08:26:23 volumio9 volumio[8002]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd May 24 08:26:23 volumio9 volumio[8002]: info: ControllerMpd::pushState May 24 08:26:23 volumio9 volumio[8002]: info: CoreCommandRouter::servicePushState May 24 08:26:23 volumio9 volumio[8002]: info: CoreStateMachine::pushState May 24 08:26:23 volumio9 volumio[8002]: info: CorePlayQueue::getTrack 0 May 24 08:26:23 volumio9 volumio[8002]: info: CoreCommandRouter::volumioPushState May 24 08:26:23 volumio9 volumio[8002]: info: CorePlayQueue::getTrack 0 May 24 08:26:23 volumio9 volumio[8002]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd May 24 08:26:23 volumio9 volumio[8002]: info: ------------------------------ 286ms May 24 08:26:23 volumio9 volumio[8002]: info: ------------------------------ 283ms May 24 08:26:23 volumio9 volumio[8002]: info: ------------------------------ 282ms May 24 08:26:23 volumio9 volumio[8002]: info: [1748049983237] Database update started May 24 08:26:23 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares May 24 08:26:26 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 24 08:26:29 volumio9 sudo[8438]: pam_unix(sudo:session): session closed for user root May 24 08:26:29 volumio9 volumio[8002]: info: Cannot mount NAS Hires at system boot, trial number 2 ,retrying in 5 seconds May 24 08:26:30 volumio9 go-librespot[8339]: time="2025-05-24T08:26:30+07:00" level=debug msg="fetched chunk 6/18, size: 524288" May 24 08:26:30 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 24 08:26:34 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 24 08:26:34 volumio9 volumio[8002]: info: Cannot mount NAS Hires at system boot, trial number 3 ,retrying in 5 seconds May 24 08:26:38 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 24 08:26:39 volumio9 volumio[8002]: info: Cannot mount NAS Hires at system boot, trial number 4 ,retrying in 5 seconds May 24 08:26:42 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 24 08:26:44 volumio9 volumio[8002]: info: Cannot mount NAS at system boot, trial number 4 ,stopping May 24 08:26:46 volumio9 go-librespot[8339]: time="2025-05-24T08:26:46+07:00" level=debug msg="fetched chunk 7/18, size: 524288" May 24 08:26:46 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 24 08:26:50 volumio9 volumio[8002]: info: CoreCommandRouter::volumioGetState May 24 08:26:50 volumio9 volumio[8002]: info: CorePlayQueue::getTrack 0 May 24 08:26:58 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 24 08:26:58 volumio9 volumio[8002]: info: CURURI: music-library May 24 08:26:58 volumio9 volumio[8002]: info: Preload queue cleared May 24 08:26:59 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 24 08:26:59 volumio9 volumio[8002]: info: CURURI: music-library/NAS May 24 08:26:59 volumio9 volumio[8002]: info: Preload queue cleared May 24 08:27:00 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 24 08:27:00 volumio9 volumio[8002]: info: CURURI: music-library/NAS/Music_Server May 24 08:27:00 volumio9 volumio[8002]: info: Preload queue cleared May 24 08:27:02 volumio9 go-librespot[8339]: time="2025-05-24T08:27:02+07:00" level=debug msg="fetched chunk 8/18, size: 524288" May 24 08:27:05 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 24 08:27:05 volumio9 volumio[8002]: info: CURURI: music-library/INTERNAL May 24 08:27:05 volumio9 volumio[8002]: info: Preload queue cleared May 24 08:27:10 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 24 08:27:10 volumio9 volumio[8002]: info: Preload queue cleared May 24 08:27:13 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 24 08:27:13 volumio9 volumio[8002]: error: Error browsing0:Error: Did not get expected response from server:{"html":{"$":{"xmlns":"http://www.w3.org/1999/xhtml","xml:lang":"en","lang":"en"},"head":[{"title":[{"_":"404 - Not Found"}]}],"body":[{"h1":[{"_":"404 - Not Found"}]}]}} May 24 08:27:13 volumio9 volumio[8002]: error: Failed to execute browseSource: May 24 08:27:16 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 24 08:27:16 volumio9 volumio[8002]: info: Preload queue cleared May 24 08:27:16 volumio9 volumio[8002]: info: Preloading song: upnp/http://192.168.1.13:9000/dev0/srv1/control@0 May 24 08:27:16 volumio9 volumio[8002]: info: Exploding uri upnp/http://192.168.1.13:9000/dev0/srv1/control@0 in service upnp_browser May 24 08:27:16 volumio9 volumio[8002]: info: No valid Plugin REST Endpoint May 24 08:27:16 volumio9 volumio[8002]: info: No valid Plugin REST Endpoint May 24 08:27:17 volumio9 go-librespot[8339]: time="2025-05-24T08:27:17+07:00" level=debug msg="fetched chunk 9/18, size: 524288" May 24 08:27:19 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 24 08:27:19 volumio9 volumio[8002]: info: Preload queue cleared May 24 08:27:22 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 24 08:27:22 volumio9 volumio[8002]: info: Preload queue cleared May 24 08:27:27 volumio9 volumio[8002]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 24 08:27:27 volumio9 volumio[8002]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 24 08:27:27 volumio9 volumio[8002]: TypeError: Cannot read property 'length' of undefined May 24 08:27:27 volumio9 volumio[8002]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 May 24 08:27:27 volumio9 volumio[8002]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 May 24 08:27:27 volumio9 volumio[8002]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) May 24 08:27:27 volumio9 volumio[8002]: at Parser.emit (events.js:315:20) May 24 08:27:27 volumio9 volumio[8002]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) May 24 08:27:27 volumio9 volumio[8002]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) May 24 08:27:27 volumio9 volumio[8002]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) May 24 08:27:27 volumio9 volumio[8002]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) May 24 08:27:27 volumio9 volumio[8002]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) May 24 08:27:27 volumio9 volumio[8002]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) May 24 08:27:27 volumio9 volumio[8002]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) May 24 08:27:27 volumio9 volumio[8002]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) May 24 08:27:27 volumio9 volumio[8002]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) May 24 08:27:27 volumio9 volumio[8002]: at IncomingMessage.emit (events.js:327:22) May 24 08:27:27 volumio9 volumio[8002]: at endReadableNT (internal/streams/readable.js:1327:12) May 24 08:27:27 volumio9 volumio[8002]: at processTicksAndRejections (internal/process/task_queues.js:80:21) May 24 08:27:27 volumio9 volumio[8002]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 24 08:27:27 volumio9 sudo[8796]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-24 08:26 May 24 08:27:27 volumio9 sudo[8796]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"