Unable to send to ES, selflog is empty and invalid-200 file is created

[lachlann562]

trafficstars

A few questions before you begin:

Is this an issue related to the Serilog core project or one of the sinks or community projects.
This issue list is intended for Serilog Elasticsearch Sink issues. If this issue relates to another sink or to the code project, please log on the related repository. Please use Gitter chat and Stack Overflow for discussions and questons.

Does this issue relate to a new feature or an existing bug?

• [X] Bug
• [ ] New Feature

What version of Serilog.Sinks.Elasticsearch is affected? Please list the related NuGet package. PM> Get-Package serilog | where {$_.Id -match 'serilog'} | select Id,Versions

Id Versions

---

Serilog.Sinks.Debug {1.0.1} Serilog.Extensions.Hosting {3.1.0} Serilog.Sinks.ElasticSearch {8.1.0} Serilog.Settings.Configuration {3.1.0} Serilog.Exceptions {5.5.0} Serilog.Sinks.Console {3.1.1} Serilog.Sinks.File {4.1.0} Serilog.Enrichers.Environment {2.1.3} Serilog {2.9.0} Serilog.AspNetCore {3.2.0} Serilog.Extensions.Logging {3.0.1}

What is the target framework and operating system? See target frameworks & net standard matrix.

• [X] netCore 3.1
• [ ] netCore 2.0
• [ ] netCore 1.0
• [ ] 4.7
• [ ] 4.6.x
• [ ] 4.5.x

Please describe the current behavior? Nothing is sent to elastic search, other sinks (file, console, jsonfile) all work as expected. SelfLog is empty. a invalid-200 file is written when i added a buffer file.

Please describe the expected behavior? index is created & messages saved to the index

If the current behavior is a bug, please provide the steps to reproduce the issue and if possible a minimal demo of the problem

program.cs

    public static class Program
    {
        public static void Main(string[] args)
        {
            // setup logging first!
            ConfigureLogging();
			//var file = File.CreateText(@"C:\usr\sitelogs\serilog-selflog.log");
			//Serilog.Debugging.SelfLog.Enable(TextWriter.Synchronized(file));
			Serilog.Debugging.SelfLog.Enable(message => Console.WriteLine(message));
			var appName = Assembly.GetExecutingAssembly().GetName().Name;
			try
			{
				Log.Information("Initiating web host builder for {Application}.",appName);
				Log.CloseAndFlush(); // tried this, didn't help
				CreateWebHostBuilder(args).Build().Run();
			}
			catch (System.Exception ex)
			{
				Log.Fatal(ex, "Failed to start {Application}",appName);
				throw;
			}
		}

		public static IWebHostBuilder CreateWebHostBuilder(string[] args) =>
			WebHost.CreateDefaultBuilder(args)
				// Add custom logging providers the same way. TO DO: create a wiki page
				// Reference: https://docs.microsoft.com/en-us/aspnet/core/fundamentals/logging/?view=aspnetcore-2.2
				.UseSerilog()
                .UseStartup<Startup>()
			;


		private static void ConfigureLogging()
		{
			var environment = Environment.GetEnvironmentVariable("ASPNETCORE_ENVIRONMENT");
			var configuration = new ConfigurationBuilder()
				.AddJsonFile("appsettings.json", optional: false, reloadOnChange: true)
				.AddJsonFile(
					$"appsettings.{Environment.GetEnvironmentVariable("ASPNETCORE_ENVIRONMENT")}.json",
					optional: true)
				.Build();

			Log.Logger = new LoggerConfiguration()
				.Enrich.FromLogContext()
				.Enrich.WithMachineName()
				.WriteTo.Debug()
				.WriteTo.Console()
				.WriteTo.Elasticsearch(ConfigureElasticSink(configuration, environment))
				.WriteTo.File((new Serilog.Formatting.Json.JsonFormatter()), @"C:\usr\sitelogs\serilog.log")
				.Enrich.WithProperty("Environment", environment)
				.ReadFrom.Configuration(configuration)
				.CreateLogger();


		}

		private static ElasticsearchSinkOptions ConfigureElasticSink(IConfigurationRoot configuration, string environment)
		{
			
			// configure the nodes
			var nodes = configuration["ElasticConfiguration:Uri"]
														.Split(",", StringSplitOptions.RemoveEmptyEntries)
                                                        .Select(x => new Uri(x));
			var user = configuration["ElasticConfiguration:User"];
			var pass = configuration["ElasticConfiguration:Password"];

			NameValueCollection headers = new NameValueCollection();
			if (!string.IsNullOrEmpty(user) && !string.IsNullOrEmpty(pass))
				headers.Add("Authorization", $"Basic {Convert.ToBase64String(System.Text.Encoding.UTF8.GetBytes($"{user}:{pass}"))}");

			var indexName = $"{Assembly.GetExecutingAssembly().GetName().Name.ToLower().Replace(".", "-")}-{environment?.ToLower().Replace(".", "-")}-{DateTime.UtcNow:yyyy-MM}";

			// configure the options
			ElasticsearchSinkOptions options = new ElasticsearchSinkOptions(nodes)
			{
				IndexFormat = "myindex-{0:yyyy.MM.dd}", // hardcode for debugging
				AutoRegisterTemplate = true,
				ModifyConnectionSettings = (c) => c.GlobalHeaders(headers),
                
                // the following options were added to aid in debugging
				EmitEventFailure =
										EmitEventFailureHandling.WriteToSelfLog |
										EmitEventFailureHandling.RaiseCallback |
										EmitEventFailureHandling.ThrowException,
				FailureCallback = e =>
				{
					Console.WriteLine("Unable to submit event " + e.MessageTemplate);
				},
				BufferBaseFilename = $@"C:\usr\sitelogs\serilog-buffer.log",
			};
			
			return options;
		}
	}
   }

