Bulk support for extensions logging integration.

ecs-dotnet.sln

@@ -75,6 +75,8 @@ Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "Elasticsearch.Extensions.Lo
 EndProject
 Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "Elasticsearch.Extensions.Logging.IntegrationTests", "tests\Elasticsearch.Extensions.Logging.IntegrationTests\Elasticsearch.Extensions.Logging.IntegrationTests.csproj", "{0E7008E1-B215-4B9B-BC28-DC9D31415FB9}"
 EndProject
+Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "Elasticsearch.Extensions.Logging.Example", "examples\Elasticsearch.Extensions.Logging.Example\Elasticsearch.Extensions.Logging.Example.csproj", "{F319AD28-A0A4-4012-8480-E2A4CFA755C2}"
+EndProject
 Global
 	GlobalSection(SolutionConfigurationPlatforms) = preSolution
 		Debug|Any CPU = Debug|Any CPU
@@ -163,6 +165,10 @@ Global
 		{0E7008E1-B215-4B9B-BC28-DC9D31415FB9}.Debug|Any CPU.Build.0 = Debug|Any CPU
 		{0E7008E1-B215-4B9B-BC28-DC9D31415FB9}.Release|Any CPU.ActiveCfg = Release|Any CPU
 		{0E7008E1-B215-4B9B-BC28-DC9D31415FB9}.Release|Any CPU.Build.0 = Release|Any CPU
+		{F319AD28-A0A4-4012-8480-E2A4CFA755C2}.Debug|Any CPU.ActiveCfg = Debug|Any CPU
+		{F319AD28-A0A4-4012-8480-E2A4CFA755C2}.Debug|Any CPU.Build.0 = Debug|Any CPU
+		{F319AD28-A0A4-4012-8480-E2A4CFA755C2}.Release|Any CPU.ActiveCfg = Release|Any CPU
+		{F319AD28-A0A4-4012-8480-E2A4CFA755C2}.Release|Any CPU.Build.0 = Release|Any CPU
 	EndGlobalSection
 	GlobalSection(SolutionProperties) = preSolution
 		HideSolutionNode = FALSE
@@ -190,6 +196,7 @@ Global
 		{EC19A9E1-79CC-46A8-94D7-EE66ED22D3BD} = {3582B07D-C2B0-49CC-B676-EAF806EB010E}
 		{D88AAA7D-1AEE-4B4C-BE37-69BA85DA07DA} = {7610B796-BB3E-4CB2-8296-79BBFF6D23FC}
 		{0E7008E1-B215-4B9B-BC28-DC9D31415FB9} = {3582B07D-C2B0-49CC-B676-EAF806EB010E}
+		{F319AD28-A0A4-4012-8480-E2A4CFA755C2} = {05075402-8669-45BD-913A-BD40A29BBEAB}
 	EndGlobalSection
 	GlobalSection(ExtensibilityGlobals) = postSolution
 		SolutionGuid = {7F60C4BB-6216-4E50-B1E4-9C38EB484843}

examples/Elasticsearch.Extensions.Logging.Example/Elasticsearch.Extensions.Logging.Example.csproj

@@ -0,0 +1,26 @@
+<Project Sdk="Microsoft.NET.Sdk">
+
+  <PropertyGroup>
+    <OutputType>Exe</OutputType>
+    <TargetFramework>netcoreapp3.1</TargetFramework>
+    <LangVersion>latest</LangVersion>
+    <Nullable>enable</Nullable>
+  </PropertyGroup>
+
+  <ItemGroup>
+    <PackageReference Include="Microsoft.Extensions.Hosting" Version="3.1.6" />
+    <PackageReference Include="Elastic.Elasticsearch.Ephemeral" Version="0.2.4" />
+    <PackageReference Include="NEST" Version="7.8.1" />
+  </ItemGroup>
+
+  <ItemGroup>
+    <ProjectReference Include="..\..\src\Elasticsearch.Extensions.Logging\Elasticsearch.Extensions.Logging.csproj" />
+  </ItemGroup>
+
+  <ItemGroup>
+    <None Update="appsettings.json">
+      <CopyToOutputDirectory>PreserveNewest</CopyToOutputDirectory>
+    </None>
+  </ItemGroup>
+
+</Project>

examples/Elasticsearch.Extensions.Logging.Example/HighVolumeWorkSimulation.cs

