The EV client trace shows the search timing out after the configured 110 seconds in the example below:
02:56:02.473[4732][H]: HDR: Requesting page: SyncPoint.aspx?Slot=0d59f676-81fa-48b5-b05b-5000fdc84e16&ArchiveID=16F9A835C63464F449F161C6D2A6313501110000EVSite&SyncPoint=0&SiteID=1F4C598219829014BBA2908DB61BCB6E41d10000EVSite
02:56:02.473[4732][L]: CInternetSendDataBase::GetDataFromServer: 0x0
02:56:02.473[4732][L]: CInternetSendDataBase::OpenRequest
02:56:02.473[4732][L]: ~CInternetSendDataBase::OpenRequest
02:56:02.474[4732][L]: ++++++++++++ Starting GET Request +++++++++++++++++++
02:57:52.533[4732][L]: CInternetSendDataBase::ReadResponse: 0x0
02:57:52.533[4732][L]: CInternetSendDataBase::ReadStatusCode: 0x0
02:57:52.534[4732][M]: HttpQueryInfo text is 'The search timed out. (0x80041c71)' status code is '200'
The client trace alternatively could also show the following:
Body is
HDR: LoadXMLResponse is
HDR:SYNC: MDCSyncResponse hr: 0xC0041C0E
HDR:SYNC: MDCSyncResponse msg: Index Search failed: %1 Index: %3 Internal reference: %2 (0xc0041c0e)
HDR:SYNC: ~MDC::ServerResponseHandling::Response: 0xC0041C0E
A Dtrace of the W3WP and EVIndexQueryServer processes will show the following with the same 110 seconds delay:
13:38:11.993 [26452] (w3wp) <6324> EV:L IndexQueryServerHttpConfig::Get. Returning config from cache: Path=/enterprisevault/search/indexserversearchservice/search, Port=80, Secure=false.
13:38:11.993 [26452] (w3wp) <6324> EV:M WinHttpSession::Initialize. Calling WinHttpOpen with agent IndexClient.
13:38:11.993 [26452] (w3wp) <6324> EV:L WinHttpSession::SetTimeouts. resolve=110000ms, connect=110000ms, send=110000ms, receive=110000ms
13:38:11.993 [26452] (w3wp) <6324> EV:M WinHttpConnect: Initialise: serverName=EV01.example.com, portNumber=80.
13:38:11.993 [26452] (w3wp) <6324> EV:M IndexQueryServerRequest: Initialise: path=/enterprisevault/search/indexserversearchservice/search, verb=POST, useAuthToken=true, secure=false.
13:38:11.993 [26452] (w3wp) <6324> EV:M IndexQueryServerRequest: Using AuthToken authentication, so modified URL path to /enterprisevault/search/indexserversearchservice/authtoken/search.
13:38:11.993 [26452] (w3wp) <6324> EV:M WinHttpRequest::Initialize. Calling WinHttpOpenRequest with path=/enterprisevault/search/indexserversearchservice/authtoken/search, verb=POST.
13:38:11.993 [26452] (w3wp) <6324> EV:L WinHttpRequest::Initialize exit.
13:38:11.993 [26452] (w3wp) <6324> EV:M WinHttpRequest::SendRequest. Calling WinHttpSendRequest with headers=Content-Type: application/octet-stream, extraDataLength=1108.
13:38:11.993 [26452] (w3wp) <6324> EV:L WinHttpRequest::Callback from WinHttp. Code=0x1, context=0x1663E2C0
13:38:11.993 [26452] (w3wp) <6324> EV:L WinHttpRequest::SendRequest exit.
13:38:11.993 [26452] (w3wp) <6324> EV:M IndexQueryServerRequest: Waiting for 110000ms for request to complete.
13:38:11.993 [26452] (w3wp) <24352> EV:L WinHttpRequest::Callback from WinHttp. Code=0x2, context=0x1663E2C0
13:38:11.993 [26452] (w3wp) <24352> EV:L WinHttpRequest::Callback from WinHttp. Code=0x4, context=0x1663E2C0
13:38:11.993 [26452] (w3wp) <24352> EV:L WinHttpRequest::Callback from WinHttp. Code=0x8, context=0x1663E2C0
13:38:11.993 [26452] (w3wp) <24352> EV:L WinHttpRequest::Callback from WinHttp. Code=0x10, context=0x1663E2C0
13:38:11.993 [26452] (w3wp) <24352> EV:L WinHttpRequest::Callback from WinHttp. Code=0x20, context=0x1663E2C0
13:39:35.041 [26452] (w3wp) <24352> EV:H WinHttpRequest::OnCallback. WINHTTP_CALLBACK_STATUS_REQUEST_ERROR.
13:39:35.041 [26452] (w3wp) <24352> EV:H WinHttpRequest::OnCallback. WINHTTP_CALLBACK_STATUS_REQUEST_ERROR - Result=5, Error=12017|
13:39:35.041 [26452] (w3wp) <24352> EV:H WinHttpRequest::OnCallback exit. ERROR HR=0x8001011f.
13:39:35.041 [26452] (w3wp) <24352> EV:M WinHttpRequest::Callback from WinHttp. pRequest->OnCallback failed with HR=0x8001011f. Calling pRequest->OnResponseComplete.
13:39:35.041 [26452] (w3wp) <24352> EV:M IndexQueryServerRequest: OnResponseComplete - HR=This operation returned because the timeout period expired. (0x8001011f)
13:39:35.041 [26452] (w3wp) <24352> EV:L WinHttpRequest::Callback from WinHttp. Code=0x800, context=0x16B3E800
13:39:35.041 [26452] (w3wp) <24352> EV:L WinHttpRequest::OnCallback. WINHTTP_CALLBACK_STATUS_HANDLE_CLOSING.
13:39:35.073 [26452] (w3wp) <19588> EV:M CIndexSearch2::PerformSearch request failed. Attempt:1 ArchiveId:16F9A835C63464F449F161C6D2A6313501110000EVSite |hr=The search timed out. (0x80041c71)
13:39:35.073 [26452] (w3wp) <19588> EV:H CIndexSearch2::PerformSearch Search failed with 'normal' error: hr=The search timed out. (0x80041c71).
Alternatively, the dtrace could also show the following:
WinHttpRequest::OnCallback. WINHTTP_CALLBACK_STATUS_HEADERS_AVAILABLE. Status code=502
WinHttpRequest::OnCallback. WINHTTP_CALLBACK_STATUS_HEADERS_AVAILABLE. Error status but no X-EV-HRESULT, so returning E_FAIL.
WinHttpRequest::OnCallback exit. ERROR HR=0x80004005.
WinHttpRequest::Callback from WinHttp. pRequest->OnCallback failed with HR=0x80004005. Calling pRequest->OnResponseComplete.
IndexQueryServerRequest: OnResponseComplete - HR=Unspecified error (0x80004005)
IndexQueryServerRequest: WaitForSingleObject returned 0.
Response received. Result = Unspecified error (0x80004005), Status = 502
CIndexQueryServerSearch::Search2. Request FAILED HR=0x80004005.
This issue can be caused by a WINHTTP proxy being configured on the EV server.
netsh winhttp show proxynetsh winhttp reset proxy