Issues with NEST 7. "The stream with Id and Tag is disposed."

Elastic Stack Elasticsearch
1

After update to Nest7 (basically nuget, no other changes) occasionally getting this error for a process that usually runs for 15 minutes.
Sometimes it happens during updating documents by id, sometimes bulk operations.
The problem disappeared when I turned off parallel processing ParallelOptions { MaxDegreeOfParallelism = 1 } so, basically lowered the load.
Have never had the issue with Nest6. IElasticClient is registered as singleton via DI.
The client talks directly to ES by IPs set in StaticConnectionPool

connectionSettings.EnableHttpCompression();
#if DEBUG
//connectionSettings.EnableDebugMode();
#endif
connectionSettings.DisableDirectStreaming();
connectionSettings.EnableHttpPipelining();
connectionSettings.PrettyJson(false);
connectionSettings.IncludeServerStackTraceOnError();

Any ideas as to what may have slipped during migration?
Maybe ConnectionSettings should be adjusted?
I'm checking whether there are multi-threading issues but as I mentioned no issues ever happened with version 6.

ES: centos7, ES 7.3.2
client: centos7, .net core 2.0, Nest 7.3.1

Log:

System.AggregateException: One or more errors occurred. (The read operation failed, see inner exception.) ---> Elasticsearch.Net.UnexpectedElasticsearchClientException: The read operation failed, see inner exception. ---> System.IO.IOException: The read operation failed, see inner exception. ---> System.ObjectDisposedException: Cannot access a disposed object.

Object name: 'The stream with Id f434e91e-8fcd-4051-83fd-56ca445e5e53 and Tag is disposed.'.
at Elasticsearch.Net.RecyclableMemoryStream.CheckDisposed()
at Elasticsearch.Net.RecyclableMemoryStream.SafeRead(Byte[] buffer, Int32 offset, Int32 count, Int32& streamPosition)
at Elasticsearch.Net.RecyclableMemoryStream.Read(Byte[] buffer, Int32 offset, Int32 count)
at System.IO.MemoryStream.ReadAsync(Byte[] buffer, Int32 offset, Int32 count, CancellationToken cancellationToken)

---> (Inner Exception #0) Elasticsearch.Net.UnexpectedElasticsearchClientException: The read operation failed, see inner exception. ---> System.IO.IOException: The read operation failed, see inner exception. ---> System.ObjectDisposedException: Cannot access a disposed object.

--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
at System.Net.Http.CurlHandler.MultiAgent.TransferDataFromRequestStream(IntPtr buffer, Int32 length, EasyRequest easy)
at System.Net.Http.CurlHandler.MultiAgent.CurlSendCallback(IntPtr buffer, UInt64 size, UInt64 nitems, IntPtr context)
--- End of inner exception stack trace ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
at System.Net.Http.CurlHandler.CurlResponseStream.Read(Byte[] buffer, Int32 offset, Int32 count)
at System.IO.Stream.CopyTo(Stream destination, Int32 bufferSize)
at Elasticsearch.Net.ResponseBuilder.SetBody[TResponse](ApiCallDetails details, RequestData requestData, Stream responseStream, String mimeType)
at Elasticsearch.Net.ResponseBuilder.ToResponse[TResponse](RequestData requestData, Exception ex, Nullable`1 statusCode, IEnumerable`1 warnings, Stream responseStream, String mimeType)
at Elasticsearch.Net.HttpConnection.Request[TResponse](RequestData requestData)
at Elasticsearch.Net.RequestPipeline.CallElasticsearch[TResponse](RequestData requestData)
at Elasticsearch.Net.Transport`1.Request[TResponse](HttpMethod method, String path, PostData data, IRequestParameters requestParameters)
--- End of inner exception stack trace ---
at Elasticsearch.Net.Transport`1.Request[TResponse](HttpMethod method, String path, PostData data, IRequestParameters requestParameters)
at Elasticsearch.Net.ElasticLowLevelClient.DoRequest[TResponse](HttpMethod method, String path, PostData data, IRequestParameters requestParameters)
at Nest.ElasticClient.DoRequest[TRequest,TResponse](TRequest p, IRequestParameters parameters, Action`1 forceConfiguration)
at Nest.ElasticClient.Search[TDocument](ISearchRequest request)
at Nest.ElasticClient.Search[TDocument](Func`2 selector)
at Loader.Writers.CustomerRepository.SearchCustomer(Func`2 query)
at Loader.Loaders.EmailSentLoader.GetUpdatedCollection(DealerDto dealer, EmailSent[] batch, ConcurrentDictionary`2 bulkCollection)
at Loader.Loaders.EmailSentLoader.<>c__DisplayClass9_1.<Load>b__1(Int32 page)
at System.Threading.Tasks.Parallel.<>c__DisplayClass44_0`2.<PartitionerForEachWorker>b__1(IEnumerator& partitionState, Int32 timeout, Boolean& replicationDelegateYieldedBeforeCompletion)
2

UPDATE
on the server side i noticed this but probably unrelated though will try again with cluster.fault_detection.follower_check.timeout: "30s" as this didn't exist on ES6. think it was 30s as default behaviour.

[WARN ][o.e.t.TransportService   ] [data-8] Received response for a request that has timed out, sent [13233ms] ago, timed out [3226ms] ago, action [internal:coordination/fault_detection/leader_check], node [{master-1}{y0ck8405SEmBxf7EMzjofQ}{G66uUm9pR0WLa5kJlLw5hA}{10.x.x.x}{10.x.x.x:9300}{m}{xpack.installed=true}], id [5834654]
3

Looking at the stack trace, the internal memory stream in which the response is buffered is already disposed when attempted to be read. Can you provide a succinct example of the type of operation that you're performing wheb you get this exception?

4

Hey Russ, glad to see you again

sure, I had to change the names of methods, etc.. but short/simplified looks like this
let me know if you need better example. I'll try to get something even closer if this is not enough.
ConnectionSettings are mentioned above.

some numbers according to logs (mentioned in gist) during stress tests.
If this process runs for two hours it can fetch 3,712,029 documents from ES and around 95% of them will be sent for bulk update.

two other loaders that have the same structure also get exception on Search. but there is one where it happens on Update.

I think i'll try one more test without DisableDirectStreaming()

5

without DisableDirectStreaming() stacktrace looks a bit different:

--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
at System.Net.Http.CurlHandler.MultiAgent.TransferDataFromRequestStream(IntPtr buffer, Int32 length, EasyRequest easy)
at System.Net.Http.CurlHandler.MultiAgent.CurlSendCallback(IntPtr buffer, UInt64 size, UInt64 nitems, IntPtr context)
--- End of inner exception stack trace ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
at System.Net.Http.CurlHandler.CurlResponseStream.Read(Byte[] buffer, Int32 offset, Int32 count)
at Elasticsearch.Net.Utf8Json.JsonSerializer.FillFromStream(Stream input, Byte[]& buffer)
at Elasticsearch.Net.Utf8Json.JsonSerializer.Deserialize[T](Stream stream, IJsonFormatterResolver resolver)
at Elasticsearch.Net.DiagnosticsSerializerProxy.Deserialize[T](Stream stream)
at Elasticsearch.Net.ResponseBuilder.SetBody[TResponse](ApiCallDetails details, RequestData requestData, Stream responseStream, String mimeType)
at Elasticsearch.Net.ResponseBuilder.ToResponse[TResponse](RequestData requestData, Exception ex, Nullable`1 statusCode, IEnumerable`1 warnings, Stream responseStream, String mimeType)
at Elasticsearch.Net.HttpConnection.Request[TResponse](RequestData requestData)
at Elasticsearch.Net.RequestPipeline.CallElasticsearch[TResponse](RequestData requestData)
at Elasticsearch.Net.Transport`1.Request[TResponse](HttpMethod method, String path, PostData data, IRequestParameters requestParameters)
--- End of inner exception stack trace ---
at Elasticsearch.Net.Transport`1.Request[TResponse](HttpMethod method, String path, PostData data, IRequestParameters requestParameters)
at Loader.Writers.CustomerRepository.SearchCustomer(Func`2 query)
...

