datalust/serilog-sinks-seq

System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host

grjw opened this issue · 5 comments

grjw commented

I'm seeing this error when I try and log to Seq. Any suggestions?

It's a .NET 4.8 ASP.NET MVC App

Sample code I'm using AutoFac IoC to inject a logger and then triggering it from there:

public class SerilogLogger
    {
        public SerilogLogger()
        {
            Log.Logger = new LoggerConfiguration()
                       .ReadFrom.AppSettings()
                       .CreateLogger();

            Serilog.Debugging.SelfLog.Enable(
                msg => System.Diagnostics.Trace.WriteLine(msg));
        }

        public void Info(object message)
        {
            Log.Logger.Information(message.ToString());
            Log.CloseAndFlush();
        }

// in IoC class
builder.RegisterType<SerilogLogger>().As<ILogger>();

// Test to trigger log message
public class TestClass 
{
    private ILogger logger;
    public TestClass(ILogger logger)
    {
        this.logger = logger;
    }

    public void TestMethod()
    {
        logger.Info("Testing from website");
    }
}

Full stack trace from SelfLog:


2020-06-16T09:35:51.2143660Z Exception while emitting periodic batch from Serilog.Sinks.Seq.SeqSink: System.Net.Http.HttpRequestException: An error occurred while sending the request. ---> System.Net.WebException: The underlying connection was closed: An unexpected error occurred on a send. ---> System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host. ---> System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
   at System.Net.Sockets.Socket.EndReceive(IAsyncResult asyncResult)
   at System.Net.Sockets.NetworkStream.EndRead(IAsyncResult asyncResult)
   --- End of inner exception stack trace ---
   at System.Net.TlsStream.EndWrite(IAsyncResult asyncResult)
   at System.Net.PooledStream.EndWrite(IAsyncResult asyncResult)
   at System.Net.ConnectStream.WriteHeadersCallback(IAsyncResult ar)
   --- End of inner exception stack trace ---
   at System.Net.HttpWebRequest.EndGetRequestStream(IAsyncResult asyncResult, TransportContext& context)
   at System.Net.Http.HttpClientHandler.GetRequestStreamCallback(IAsyncResult ar)
   --- End of inner exception stack trace ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Serilog.Sinks.Seq.SeqSink.<EmitBatchAsync>d__14.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Serilog.Sinks.PeriodicBatching.PeriodicBatchingSink.<OnTick>d__16.MoveNext()
2020-06-16T09:35:51.3180195Z Exception while emitting periodic batch from Serilog.Sinks.Seq.SeqSink: System.Net.Http.HttpRequestException: An error occurred while sending the request. ---> System.Net.WebException: The underlying connection was closed: An unexpected error occurred on a send. ---> System.IO.IOException: Unable to read data from the transport connection: An existing connection was forcibly closed by the remote host. ---> System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
   at System.Net.Sockets.Socket.EndReceive(IAsyncResult asyncResult)
   at System.Net.Sockets.NetworkStream.EndRead(IAsyncResult asyncResult)
   --- End of inner exception stack trace ---
   at System.Net.TlsStream.EndWrite(IAsyncResult asyncResult)
   at System.Net.PooledStream.EndWrite(IAsyncResult asyncResult)
   at System.Net.ConnectStream.WriteHeadersCallback(IAsyncResult ar)
   --- End of inner exception stack trace ---
   at System.Net.HttpWebRequest.EndGetRequestStream(IAsyncResult asyncResult, TransportContext& context)
   at System.Net.Http.HttpClientHandler.GetRequestStreamCallback(IAsyncResult ar)
   --- End of inner exception stack trace ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Serilog.Sinks.Seq.SeqSink.<EmitBatchAsync>d__14.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Serilog.Sinks.PeriodicBatching.PeriodicBatchingSink.<OnTick>d__16.MoveNext()

Thanks!

grjw commented

Also I get the same error if I use an instance of Serilog instead of the static methods:

    public class SerilogLogger : ILogger
    {
        private readonly Serilog.Core.Logger logger;

        public SerilogLogger()
        {
            logger = new LoggerConfiguration()
                       .ReadFrom.AppSettings()
                       .CreateLogger();

            Serilog.Debugging.SelfLog.Enable(
                msg => System.Diagnostics.Trace.WriteLine(msg));
        }

        public void Info(object message)
        {
            logger.Information(message.ToString());
        }
}

Also here is my config:

    <!-- declare the switch -->
    <add key="serilog:level-switch:$controlSwitch" value="Information"/>
    <!-- use it to control the root logger -->
    <add key="serilog:minimum-level:controlled-by" value="$controlSwitch"/>
    <add key="serilog:using:Seq" value="Serilog.Sinks.Seq"/>
    <add key="serilog:write-to:Seq.serverUrl" value="https://seq.mydomain.com:5341"/>
    <add key="serilog:write-to:Seq.apiKey" value="*****************************"/>
    <!-- give the sink access to the switch -->
    <add key="serilog:write-to:Seq.controlLevelSwitch" value="$controlSwitch"/>
    <add key="serilog:enrich:with-property:system" value="Main Website Test"/>
    <add key="serilog:enrich:with-property:appname" value="website"/>
    <add key="serilog:enrich:with-property:environment" value="development"/>
    <add key="ClientSettingsProvider.ServiceUri" value=""/>
grjw commented

I've tried to create a new project and replicate as much of environment from the original project as I can (MVC 5, IoC, etc) and ti works fine. The only thing I haven't replicated is that it's an Umbraco 7 site. Would that affect it?

Umbraco 8 seems to support Serilog natively but I can't see an issue with version 7?

Hi Gavin, thanks for the note.

I think the issue is that your logger isn't registered with Autofac as SingleInstance(); this is required for efficient operation of many sinks, including the Seq one.

They'll still normally "work" when multiple instances are created, but because they use timers and HTTP connections, they can overload available TCP connections etc., leading to this kind of issue.

Hopefully this provides some clues, please let me know if you still have no luck! 👍

Ah, sorry - also, Autofac will be disposing that InstancePerDependency() logger per request, which will also potentially cause trouble. Definitely SingleInstance() :-)

grjw commented

Hi @nblumhardt

Thanks for the suggestions, I really appreciate it. I have found now found the issue.

Googling the error, a few people mention not using TLS1.2 can trigger this. Someone else also said Seq needs TLS1.2. Looking at Wireshark, my prototype (which works) is using TLS1.2 and the website (which doesn't) is using TLS1. Both are .NET 4.8

I had upgraded my MVC project to 4.8 for that reason but completely forgot about the httpruntime targetFramework attribute in web.config, It was still set to 4.5. Changing that to 4.8 has fixed it.

Thanks also for the suggestions about using SingleInstance - I'll update that as well.