# Sparse slow NEST Searches

**URL:** <https://discuss.elastic.co/t/sparse-slow-nest-searches/77304>\
**Category:** Elasticsearch\
**Created:** [March 3, 2017, 11:22am UTC](https://discuss.elastic.co/t/sparse-slow-nest-searches/77304 "2017-03-03T11:22:12Z")\
**Posts on this page:** 6\
**Page:** 1

<div class="post-metadata">

**Author:** ![Xavi\_Ametller](https://avatars.discourse-cdn.com/v4/letter/x/b5ac83/32.png) [@Xavi\_Ametller](https://discuss.elastic.co/u/Xavi_Ametller)\
**Post date:** [March 3, 2017, 11:22am UTC](https://discuss.elastic.co/t/sparse-slow-nest-searches/77304/1 "2017-03-03T11:22:12Z")

</div>

Hi everyone,

We are using ElasticSearch Nest client to build an API with Dot Net Core to run queries towards an ElasticSearch cluster. Most of the times, we run the same type of query with a filter that's provided as part of the API call, so we have wrapped it into a method like this:

```
var stopWatch = new Stopwatch(); // stopwatch added to investigate the issue
stopWatch.Start();

var searchRequest = new SearchRequest<Price>
 {
     Size = 0,
     Query = new BoolQuery()
     {
         Must = _filterTermQueries_
     },
     Aggregations = aggrs
 };
var results = indexClient.Search<Price>(searchRequest);

timeTracking.Enqueue($"Search done - {stopwatch.ElapsedMilliseconds} - {results.Took}");

```

Most of the time, the _stopwatch time_ is +-50 ms more than the _results.Took_ time, understandable due to serialization and deserialization of the request/response.

The problem is that, every once in a while, **the difference between the two is up to 3 seconds** , hence the API takes more than 3 seconds to answer even though ElasticSearch indexes only spent milliseconds finding the data.  
Note this happens with load (via JMeterLoadTest) and without load (single call via postman).

I've read in [this discussion](https://discuss.elastic.co/t/nest-is-much-slower-than-kibana/66081/3) that: "Bear in mind that the first query to Elasticsearch from NEST will be much slower because the client caches a lot of delegates, compiled expressions and json serialization properties on this first call."

Hence I question myself:

1. For how long are those things cached? Could it be that those caches are evicted every once in a while and we have to pay this price again?
2. Is there any way to gather extra information about them at runtime?

Any help would be appreciated, thanks!

---

<div class="post-metadata">

**Author:** ![forloop](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/forloop/32/9021_2.png) [@forloop](https://discuss.elastic.co/u/forloop)\
**Post date:** [March 5, 2017, 7:41am UTC](https://discuss.elastic.co/t/sparse-slow-nest-searches/77304/2 "2017-03-05T07:41:15Z")

</div>

Hey @Xavi_Ametller,

The caches used are unbounded so no previously cached data is evicted for the lifetime of the AppDomain.

Could you provide some additional detail on your setup?

1. What version of NEST are you using?
2. What OS/Runtime are you running on? You mention .NET Core, is this on Windows, Linux, etc?

You should be able to get more information from the `.DebugInformation` property on the response. If this isn't yielding any further insight, you could also look at [configuring network tracing](https://msdn.microsoft.com/en-us/library/ty48b824(v=vs.110).aspx).

---

<div class="post-metadata">

**Author:** ![Xavi\_Ametller](https://avatars.discourse-cdn.com/v4/letter/x/b5ac83/32.png) [@Xavi\_Ametller](https://discuss.elastic.co/u/Xavi_Ametller)\
**Post date:** [March 8, 2017, 9:15am UTC](https://discuss.elastic.co/t/sparse-slow-nest-searches/77304/3 "2017-03-08T09:15:42Z")

</div>

Hi @forloop, thanks for your pointers,

First of all, let me answer your questions:

1. We are using NEST 5.2.0.
2. We are running on Windows, more concretely an Azure WebApp on a S1 Service Plan (1 core, 1.75 GB Ram). The API is the only app running on the service plan.

If I look at the `.DebugInformation`of the response when we have this problem (I can reproduce it running the API locally with the index in the cloud) I can see that the API call sometimes takes 2 orders of magnitude more than the response from Elastic:  
Valid NEST response built from a successful low level call on POST: /Index/price/\_search  
# Audit trail of this API call:  
- [1] HealthyResponse: Node: XXX **Took: 00:00:00.7833709**  
# Request:  
{  
...  
}  
# Response:  
{ **"took":95** ,"timed\_out":false,"\_shards":{"total":80,"successful":80,"failed":0}, ... }

On top of that, I'd like to add that if we repeat the _same exact_ query several times, performance is good most of the times, so it doesn't seem to be query-related.

To be fair, it is not clear to me what operations are included in the first _took_ (the slow one) - I understand the number is obtained by NEST on the client side but correct me if I'm wrong. If that were the case, is there any way to obtain profiling information about how much each operation took on NEST side (serialize request, send, receive answer, build response object).

In any case, if the caches are never evicted, then I would expect that serializing the request and building the response should take a negligible amount of time.

I would like to add that we use this method as part of a bunch of tasks that are executed in parallel, so we also considered if the time could be caused by task switching. We have replaced the call to the method by a Sleep and the problem is not happening anymore.  
We also have tried to change the execution to a synchronous implementation (without tasks) and the problem persists but happens less often, so we wonder if maybe its a combination of NEST + tasks...

Any insights will be appreciated, thanks!

---

<div class="post-metadata">

**Author:** ![Xavi\_Ametller](https://avatars.discourse-cdn.com/v4/letter/x/b5ac83/32.png) [@Xavi\_Ametller](https://discuss.elastic.co/u/Xavi_Ametller)\
**Post date:** [March 17, 2017, 1:13pm UTC](https://discuss.elastic.co/t/sparse-slow-nest-searches/77304/4 "2017-03-17T13:13:33Z")

</div>

Just for the record, I have identified what seems to be the problem (although have not fixed it). Seems that Dot net core and Nancy FX do not play very well together and the problem has nothing to do with NEST.  
To demonstrate it, I have created an endpoint in the API which returns a constant string (hello world stuff). That endpoint also has sparse peaks of bad performance as well.

Also reinforcing the hypothesis, I have moved the API to .Net 4.5 and WebApi 2.0 and everything works now like a charm (hello world and NEST) with much more higher throughput thanks to the consistently slow response times.  
Would love to know where the real problem is, but since the API is a proof of concept I decided not to spend more time investigating this.  
Kind regards,

---

<div class="post-metadata">

**Author:** ![forloop](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/forloop/32/9021_2.png) [@forloop](https://discuss.elastic.co/u/forloop)\
**Post date:** [March 19, 2017, 11:45am UTC](https://discuss.elastic.co/t/sparse-slow-nest-searches/77304/5 "2017-03-19T11:45:52Z")

</div>

Thanks for the update @Xavi_Ametller, glad you got to the bottom of it 😄

---

<div class="post-metadata">

**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\
**Post date:** [April 16, 2017, 11:46am UTC](https://discuss.elastic.co/t/sparse-slow-nest-searches/77304/6 "2017-04-16T11:46:14Z")

</div>

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.