@@ -0,0 +1,30 @@
+using System;
+using System.Collections.Generic;
+using System.Net;
+using System.Security.Claims;
+using System.Security.Principal;
+using System.Threading;
+using System.Threading.Tasks;
+using Microsoft.Extensions.Hosting;
+using Microsoft.Extensions.Logging;
+
+namespace Elasticsearch.Extensions.Logging.Example
+{
+
+	/// <summary> Simulate work that logs in low volume with some time in between each log call </summary>
+	public class HighVolumeWorkSimulation : BackgroundService
+	{
+		private readonly ILogger<HighVolumeWorkSimulation> _logger;
+
+		public HighVolumeWorkSimulation(ILogger<HighVolumeWorkSimulation> logger) => _logger = logger;
+
+		protected override async Task ExecuteAsync(CancellationToken ctx)
+		{
+			for (var i = 0; i < 100_000; i++)
+			{
+				_logger.LogWarning($"We are logging way too much: {i}");
+				if (i % 100 == 0) await Task.Delay(1, ctx);
+			}
+		}
+	}
+}

examples/Elasticsearch.Extensions.Logging.Example/Log.cs

@@ -0,0 +1,39 @@
+using System;
+using Microsoft.Extensions.Logging;
+
+namespace Elasticsearch.Extensions.Logging.Example
+{
+	public class Log
+	{
+		public static readonly Action<ILogger, Exception?> CriticalErrorExecuteFailed =
+			LoggerMessage.Define(LogLevel.Critical,
+				new EventId(9000, nameof(CriticalErrorExecuteFailed)),
+				"Critical error, execute failed.");
+
+		public static readonly Action<ILogger, int, Exception?> ErrorProcessingCustomer =
+			LoggerMessage.Define<int>(LogLevel.Error,
+				new EventId(5000, nameof(ErrorProcessingCustomer)),
+				"Unexpected error processing customer {CustomerId}.");
+
+		public static readonly Action<ILogger, Guid, Exception?> ProcessOrderItem =
+			LoggerMessage.Define<Guid>(LogLevel.Information,
+				new EventId(1000, nameof(ProcessOrderItem)),
+				"Processing order item {ItemId}.");
+
+		public static readonly Action<ILogger, byte, bool, Exception?> SignInToken =
+			LoggerMessage.Define<byte, bool>(LogLevel.Trace,
+				new EventId(1, nameof(SignInToken)),
+				"Sign in secret token checksum {Checksum}: {Success}.");
+
+		public static readonly Action<ILogger, int, Exception?> StartingProcessing =
+			LoggerMessage.Define<int>(LogLevel.Debug,
+				new EventId(6000, nameof(StartingProcessing)),
+				"Starting processing of {ItemCount} items.");
+
+		public static readonly Action<ILogger, DateTimeOffset, Exception?> WarningEndOfProcessing =
+			LoggerMessage.Define<DateTimeOffset>(LogLevel.Warning,
+				new EventId(4000, nameof(WarningEndOfProcessing)),
+				"End of processing reached at {EndTime}.");
+	}
+
+}

examples/Elasticsearch.Extensions.Logging.Example/LowVolumeWorkSimulation.cs

@@ -0,0 +1,87 @@
+using System;
+using System.Collections.Generic;
+using System.Net;
+using System.Security.Claims;
+using System.Security.Principal;
+using System.Threading;
+using System.Threading.Tasks;
+using Microsoft.Extensions.Hosting;
+using Microsoft.Extensions.Logging;
+
+namespace Elasticsearch.Extensions.Logging.Example
+{
+
+	/// <summary> Simulate work that logs in low volume with some time in between each log call </summary>
+	public class LowVolumeWorkSimulation : BackgroundService
+	{
+		private readonly ILogger<LowVolumeWorkSimulation> _logger;
+
+		public LowVolumeWorkSimulation(ILogger<LowVolumeWorkSimulation> logger) => _logger = logger;
+
+		protected override async Task ExecuteAsync(CancellationToken stoppingToken)
+		{
+			var ipAddress = IPAddress.Parse("2001:db8:85a3::8a2e:370:7334");
+			var customerId = 12345;
+			var orderId = "PO-56789";
+			var dueDate = new DateTime(2020, 1, 2);
+			var token = new byte[] { 0x12, 0x34, 0xbc, 0xde };
+			var checksum = (byte)0x9a;
+			var success = true;
+			var end = new DateTimeOffset(2020, 1, 2, 3, 4, 5, TimeSpan.FromHours(6));
+			var total = 100;
+			var rate = 0;
+
+			Thread.CurrentPrincipal = new ClaimsPrincipal(new GenericIdentity("user@example.com"));
+			//Trace.CorrelationManager.ActivityId = Guid.NewGuid();
+
+			using (_logger.BeginScope("IP address {ip}", ipAddress))
+			{
+				try
+				{
+					using (_logger.BeginScope(new Dictionary<string, object> { ["SecretToken"] = token }))
+					{
+						Log.SignInToken(_logger, checksum, success, null);
+					}
+
+					using (_logger.BeginScope("Customer {CustomerId}, Order {OrderId}, Due {DueDate:yyyy-MM-dd}",
+						customerId, orderId, dueDate))
+					{
+						Log.StartingProcessing(_logger, 10, null);
+						var items = new List<Guid>();
+						for (var i = 0; i < 10; i++)
+						{
+							await Task.Delay(TimeSpan.FromMilliseconds(1000), stoppingToken).ConfigureAwait(false);
+							var item = Guid.NewGuid();
+							Log.ProcessOrderItem(_logger, item, null);
+							items.Add(item);
+						}
+
+						using (_logger.BeginScope("{ItemsProcessed}", items))
+						{
+							_logger.LogWarning("End of processing reached at {EndTime}.", end);
+							Log.WarningEndOfProcessing(_logger, end, null);
+						}
+
+						try
+						{
+							var points = total / rate;
+						}
+						catch (Exception ex)
+						{
+							throw new Exception("Calculation error", ex);
+						}
+					}
+				}
+				catch (Exception ex)
+				{
+					using (_logger.BeginScope("PlainScope"))
+					{
+						Log.ErrorProcessingCustomer(_logger, customerId, ex);
+					}
+				}
+			}
+
+			Log.CriticalErrorExecuteFailed(_logger, null);
+		}
+	}
+}

