.NET Core console application does not log unless program execution is halted

[DontWorry33]

Hello,

When I was trying to create an example application (similar to https://github.com/jptoto/log4net.ES.Example but for .NET Core instead), I realized that logging into elastic does not work unless there is a Console.ReadKey() or anything that lets the application halt its execution at the end of the Program. This is not the same case when running the example application linked above as that one will work without putting a Console.ReadKey(). My assumption is that it has to do something with async tasks not completing because when I tried to debug the issue, it seemed like the program doesn't continue on to the Post method (my breakpoint never gets hit) after this line in Repository.cs :

logEvents.Do(logEvent => httpClient.Post(uri, logEvent));

I also don't get any errors reported without the Console.ReadKey().

Here is my configuration:

Program.cs

using System;
using System.IO;
using System.Reflection;
using log4net;
using log4net.Config;

namespace ConsoleApp1
{
    class Program
    {
        // Create a new logging instance
        private static readonly ILog _log = LogManager.GetLogger(typeof(Program));

        static void Main(string[] args)
        {
            XmlConfigurator.Configure(LogManager.GetRepository(Assembly.GetCallingAssembly()), new FileInfo("log4net.config"));

            // Most basic logging example.
            _log.ErrorFormat("System Error {0}", "Divide by zero error.");


            // Log a message with an exeption object
            _log.Error("System Error", new Exception("Something terrible happened."));


            // Log an exception object with custom fields in the Data property
            Exception newException = new Exception("There was a system error");
            newException.Data.Add("CustomProperty", "CustomPropertyValue");
            newException.Data.Add("SystemUserID", "User43");

            _log.Error("Something broke.", newException);
            //Console.ReadKey();
        }
    }
}

log4net.config

<log4net>
    <!-- Default style appender. You can change the name but make sure you reference it corectly. Change the type if you're using .NET 4.0 -->
    <appender name="ElasticSearchAppender" type="log4net.ElasticSearch.ElasticSearchAppender, log4net.ElasticSearch">
      <layout type="log4net.Layout.PatternLayout,log4net">
        <param name="ConversionPattern" value="%d{ABSOLUTE} %-5p %c{1}:%L - %m%n" />
      </layout>
      
      <!-- You can also use scheme, user, password here if you need https and http authentication, see the docs -->
      <connectionString value="Scheme=http;Server=localhost;Index=log;Port=9200;rolling=true"/>
      
      <!-- false means do not eject older messages when the buffer is full, try to keep them all. -->
      <lossy value="false" />
      
      <!-- Any buffer > 1 will use the Elasticsearch _bulk API. Tune as needed depending on how high volume your app is and how fast you want messages to show up in ES -->
      <bufferSize value="1" />
      
      <!-- When an event comes in that matches or is above the treshold, the buffer will flush. I don't reccommend setting to "ALL" or it will defeat the purpose of having a buffer -->
      <evaluator type="log4net.Core.LevelEvaluator">
        <threshold value="DEBUG"/>
      </evaluator>
    </appender>
    
    <!-- Common to all log4net configs. See log4net docs for more details  -->
    <root>
      <level value="ALL"/>
      <appender-ref ref="ElasticSearchAppender" />
    </root>
  </log4net>

Uncommenting the Console.ReadKey() and waiting a second before terminating the application will successfully log the messages to Elastic, however, if I throw an exception in Repository.cs (line 47), I get the following errors:

log4net: Configuration update mode [Merge].
log4net: Logger [root] Level string is [ALL].
log4net: Logger [root] level set to [name="ALL",value=-2147483648].
log4net: Loading Appender [ElasticSearchAppender] type: [log4net.ElasticSearch.ElasticSearchAppender, log4net.ElasticSearch]
log4net: Converter [message] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [newline] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Setting Property [ConversionPattern] to String value [%d{ABSOLUTE} %-5p %c{1}:%L - %m%n]
log4net: Converter [d] Option [ABSOLUTE] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [literal] Option [ ] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [p] Option [] Format [min=5,max=2147483647,leftAlign=True]
log4net: Converter [literal] Option [ ] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [c] Option [1] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [literal] Option [:] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [L] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [literal] Option [ - ] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [m] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [n] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Setting Property [Layout] to object [log4net.Layout.PatternLayout]
log4net: Setting Property [ConnectionString] to String value [Scheme=http;Server=localhost;Index=log;Port=9200;rolling=true]
log4net: Setting Property [Lossy] to Boolean value [False]
log4net: Setting Property [BufferSize] to Int32 value [1]
log4net: Setting Property [Threshold] to Level value [DEBUG]
log4net: Setting Property [Evaluator] to object [log4net.Core.LevelEvaluator]
log4net: Created Appender [ElasticSearchAppender]
log4net: Adding appender named [ElasticSearchAppender] to logger [root].
log4net: Hierarchy Threshold []
log4net:ERROR [ElasticSearchAppender] ErrorCode: GenericFailure. ElasticSearchAppender [ElasticSearchAppender]: Failed to addd logEvents to Repository in SendBufferCallback.
log4net:ERROR [ElasticSearchAppender] ErrorCode: GenericFailure. ElasticSearchAppender [ElasticSearchAppender]: Failed to addd logEvents to Repository in SendBufferCallback.
log4net:ERROR [ElasticSearchAppender] ErrorCode: GenericFailure. ElasticSearchAppender [ElasticSearchAppender]: Failed to addd logEvents to Repository in SendBufferCallback.
System.Exception: Cannot access a disposed object.
Object name: 'System.Net.HttpWebResponse'.
   at log4net.ElasticSearch.Repository.Add(IEnumerable`1 logEvents, Int32 bufferSize) in C:\Users\hha\workspace\log4net.ElasticSearch\src\log4net.ElasticSearch\Repository.cs:line 49
   at log4net.ElasticSearch.ElasticSearchAppender.SendBufferCallback(Object state) in C:\Users\hha\workspace\log4net.ElasticSearch\src\log4net.ElasticSearch\ElasticSearchAppender.cs:line 93
System.Exception: Cannot access a disposed object.
Object name: 'System.Net.HttpWebResponse'.
   at log4net.ElasticSearch.Repository.Add(IEnumerable`1 logEvents, Int32 bufferSize) in C:\Users\hha\workspace\log4net.ElasticSearch\src\log4net.ElasticSearch\Repository.cs:line 49
   at log4net.ElasticSearch.ElasticSearchAppender.SendBufferCallback(Object state) in C:\Users\hha\workspace\log4net.ElasticSearch\src\log4net.ElasticSearch\ElasticSearchAppender.cs:line 93
System.Exception: Cannot access a disposed object.
Object name: 'System.Net.HttpWebResponse'.
   at log4net.ElasticSearch.Repository.Add(IEnumerable`1 logEvents, Int32 bufferSize) in C:\Users\hha\workspace\log4net.ElasticSearch\src\log4net.ElasticSearch\Repository.cs:line 49
   at log4net.ElasticSearch.ElasticSearchAppender.SendBufferCallback(Object state) in C:\Users\hha\workspace\log4net.ElasticSearch\src\log4net.ElasticSearch\ElasticSearchAppender.cs:line 93

[bruno-garcia]

One difference between your sample and the one you mentioned is that your are using bufferSize=1. The sample uses 100 which uses the bulk API. I'm not sure it has anything to do because this Appender derives from BufferingAppenderSkeleton, which is asynchronous. So in any case you should make sure events are flushed before exiting. I would expect you to Flush all queued events at the end of the app.

This was raised on stackoverflow:

To wait up to 2 seconds to flush queued events:
LogManager.Flush(2000);