asp.netiislog4netlogentries

Log4Net / LogEntries brought down our production site


We had a seriously scary incident this morning. Our QA team (who fortunately start work before the US work day begins) reported that our production web site had suddenly gone down. We had not done anything strange at that time; the failure was sudden and simultaneously affected all our environments. I went onto the production web server (IIS) and found that the application pool had stopped. I restarted it, and it immediately crashed again. I checked the Windows Event Viewer, and found the following error in the logs:

Source: .NET Runtime

Application: w3wp.exe

Framework Version: v4.0.30319

Description: The process was terminated due to an unhandled exception.

Exception Info: System.Security.Authentication.AuthenticationException Stack: at System.Net.Security.SslState.ForceAuthentication(Boolean, Byte[], System.Net.AsyncProtocolRequest) at System.Net.Security.SslState.ProcessAuthentication(System.Net.LazyAsyncResult) at System.Net.Security.SslStream.AuthenticateAsClient(System.String) at LogentriesCore.AsyncLoggerBase.Run() at System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean) at System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean) at System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) at System.Threading.ThreadHelper.ThreadStart()

Source: ASP.NET 4.0.30319.0

An unhandled exception occurred and the process was terminated.

Application ID: /LM/W3SVC/1/ROOT

Process ID: 10156

Exception: System.Security.Authentication.AuthenticationException

Message: The remote certificate is invalid according to the validation procedure.

StackTrace: at System.Net.Security.SslState.StartSendAuthResetSignal(ProtocolToken message, AsyncProtocolRequest asyncRequest, Exception exception) at System.Net.Security.SslState.StartSendBlob(Byte[] incoming, Int32 count, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.ProcessReceivedBlob(Byte[] buffer, Int32 count, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.StartReceiveBlob(Byte[] buffer, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.StartSendBlob(Byte[] incoming, Int32 count, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.ProcessReceivedBlob(Byte[] buffer, Int32 count, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.StartReceiveBlob(Byte[] buffer, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.StartSendBlob(Byte[] incoming, Int32 count, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.ProcessReceivedBlob(Byte[] buffer, Int32 count, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.StartReceiveBlob(Byte[] buffer, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.StartSendBlob(Byte[] incoming, Int32 count, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.ProcessReceivedBlob(Byte[] buffer, Int32 count, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.StartReceiveBlob(Byte[] buffer, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.StartSendBlob(Byte[] incoming, Int32 count, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.ProcessReceivedBlob(Byte[] buffer, Int32 count, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.StartReceiveBlob(Byte[] buffer, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.StartSendBlob(Byte[] incoming, Int32 count, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.ProcessReceivedBlob(Byte[] buffer, Int32 count, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.StartReceiveBlob(Byte[] buffer, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.StartSendBlob(Byte[] incoming, Int32 count, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.ProcessReceivedBlob(Byte[] buffer, Int32 count, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.StartReceiveBlob(Byte[] buffer, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.StartSendBlob(Byte[] incoming, Int32 count, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.ForceAuthentication(Boolean receiveFirst, Byte[] buffer, AsyncProtocolRequest asyncRequest) at System.Net.Security.SslState.ProcessAuthentication(LazyAsyncResult lazyResult) at System.Net.Security.SslStream.AuthenticateAsClient(String targetHost) at LogentriesCore.AsyncLoggerBase.Run() at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx) at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx) at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state) at System.Threading.ThreadHelper.ThreadStart()

This stack trace doesn't contain any of our own code; the only thing that meant anything to me was the bit about Logentries. So I right away opened the web.config file and commented out the following line in the Log4Net config:

<appender-ref ref="LeAppender" />

where LeAppender was defined before as

<appender name="LeAppender" type="log4net.Appender.LogentriesAppender, LogentriesLog4net">
  <UseHttp value="false" />
  <UseSsl value="true" />
  <layout type="log4net.Layout.PatternLayout">
    <conversionPattern value="%date %-5level %logger [host=%P{log4net:HostName}:appdomain=%appdomain:referenceid=%property{referenceid}] - %message%newline" />
  </layout>
</appender>

I restarted the web site and everything started working again, and our customers were none the wiser; it's very fortunate that this all happened and got resolved before business hours (but it was close!).

This totally freaks me out. Log4Net, to my mind, is supposed to be a totally robust framework that cannot possibly do any damage. It seems to me that Logentries had a certificate expire (or something like that), and the effect of that was immediately to crash our production web site!

Is there something wrong with our Log4Net/Logentries setup?

Initial configuration (dunno what could be wrong with this):

XmlConfigurator.Configure();

The logger itself is an ILog, and it is assigned like so:

_log = LogManager.GetLogger("Logger");

and the logging is done like so:

_log.Logger.Log(typeof(MyLogger), level, message, ex);

Nothing untoward here. And it's been working fine for over a year. Moreover, the stack trace, as I mentioned before, doesn't have any reference to any of our own code, so it's probably not due to any bad code that we've written.

Any ideas what went wrong, how to fix it, and how to make sure that this kind of outage never brings our system down again?


Solution

  • "On the 14th of September new SSL certificates were issued for api.logentries.com. Due to constraints these certificates do not match older certificates that were previously provided for api.logentries.com. We advise all Users who are currently embedding old api.logentries.com certificates to switch to use your systems cert pool. For help on changing your setup please contact support@logentries.com"

    This message was supposed to show up the first time you logged into log entries today. This is why your problems started today.

    If you upgrade your log4net package to the latest, and your logentries package to the latest, your problem will be solved.