Elasticsearch NEST client 7.17 productivity investigation

[Vadym_Romanenko]

Hi, Team!

We created solution that generates documents and posts them to Elastic. After that users can search for data located in Elastic. Our solution is web app implemented with ASP.NET, c# on the backend. We use Elasticsearch server 7 and NEST ES client 7.17.
At this moment we're trying to improve speed of our solution, so I added some code that measures speed of searching.
Here is some numbers:

• method that generates ES request takes 5-10ms
• ES query call takes 20-60 ms (ElasticClient.Search(Func<SearchDescriptor, ISearchRequest> selector = null))
• processing of results takes 10-30 ms
  What is strange here for me. I see that ES response param "took" is between 2-5ms, but time that takes call of NEST's ElasticClient.Search method takes much more time - x10-x15 to the value of that "took" parameter.
  During investigation I downloaded ES NEST client source codes and attached it to our project. After that I added some logging to several NEST methods.
  I added logging with measuring to all lines of this methods:

 **ElasticClient**.DoRequest<TRequest, TResponse>(
			TRequest p,
			IRequestParameters parameters,
			Action<IConnectionConfigurationValues, IRequestConfiguration> forceConfiguration = null
		)
			where TRequest : class, IRequest
			where TResponse : class, IElasticsearchResponse, new()

 **Transport**.Request<TResponse>(HttpMethod method, string path, PostData data = null, IRequestParameters requestParameters = null)
			where TResponse : class, IElasticsearchResponse, new()

 **RequestPipeline**.CallElasticsearch<TResponse>(RequestData requestData)
			where TResponse : class, IElasticsearchResponse, new()

Here is sample result of complete logging for this methods. Data is formatted according to call stack, timing in milliseconds are in the beginning of each line

--EasticClient.DoRequest started
    0 Configuration completed
    0 Content Type processed
    0 URL processed
--Transport.Request started
        0 Pipeline creation completed
        6.7229 First pool usage completed
        0 Request data created
        0 OnRequestDataCreated completed 
        0 New foreach step started
        0 Sniff completed
        0 Ping completed
--RequestPipeline.CallElasticsearch started
            0 Audit initialized
            0 Diagnozed
            0 ThrowIfTransientProductCheckFailure
            13.3083 Response obtained
            0 PostCallElasticsearch finished
            0 Finalization took
--RequestPipeline.CallElasticsearch completed
        13.3083 Response received
        0 Pipeline marked alive
        0 Response finalized
        0 Whole time for request method
        0 Finalization took
--Transport.Request completed
    20.0312 Request completed
    0 Finalization took
--EasticClient.DoRequest completed
22.0313 EasticClient.DoRequest completed

So, according to this log, EasticClient.DoRequest completed in 22ms, and it took almost 7ms for something like "first pool usage" and 13ms to complete call to elasticsearch. Parameter "took" equals to 2ms. This difference looks strange for me - 2ms from ES server vs 22ms of complete running request with NEST.
But I have even more strange situation. If I'm completing request after some pause after previous call (like 30 seconds) - I see much worse situation. Below is shortened log with zero lines removed.

--EasticClient.DoRequest started
--Transport.Request started
        2044.0038 First pool usage completed
--RequestPipeline.CallElasticsearch started
            16.1455 Response obtained
--RequestPipeline.CallElasticsearch completed
        16.1455 Response received
--Transport.Request completed
    2060.1493 Request completed
--EasticClient.DoRequest completed
2061.1434 EasticClient.DoRequest completed

So, here we see huge value for running "First pool usage" command - 2044ms!!

Now I'm trying to understand if we're doing something wrong. Some hints with configuration? Some way to improve speed of completing step "First pool usage"? Or it is normal time for running this operations?

Some words about testing configuration:

• Windows 10 with last update
• our website runs under IIS with default configuraition
• Elasticsearch server runs under Docker on the same machine with default configuration
• Elasticsearch index that is used for testing contains just 180 documents, each document has maximum 30 properties, no pictures, no files
• testing machine has this resources: intel i7 8gen, 32gb, sdd

I will be grateful for any ideas or suggestions.

[Vadym_Romanenko]

I created a test project that requests data in Elastic (same query, one-by-one, with pauses, same ElasticClient instance)
I see that it works much faster than in situation where I'm creating new client instance per each call.
Are there any recommendations how to organize ElasticClient instances pool for a web application? I think this solution will bring me success in my case
Here is my statistics in ms for running same query with pauses:

[Vadym_Romanenko]

I don't see any answers or additional questions, so I think that my topic was hard to understand or not interesting for community. So, I will share solution that I'm implemented.
In ES 8 I found recommendation that there should be single instance for ES client in the application. Later I found that such recommendation presents in ES 7 that we're using now. I haven't seen this recommendation before.
After moving ES client to be a singleton, I see this results. All requests to ES runs less than 25ms (instead of the first one after startup). Value closer to 25ms could be found in processing of ES queries with reported value of "took" close to 9ms.

It looks much better than previous situation when query with reported "took" value equal to 2ms was processed up to 60ms. Now this queries could be processed even faster than 15ms.

We think that there are no way to improve speed of processing for now. I hope that this decision (use ES client as singleton) will help someone to improve his speed of running queries.