Reason for long response times with "first" search query?

Question

I'm working on an application which uses MySQL as its database. I am however adding a search function with autocomplete/"as-you-type results" which uses ElasticSearch. Getting the relevant data from MySQL to ElasticSearch is not a problem and my searches works fine.

I do however have som performance issues but only when making the "first" search query, which takes about 1-5 seconds. By "first" I mean the first search within a couple of minutes; a second search within 10 seconds after the first search gets near instant results, while a second search five minutes after the first gets the results only after a significant delay.

My initial thought was that setting up the HTTP connection (which is pooled by .NET Framework) was causing the extra delay but it seems strange that that would take 1-5 seconds on a fast LAN network when not even using a DNS name to resolve the ElasticSearch server.

Are there any other possible culprits/usual suspects I should be looking at? Or does the initial-HTTP-connection-delay seem reasonble (and what would I do about that?)?

Searching is done like this (note that the ElasticSearch/NEST client is managed as a singleton and is already created):

public IEnumerable<Person> Search(ElasticClient esclient, IEnumerable<string> queryParts, int groupId) {
    // Make the search query and return the results.
    return esclient.Search<Person>(s => s
        .Query(q =>
            q.Terms(p => p.FirstName, queryParts) ||
            q.Terms(p => p.LastName, queryParts)
        )
        .Filter(f => f
            .Term(p => p.MemberOfGroups, new int[] { groupId })
        )
    ).Documents;
}

EDIT: My ElasticClient is created like this:

new ElasticClient(new ConnectionSettings(new Uri(esUrl), index));

@DavidNordvall what does your ES cluster look like and the mapping for `Person`? — Russ Cam, Nov 03 '15 at 08:39

score 1 · Answer 1 · answered Oct 27 '15 at 07:17

1

Most likely, it's the caching that happens in Elasticsearch. The first query will cache the results of the filters, the subsequent call will use the cached results, instead of running the query again. If you update the indices in the meantime the cache is invalidated, because the data changed.

You can test this assumption by:

temporarily disabling refresh:

PUT /index/_settings
{
  "index": {
    "refresh_interval": "-1"
  }
}

run the query once
wait some minutes
run the query second time and compare the results
after the test you can enable set back the refresh_interval to the initial value. If you didn't change it in settings, then it should be 1s (the default).

answered Oct 27 '15 at 07:17

Andrei Stefan

51,654
6
98
89

Disabling the refresh would mean that newly indexed documents won't show up in my search results but all searches (except the very first) should be fast? Which would mean that setting refresh interval to 3600 (one hour) would mean that new documents only appear in search results once every hour and that only one search every hour would be slow? – David Nordvall Oct 27 '15 at 13:24
I mentioned refresh_interval to test the hypothesis that the caching is the one that makes the first call take longer than the others. When documents get updated/added/deleted the cache is invalidated. I am trying forbid to make the documents refresh so that we can test the cache. – Andrei Stefan Oct 27 '15 at 13:37
This doesn't seem to be the problem. I have tested to both disable refresh and disable update of the index and neither changes the "initial-search-takes-a-really-long-time" behavior. – David Nordvall Oct 28 '15 at 08:58
And did you use the same query every time? – Andrei Stefan Oct 28 '15 at 09:03
The value of the variable "queryParts" (see my code snippet in the question) changed, the filter term did not. – David Nordvall Oct 28 '15 at 09:21
Ok, run this command `GET /_stats/filter_cache?index=your_index_name` and see if there are any `filter_cache` `evictions`. – Andrei Stefan Oct 28 '15 at 09:59
No filter cache evictions. – David Nordvall Oct 28 '15 at 11:06
That's weird. Do you clear cache manually, by any chance? What ES version is this? – Andrei Stefan Oct 28 '15 at 11:10
ES version 1.7.2. As far as I know, I don't clear the cache manually. I have one service which continously updates the index with new and/or updated documents and one web application which queries the index. Updating the index is done using the NEST client's IndexMany() API. – David Nordvall Oct 28 '15 at 11:32
I'm wondering what query your .NET code generates... can you enable slowlogs and set the threshold to a very low value (1ms) and run your query? Then look in the slowlogs and provide the generated query, please. – Andrei Stefan Oct 28 '15 at 12:08

score 0 · Answer 2 · answered Oct 27 '15 at 07:52

you can check or post the logs of your elastic search cluster here.It should be in your $log_directory/.That will give to more verbose insight of whats happening inside the cluster if you set tarce level for logs.

One for thing if cache is the issue for first query, you can utilize elastic search warmers to warm your cluster cache after deployment or write a scheduler to run warmers twice or thrice a day.

Thanks.

Reason for long response times with "first" search query?

2 Answers2