Both exceptions lead me here and here

Does it mean i have issues with the box setup or i have code issues?
If it's running slower (with just one thread) then no issues but with nest6 hadn't these problems. Does Nest6 also use CurlResponseStream?

That's what i see on the box:

# yum list installed
...
libcurl.x86_64    7.29.0-46.el7    @base
dotnet-host.x86_64    2.1.5-1    @packages-microsoft-com-prod
dotnet-hostfxr-2.0.5.x86_64	2.0.5-1    @packages-microsoft-com-prod
dotnet-runtime-2.0.5.x86_64    2.0.5-1    @packages-microsoft-com-prod
dotnet-sdk-2.1.4.x86_64    2.1.4-1    @packages-microsoft-com-prod
...
# yum list available libcurl
libcurl.x86_64    7.29.0-54.el7    @base

I can try to update it to .net core 2.2 and also do yum update just in case though not sure if this could really help

6

The stacktrace does looks suspicious and we'll need to investigate it further. It looks to originate from reading from the CurlResponseStream in both cases. What's the typical size of the response? Are there any further logs/diagnostics when the exception is thrown, perhaps in OS logs?

NEST 6 uses the same HttpConnection implementation as 7, which will use the managed SocketsHttpHandler implementation on .NET Core 2.1 and above, and the CurlHandler on older versions, or if managed handler feature is turned off with AppContext.SetSwitch("System.Net.Http.UseSocketsHttpHandler", false);.

For what it's worth, we've seen other issues related to CurlHandler previously, related to socket starvation. This looks like a separate issue here though.

7

Would you like me to open github issue rather? I opened ticket here as I thought it's just a configuration problem.

Checked the code and ec2 instance. The setting UseSocketsHttpHandler is not switched off.
Max response size (300 docs) for this loader is about 6MB.
Unfortunately, we didn't catch any OS logs as those machines are not reused. they created only for the loader's process and then self-terminated.
I'll try to set up something to get those.

Thank you for the link and the info about changes in .net core 2.1 on this topic!
Meantime, I will compile the app as 2.2 as well as update the libs on AMI.
Will let you know.

8

A GitHub issue may be better to track for this. Would you mind opening one?

9

Sure, created: https://github.com/elastic/elasticsearch-net/issues/4168

1 Like
10

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