AppSettings.json

Logging": {
    "LogLevel": {
      "Default": "Trace" /*,
      "Microsoft": "Warning",
      "Microsoft.Hosting.Lifetime": "Information"*/
    },
    "Serilog": {
      "MinimumLevel": {
        "Default": "Trace",
        "Override": {
          "Microsoft": "Information",
          "System": "Warning"
        }
      }
    }

  },
  "ElasticConfiguration": {
    "Uri": "https://myesnode:9200/",
    "User": "myuser",
    "Password": "mypassword"

  },

Startup.cs

      public override void ConfigureAppServices(IServiceCollection services)
       {
           services.AddLogging((builder) => builder.AddSerilog(dispose: true)); // tried this suggestion, didn't help
       }

serilog-selflog.log --> file is empty serilog-buffer.log.{date}.json {"@timestamp":"2020-06-25T13:46:36.2753717-04:00","level":"Information","messageTemplate":"Initiating web host builder for {Application}.","message":"Initiating web host builder for \"myapp\".","fields":{"Application":"myapp","MachineName":"L01215","Environment":"Development"}}

invalid-200-{guid}.json

{"index":{"_index":"myindex-2020.06.25","_type":"_doc","_id":"0_088efd4f-02c4-4467-8908-57fe1a531216"}}
{"@timestamp":"2020-06-25T13:46:36.2753717-04:00","level":"Information","messageTemplate":"Initiating web host builder for {Application}.","message":"Initiating web host builder for \"myapp\".","fields":{"Application":"myapp","MachineName":"L01215","Environment":"Development"}}

however elastic does not show a "myindex"

the buffer was added as a way to evaluate if it is buffering anything to send.

[mivano]

Hard to tell what is causing this. some ideas:

• The buffer might sometimes also be a culprit, but I assume you also tried without. Tried accessing your ES logs on the ES server?
• Do you see data being sent when you use something like Fiddler?
• Are you able to setup a very minimal example, just adding the bare minimal components for ES logging and see if that works, in order to exclude other parts of the code?

[suadev]

Same here. Asp.Net Core write its own log to ES successfully.

But, manual logging like below never appears on ES and self logging is useless.

 _logger.LogInformation($"Handling Request:{typeof(TRequest).Name}");