Bug in v7.1.0 with CloseAndFlush hanging app during exit.

[hastarin]

What version of Serilog.Sinks.Elasticsearch is affected? Please list the related NuGet package.
v7.1.0

What is the target framework and operating system?
4.7.1

Please describe the current behavior?
When calling Log.CloseAndFlush() my application hangs.

Stack trace when hitting pause in a debug session:

 	mscorlib.dll!System.Threading.SynchronizationContext.InvokeWaitMethodHelper(System.Threading.SynchronizationContext syncContext, System.IntPtr[] waitHandles, bool waitAll, int millisecondsTimeout)	Unknown
 	[Native to Managed Transition]	
 	[Managed to Native Transition]	
 	mscorlib.dll!System.Threading.Monitor.Wait(object obj, int millisecondsTimeout, bool exitContext)	Unknown
 	mscorlib.dll!System.Threading.Monitor.Wait(object obj, int millisecondsTimeout)	Unknown
 	mscorlib.dll!System.Threading.ManualResetEventSlim.Wait(int millisecondsTimeout, System.Threading.CancellationToken cancellationToken)	Unknown
 	mscorlib.dll!System.Threading.Tasks.Task.SpinThenBlockingWait(int millisecondsTimeout, System.Threading.CancellationToken cancellationToken)	Unknown
 	mscorlib.dll!System.Threading.Tasks.Task.InternalWait(int millisecondsTimeout, System.Threading.CancellationToken cancellationToken)	Unknown
 	mscorlib.dll!System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(System.Threading.Tasks.Task task)	Unknown
 	Serilog.Sinks.Elasticsearch.dll!Serilog.Sinks.Elasticsearch.Durable.LogShipper<System.Collections.Generic.List<string>>.CloseAndFlush()	Unknown
 	Serilog.Sinks.Elasticsearch.dll!Serilog.Sinks.Elasticsearch.Durable.DurableElasticsearchSink.Dispose()	Unknown
 	Serilog.dll!Serilog.Core.Sinks.RestrictedSink.Dispose()	Unknown
 	Serilog.dll!Serilog.LoggerConfiguration.CreateLogger.__Dispose|0()	Unknown
 	Serilog.dll!Serilog.Core.Logger.Dispose()	Unknown
 	Serilog.dll!Serilog.Log.CloseAndFlush()	Unknown

Please describe the expected behavior?
I would expect the previous behavior, or a small extra delay to ensure a flush occurs, but not a hang.

[mivano]

You are correct, it should certainly not hang, but make sure all buffered events are flushed inside the sinks and then dispose of the logger. Is there any logging in the Selflog of Serilog or in the Elasticsearch server?

[hastarin]

@mivano My apologies I only just noticed this. I had to roll back the version as this was a production system so I'm afraid I can't help with further logs.

[mivano]

Then I m afraid that it is pretty hard to support this issue. Closing for now, feel free to reopen when you have more details.

[hastarin]

@mivano Totally understood thanks. FYI I did a quick local test and did not have the problem so perhaps it was a conflict with another package that I have since upgraded.

[mivano]

Great. When it happens again, make sure to enable the selflog of Serilog. The sink will write any exceptions to there.

[ghost]

I have been seeing this behaviour ever since DurableSink started flushing to elastic on shutdown.

The problem is rather obvious:

void CloseAndFlush()
{
    /* ... */

    OnTick().GetAwaiter().GetResult();
}

/* ... */

protected virtual async Task OnTick()
{
    /* ... */
}

The CloseAndFlush method is blocking on an async method, which will almost always deadlock. In my experience, the only way to reliably block on an asynchronous method without deadlocking is running it on another thread:

void CloseAndFlush()
{
    /* ... */

    Task.Run(OnTick).Wait();
}

[mivano]

Thanks for the pointer. We will most likely get rid of the durable mode here soon. Causing more issues then actually delivering value #254