examples/Elasticsearch.Extensions.Logging.Example/Program.cs

@@ -0,0 +1,67 @@
+using System;
+using System.Threading.Tasks;
+using Elastic.Elasticsearch.Ephemeral;
+using Elasticsearch.Net;
+using Microsoft.Extensions.Configuration;
+using Microsoft.Extensions.DependencyInjection;
+using Microsoft.Extensions.Hosting;
+using Microsoft.Extensions.Logging;
+using Nest;
+
+namespace Elasticsearch.Extensions.Logging.Example
+{
+	internal static class Program
+	{
+		public static IHostBuilder CreateHostBuilder(string[] args)
+		{
+			var highLoadUseCase = args.Length > 0 && args[0] == "high";
+			return Host.CreateDefaultBuilder(args)
+				.UseConsoleLifetime()
+				.ConfigureAppConfiguration((hostContext, configurationBuilder) =>
+				{
+					configurationBuilder.SetBasePath(AppDomain.CurrentDomain.BaseDirectory);
+				})
+				.ConfigureLogging((hostContext, loggingBuilder) =>
+				{
+					// removing console logger when showcasing high traffic, too noisy otherwise
+					if (highLoadUseCase)
+						loggingBuilder.ClearProviders();
+
+					loggingBuilder.AddElasticsearch(c =>
+					{
+						if (highLoadUseCase)
+							c.BufferOptions = new BufferOptions { ConcurrentConsumers = 4, PublishRejectionCallback = e => Console.Write("!") };
+
+						c.BufferOptions.ElasticsearchResponseCallback = (r, b) =>
+							Console.WriteLine($"Indexed: {r.ApiCall.Success} items: {b.Count} time since first read: {b.DurationSinceFirstRead}");
+					});
+				})
+				.ConfigureServices((hostContext, services) =>
+				{
+					if (args.Length > 0 && args[0] == "high")
+						services.AddHostedService<HighVolumeWorkSimulation>();
+					else services.AddHostedService<LowVolumeWorkSimulation>();
+				});
+		}
+
+		public static async Task Main(string[] args)
+		{
+			using var cluster = new EphemeralCluster("7.8.0");
+			var client = CreateClient(cluster);
+			if (!(await client.RootNodeInfoAsync()).IsValid)
+				cluster.Start(TimeSpan.FromMinutes(1));
+			else Console.WriteLine("Using already running Elasticsearch instance");
+
+			await CreateHostBuilder(args).Build().RunAsync();
+		}
+
+		private static ElasticClient CreateClient(EphemeralCluster cluster)
+		{
+			var nodes = cluster.NodesUris();
+			var connectionPool = new StaticConnectionPool(nodes);
+			var settings = new ConnectionSettings(connectionPool)
+				.EnableDebugMode();
+			return new ElasticClient(settings);
+		}
+	}
+}

examples/Elasticsearch.Extensions.Logging.Example/appsettings.json

@@ -0,0 +1,17 @@
+{
+  "Logging": {
+    "Elasticsearch": {
+      "Tags": [ "Development", "Example" ],
+      "IndexOffset": "00:00",
+      "IsEnabled": true,
+      "IncludeScopes": true,
+      "IncludeHost": true,
+      "IncludeProcess": true,
+      "IncludeUser": true
+    },
+    "LogLevel" : {
+      "Default": "Trace",
+      "Microsoft": "Warning"
+    }
+  }
+}