Aug 28 03:26:02 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:26:06 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:26:10 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:26:14 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:26:18 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:26:22 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:26:26 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:26:30 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:26:34 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:26:38 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: networkfs , addShare Aug 28 03:26:38 volumio volumio[1057]: info: Adding a new share Aug 28 03:26:38 volumio volumio[1057]: info: Checking key NasMounts.7e908baa-67df-4a93-b61b-038cc1378832 Aug 28 03:26:38 volumio volumio[1057]: info: No correspondence found in configuration for share SA6400732 on IP 192.168.3.158 Aug 28 03:26:38 volumio volumio[1057]: info: Executing SMB command: smbclient --debuglevel=4 -L 192.168.3.158 -N -m SMB3_11 Aug 28 03:26:38 volumio volumio[1057]: info: Error browsing device SA6400732 for shares: Command failed: smbclient --debuglevel=4 -L 192.168.3.158 -N -m SMB3_11 Aug 28 03:26:38 volumio volumio[1057]: lp_load_ex: refreshing parameters Aug 28 03:26:38 volumio volumio[1057]: Initialising global parameters Aug 28 03:26:38 volumio volumio[1057]: Processing section "[global]" Aug 28 03:26:38 volumio volumio[1057]: doing parameter netbios name = Volumio Aug 28 03:26:38 volumio volumio[1057]: doing parameter server string = Volumio Audiophile Music Player Aug 28 03:26:38 volumio volumio[1057]: doing parameter workgroup = WORKGROUP Aug 28 03:26:38 volumio volumio[1057]: doing parameter security = user Aug 28 03:26:38 volumio volumio[1057]: doing parameter map to guest = Bad User Aug 28 03:26:38 volumio volumio[1057]: doing parameter encrypt passwords = yes Aug 28 03:26:38 volumio volumio[1057]: lpcfg_do_global_parameter: WARNING: The "encrypt passwords" option is deprecated Aug 28 03:26:38 volumio volumio[1057]: doing parameter wins support = yes Aug 28 03:26:38 volumio volumio[1057]: doing parameter local master = no Aug 28 03:26:38 volumio volumio[1057]: doing parameter preferred master = no Aug 28 03:26:38 volumio volumio[1057]: doing parameter os level = 30 Aug 28 03:26:38 volumio volumio[1057]: doing parameter fruit:model = AirPort Aug 28 03:26:38 volumio volumio[1057]: pm_process() returned Yes Aug 28 03:26:38 volumio volumio[1057]: added interface eth0 ip=192.168.3.196 bcast=192.168.3.255 netmask=255.255.255.0 Aug 28 03:26:38 volumio volumio[1057]: Client started (version 4.17.8-Raspbian). Aug 28 03:26:38 volumio volumio[1057]: Connecting to 192.168.3.158 at port 445 Aug 28 03:26:38 volumio volumio[1057]: session request ok Aug 28 03:26:38 volumio volumio[1057]: negotiated dialect[SMB3_11] against server[192.168.3.158] Aug 28 03:26:38 volumio volumio[1057]: GENSEC backend 'gssapi_spnego' registered Aug 28 03:26:38 volumio volumio[1057]: GENSEC backend 'gssapi_krb5' registered Aug 28 03:26:38 volumio volumio[1057]: GENSEC backend 'gssapi_krb5_sasl' registered Aug 28 03:26:38 volumio volumio[1057]: GENSEC backend 'spnego' registered Aug 28 03:26:38 volumio volumio[1057]: GENSEC backend 'schannel' registered Aug 28 03:26:38 volumio volumio[1057]: GENSEC backend 'ncalrpc_as_system' registered Aug 28 03:26:38 volumio volumio[1057]: GENSEC backend 'sasl-EXTERNAL' registered Aug 28 03:26:38 volumio volumio[1057]: GENSEC backend 'ntlmssp' registered Aug 28 03:26:38 volumio volumio[1057]: GENSEC backend 'ntlmssp_resume_ccache' registered Aug 28 03:26:38 volumio volumio[1057]: GENSEC backend 'http_basic' registered Aug 28 03:26:38 volumio volumio[1057]: GENSEC backend 'http_ntlm' registered Aug 28 03:26:38 volumio volumio[1057]: GENSEC backend 'http_negotiate' registered Aug 28 03:26:38 volumio volumio[1057]: GENSEC backend 'krb5' registered Aug 28 03:26:38 volumio volumio[1057]: GENSEC backend 'fake_gssapi_krb5' registered Aug 28 03:26:38 volumio volumio[1057]: Cannot do GSE to an IP address Aug 28 03:26:38 volumio volumio[1057]: Failed to start GENSEC client mech gse_krb5: NT_STATUS_INVALID_PARAMETER Aug 28 03:26:38 volumio volumio[1057]: Got challenge flags: Aug 28 03:26:38 volumio volumio[1057]: Got NTLMSSP neg_flags=0x628a8215 Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_UNICODE Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_REQUEST_TARGET Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_SIGN Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_NTLM Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_TARGET_TYPE_SERVER Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_TARGET_INFO Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_VERSION Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_128 Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_KEY_EXCH Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP: Set final flags: Aug 28 03:26:38 volumio volumio[1057]: Got NTLMSSP neg_flags=0x62008215 Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_UNICODE Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_REQUEST_TARGET Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_SIGN Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_NTLM Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_VERSION Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_128 Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_KEY_EXCH Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP Sign/Seal - Initialising with flags: Aug 28 03:26:38 volumio volumio[1057]: Got NTLMSSP neg_flags=0x62008215 Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_UNICODE Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_REQUEST_TARGET Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_SIGN Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_NTLM Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_VERSION Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_128 Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_KEY_EXCH Aug 28 03:26:38 volumio volumio[1057]: SPNEGO login failed: The attempted logon is invalid. This is either due to a bad username or authentication information. Aug 28 03:26:38 volumio volumio[1057]: Got challenge flags: Aug 28 03:26:38 volumio volumio[1057]: Got NTLMSSP neg_flags=0x628a8215 Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_UNICODE Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_REQUEST_TARGET Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_SIGN Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_NTLM Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_TARGET_TYPE_SERVER Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_TARGET_INFO Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_VERSION Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_128 Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_KEY_EXCH Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP: Set final flags: Aug 28 03:26:38 volumio volumio[1057]: Got NTLMSSP neg_flags=0x62008a15 Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_UNICODE Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_REQUEST_TARGET Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_SIGN Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_NTLM Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_ANONYMOUS Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_VERSION Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_128 Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_KEY_EXCH Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP Sign/Seal - Initialising with flags: Aug 28 03:26:38 volumio volumio[1057]: Got NTLMSSP neg_flags=0x62008a15 Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_UNICODE Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_REQUEST_TARGET Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_SIGN Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_NTLM Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_ANONYMOUS Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_ALWAYS_SIGN Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_VERSION Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_128 Aug 28 03:26:38 volumio volumio[1057]: NTLMSSP_NEGOTIATE_KEY_EXCH Aug 28 03:26:38 volumio volumio[1057]: SPNEGO login failed: The attempted logon is invalid. This is either due to a bad username or authentication information. Aug 28 03:26:38 volumio volumio[1057]: info: Detected device SA6400732 with version null Aug 28 03:26:38 volumio sudo[2244]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.3.158/music /mnt/NAS/SA6400732 Aug 28 03:26:38 volumio sudo[2244]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 03:26:38 volumio kernel: CIFS: Attempting to mount //192.168.3.158/music Aug 28 03:26:38 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:26:39 volumio sudo[2244]: pam_unix(sudo:session): session closed for user root Aug 28 03:26:39 volumio kernel: CIFS: Status code returned 0xc000006d STATUS_LOGON_FAILURE Aug 28 03:26:39 volumio kernel: CIFS: VFS: \\192.168.3.158 Send error in SessSetup = -13 Aug 28 03:26:39 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -13 Aug 28 03:26:39 volumio volumio[1057]: info: Permission denied for SA6400732 on IP 192.168.3.158 Aug 28 03:26:40 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Aug 28 03:26:42 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:26:46 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: networkfs , editShare Aug 28 03:26:50 volumio volumio[1057]: info: Share SA6400732 successfully unmounted Aug 28 03:26:50 volumio sudo[2292]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=jack,password=751218Ok%,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.3.158/music /mnt/NAS/SA6400732 Aug 28 03:26:50 volumio sudo[2292]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 03:26:50 volumio kernel: CIFS: Attempting to mount //192.168.3.158/music Aug 28 03:26:50 volumio sudo[2292]: pam_unix(sudo:session): session closed for user root Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:26:50 volumio volumio[1057]: info: Aug 28 03:26:50 volumio volumio[1057]: ---------------------------- MPD announces state update: update Aug 28 03:26:50 volumio volumio[1057]: info: ControllerMpd::getState Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:26:50 volumio volumio[1057]: info: Aug 28 03:26:50 volumio volumio[1057]: ---------------------------- MPD announces state update: update Aug 28 03:26:50 volumio volumio[1057]: info: ControllerMpd::getState Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:26:50 volumio volumio[1057]: info: Aug 28 03:26:50 volumio volumio[1057]: ---------------------------- MPD announces state update: update Aug 28 03:26:50 volumio volumio[1057]: info: ControllerMpd::getState Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:26:50 volumio volumio[1057]: info: sendMpdCommand status took 8 milliseconds Aug 28 03:26:50 volumio volumio[1057]: info: sendMpdCommand status took 6 milliseconds Aug 28 03:26:50 volumio volumio[1057]: info: sendMpdCommand status took 6 milliseconds Aug 28 03:26:50 volumio volumio[1057]: info: sendMpdCommand status took 5 milliseconds Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:26:50 volumio volumio[1057]: info: Command Router : Notfying DB Updatetrue Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::Close All Modals sent Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:26:50 volumio volumio[1057]: info: Command Router : Notfying DB Updatetrue Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::Close All Modals sent Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:26:50 volumio volumio[1057]: info: ControllerMpd::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::servicePushState Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: 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} Aug 28 03:26:50 volumio volumio[1057]: verbose: CURRENT POSITION 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::syncState stateService stop Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::syncState currentStatus stop Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: No code Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: ControllerMpd::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::servicePushState Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: 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} Aug 28 03:26:50 volumio volumio[1057]: verbose: CURRENT POSITION 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::syncState stateService stop Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::syncState currentStatus stop Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: No code Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: ------------------------------ 135ms Aug 28 03:26:50 volumio volumio[1057]: info: ------------------------------ 133ms Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:26:50 volumio volumio[1057]: info: Aug 28 03:26:50 volumio volumio[1057]: ---------------------------- MPD announces state update: update Aug 28 03:26:50 volumio volumio[1057]: info: ControllerMpd::getState Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:26:50 volumio volumio[1057]: info: Aug 28 03:26:50 volumio volumio[1057]: ---------------------------- MPD announces state update: update Aug 28 03:26:50 volumio volumio[1057]: info: ControllerMpd::getState Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:26:50 volumio volumio[1057]: info: Aug 28 03:26:50 volumio volumio[1057]: ---------------------------- MPD announces state update: update Aug 28 03:26:50 volumio volumio[1057]: info: sendMpdCommand status took 137 milliseconds Aug 28 03:26:50 volumio volumio[1057]: info: sendMpdCommand status took 136 milliseconds Aug 28 03:26:50 volumio volumio[1057]: info: ControllerMpd::getState Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:26:50 volumio volumio[1057]: info: sendMpdCommand status took 6 milliseconds Aug 28 03:26:50 volumio volumio[1057]: info: sendMpdCommand status took 6 milliseconds Aug 28 03:26:50 volumio volumio[1057]: info: sendMpdCommand status took 5 milliseconds Aug 28 03:26:50 volumio volumio[1057]: info: sendMpdCommand status took 4 milliseconds Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:26:50 volumio volumio[1057]: info: Command Router : Notfying DB Updatetrue Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::Close All Modals sent Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:26:50 volumio volumio[1057]: info: Command Router : Notfying DB Updatefalse Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::Close All Modals sent Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:26:50 volumio volumio[1057]: info: Command Router : Notfying DB Updatefalse Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::Close All Modals sent Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:26:50 volumio volumio[1057]: info: ControllerMpd::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::servicePushState Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: 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} Aug 28 03:26:50 volumio volumio[1057]: verbose: CURRENT POSITION 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::syncState stateService stop Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::syncState currentStatus stop Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: No code Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: ControllerMpd::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::servicePushState Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 28 03:26:50 volumio volumio[1057]: verbose: CURRENT POSITION 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::syncState stateService stop Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::syncState currentStatus stop Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: No code Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: ControllerMpd::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::servicePushState Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 28 03:26:50 volumio volumio[1057]: verbose: CURRENT POSITION 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::syncState stateService stop Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::syncState currentStatus stop Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: No code Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: ------------------------------ 306ms Aug 28 03:26:50 volumio volumio[1057]: info: ------------------------------ 175ms Aug 28 03:26:50 volumio volumio[1057]: info: ------------------------------ 174ms Aug 28 03:26:50 volumio volumio[1057]: info: [1787858810556] Database update started Aug 28 03:26:50 volumio volumio[1057]: info: sendMpdCommand status took 252 milliseconds Aug 28 03:26:50 volumio volumio[1057]: info: sendMpdCommand status took 250 milliseconds Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:26:50 volumio volumio[1057]: info: Command Router : Notfying DB Updatefalse Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::Close All Modals sent Aug 28 03:26:50 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:26:50 volumio volumio[1057]: info: ControllerMpd::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::servicePushState Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 28 03:26:50 volumio volumio[1057]: verbose: CURRENT POSITION 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::syncState stateService stop Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::syncState currentStatus stop Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: No code Aug 28 03:26:50 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:26:50 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:26:50 volumio volumio[1057]: info: ------------------------------ 317ms Aug 28 03:26:50 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:26:51 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Aug 28 03:26:54 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:26:57 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: networkfs , deleteShare Aug 28 03:26:57 volumio sudo[2350]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/umount /mnt/NAS/SA6400732 Aug 28 03:26:57 volumio sudo[2350]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 28 03:26:57 volumio systemd[1]: mnt-NAS-SA6400732.mount: Deactivated successfully. Aug 28 03:26:57 volumio sudo[2350]: pam_unix(sudo:session): session closed for user root Aug 28 03:26:57 volumio volumio[1057]: info: Share SA6400732 successfully unmounted Aug 28 03:26:58 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Aug 28 03:26:58 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:27:00 volumio volumio[1057]: info: Aug 28 03:27:00 volumio volumio[1057]: ---------------------------- MPD announces state update: update Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::getState Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:27:00 volumio volumio[1057]: info: Aug 28 03:27:00 volumio volumio[1057]: ---------------------------- MPD announces state update: update Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::getState Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:27:00 volumio volumio[1057]: info: Aug 28 03:27:00 volumio volumio[1057]: ---------------------------- MPD announces state update: update Aug 28 03:27:00 volumio volumio[1057]: info: MPD Database updated - AlbumList cache refreshed Aug 28 03:27:00 volumio volumio[1057]: info: Aug 28 03:27:00 volumio volumio[1057]: ---------------------------- MPD announces state update: database Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:27:00 volumio volumio[1057]: info: Aug 28 03:27:00 volumio volumio[1057]: ---------------------------- MPD announces state update: update Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::getState Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:27:00 volumio volumio[1057]: info: sendMpdCommand status took 13 milliseconds Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::getState Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::getState Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:27:00 volumio volumio[1057]: info: sendMpdCommand status took 12 milliseconds Aug 28 03:27:00 volumio volumio[1057]: info: sendMpdCommand status took 11 milliseconds Aug 28 03:27:00 volumio volumio[1057]: info: sendMpdCommand status took 10 milliseconds Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:27:00 volumio volumio[1057]: info: Command Router : Notfying DB Updatefalse Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::Close All Modals sent Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:27:00 volumio volumio[1057]: info: Command Router : Notfying DB Updatefalse Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::Close All Modals sent Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::servicePushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 28 03:27:00 volumio volumio[1057]: verbose: CURRENT POSITION 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState stateService stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState currentStatus stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: No code Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::servicePushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 28 03:27:00 volumio volumio[1057]: verbose: CURRENT POSITION 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState stateService stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState currentStatus stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: No code Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: ------------------------------ 227ms Aug 28 03:27:00 volumio volumio[1057]: info: ------------------------------ 223ms Aug 28 03:27:00 volumio volumio[1057]: info: MPD Database updated - AlbumList cache refreshed Aug 28 03:27:00 volumio volumio[1057]: info: Aug 28 03:27:00 volumio volumio[1057]: ---------------------------- MPD announces state update: database Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:27:00 volumio volumio[1057]: info: Aug 28 03:27:00 volumio volumio[1057]: ---------------------------- MPD announces state update: update Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::getState Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::getState Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:27:00 volumio volumio[1057]: info: MPD Database updated - AlbumList cache refreshed Aug 28 03:27:00 volumio volumio[1057]: info: Aug 28 03:27:00 volumio volumio[1057]: ---------------------------- MPD announces state update: database Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:27:00 volumio volumio[1057]: info: Aug 28 03:27:00 volumio volumio[1057]: ---------------------------- MPD announces state update: update Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::getState Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::getState Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::sendMpdCommand status Aug 28 03:27:00 volumio volumio[1057]: info: sendMpdCommand status took 233 milliseconds Aug 28 03:27:00 volumio volumio[1057]: info: sendMpdCommand status took 230 milliseconds Aug 28 03:27:00 volumio volumio[1057]: info: sendMpdCommand status took 229 milliseconds Aug 28 03:27:00 volumio volumio[1057]: info: sendMpdCommand status took 228 milliseconds Aug 28 03:27:00 volumio volumio[1057]: info: sendMpdCommand status took 226 milliseconds Aug 28 03:27:00 volumio volumio[1057]: info: sendMpdCommand status took 12 milliseconds Aug 28 03:27:00 volumio volumio[1057]: info: sendMpdCommand status took 11 milliseconds Aug 28 03:27:00 volumio volumio[1057]: info: sendMpdCommand status took 10 milliseconds Aug 28 03:27:00 volumio volumio[1057]: info: sendMpdCommand status took 9 milliseconds Aug 28 03:27:00 volumio volumio[1057]: info: sendMpdCommand status took 8 milliseconds Aug 28 03:27:00 volumio volumio[1057]: info: sendMpdCommand status took 7 milliseconds Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:27:00 volumio volumio[1057]: info: Command Router : Notfying DB Updatefalse Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::Close All Modals sent Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:27:00 volumio volumio[1057]: info: Command Router : Notfying DB Updatefalse Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::Close All Modals sent Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:27:00 volumio volumio[1057]: info: Command Router : Notfying DB Updatefalse Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::Close All Modals sent Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:27:00 volumio volumio[1057]: info: Command Router : Notfying DB Updatefalse Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::Close All Modals sent Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:27:00 volumio volumio[1057]: verbose: ControllerMpd::parseState Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::servicePushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 28 03:27:00 volumio volumio[1057]: verbose: CURRENT POSITION 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState stateService stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState currentStatus stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: No code Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::servicePushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 28 03:27:00 volumio volumio[1057]: verbose: CURRENT POSITION 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState stateService stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState currentStatus stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: No code Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::servicePushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 28 03:27:00 volumio volumio[1057]: verbose: CURRENT POSITION 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState stateService stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState currentStatus stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: No code Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::servicePushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 28 03:27:00 volumio volumio[1057]: verbose: CURRENT POSITION 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState stateService stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState currentStatus stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: No code Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::servicePushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 28 03:27:00 volumio volumio[1057]: verbose: CURRENT POSITION 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState stateService stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState currentStatus stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: No code Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::servicePushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 28 03:27:00 volumio volumio[1057]: verbose: CURRENT POSITION 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState stateService stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState currentStatus stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: No code Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: ControllerMpd::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::servicePushState Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 28 03:27:00 volumio volumio[1057]: verbose: CURRENT POSITION 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState stateService stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::syncState currentStatus stop Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: No code Aug 28 03:27:00 volumio volumio[1057]: info: CoreStateMachine::pushState Aug 28 03:27:00 volumio volumio[1057]: info: CorePlayQueue::getTrack 0 Aug 28 03:27:00 volumio volumio[1057]: info: CoreCommandRouter::volumioPushState Aug 28 03:27:00 volumio volumio[1057]: info: ------------------------------ 571ms Aug 28 03:27:00 volumio volumio[1057]: info: ------------------------------ 571ms Aug 28 03:27:00 volumio volumio[1057]: info: ------------------------------ 571ms Aug 28 03:27:00 volumio volumio[1057]: info: ------------------------------ 352ms Aug 28 03:27:00 volumio volumio[1057]: info: ------------------------------ 353ms Aug 28 03:27:00 volumio volumio[1057]: info: ------------------------------ 350ms Aug 28 03:27:00 volumio volumio[1057]: info: ------------------------------ 351ms Aug 28 03:27:00 volumio volumio[1057]: info: [1787858820877] Database update started Aug 28 03:27:01 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Aug 28 03:27:01 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Aug 28 03:27:02 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:27:03 volumio volumio[1057]: info: Executing SMB command: smbclient --no-pass --debuglevel=0 -L SA6400732.local. -m SMB3_11 Aug 28 03:27:03 volumio volumio[1057]: info: Error browsing device SA6400732 for shares: Command failed: smbclient --no-pass --debuglevel=0 -L SA6400732.local. -m SMB3_11 Aug 28 03:27:04 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: networkfs , deleteShare Aug 28 03:27:05 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Aug 28 03:27:06 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:27:10 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:27:14 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:27:18 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:27:22 volumio volumio[1057]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Aug 28 03:27:26 volumio volumio[1057]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 03:27:26 volumio volumio[1057]: Error: connect ETIMEDOUT 108.160.166.142:443 Aug 28 03:27:26 volumio volumio[1057]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Aug 28 03:27:26 volumio volumio[1057]: errno: -110, Aug 28 03:27:26 volumio volumio[1057]: code: 'ETIMEDOUT', Aug 28 03:27:26 volumio volumio[1057]: syscall: 'connect', Aug 28 03:27:26 volumio volumio[1057]: address: '108.160.166.142', Aug 28 03:27:26 volumio volumio[1057]: port: 443 Aug 28 03:27:26 volumio volumio[1057]: } Aug 28 03:27:26 volumio volumio[1057]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 28 03:27:27 volumio sudo[2456]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-28 03:26' Aug 28 03:27:27 volumio sudo[2456]: 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="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"