fix/message template scope extensions (#290)

elastic · Mar 27, 2023 · e2b8208 · e2b8208
1 parent ceae3da
commit e2b8208
Show file tree

Hide file tree

Showing 2 changed files with 34 additions and 7 deletions.
diff --git a/src/Elasticsearch.Extensions.Logging/ElasticsearchLogger.cs b/src/Elasticsearch.Extensions.Logging/ElasticsearchLogger.cs
@@ -58,7 +58,7 @@ Func<TState, Exception, string> formatter
 				// Maybe render to JSON in-process, then queue bytes for sending to index ??
 
 				var logEvent = BuildLogEvent(_categoryName, logLevel, eventId, state, exception, formatter);
-				_channel.TryWrite(logEvent);
+				var written = _channel.TryWrite(logEvent);
 			}
 			catch (Exception ex)
 			{
@@ -78,9 +78,7 @@ void AddScopeValue<TState>(TState scope, LogEvent log)
 
 
 				var scopeValues = (scope as IEnumerable<KeyValuePair<string, object>>)?.ToList();
-				var scopeName = scope as string ?? scope.GetType().Name;
-				if (scopeValues != null && scopeValues.Any(kv=>kv.Key == "{OriginalFormat}"))
-					scopeName = FormatValue(scope);
+				var scopeName = scopeValues != null && scopeValues.Any(kv => kv.Key == "{OriginalFormat}") ? scope.ToString() : FormatValue(scope, 0, scope.GetType().Name);
 				log.Scopes.Add(scopeName);
 
 				if (scopeValues == null) return;
@@ -105,7 +103,8 @@ private void AssignStateOrScopeLabels(LogEvent logEvent, KeyValuePair<string, ob
 		{
 			if (kvp.Key == "{OriginalFormat}")
 			{
-				logEvent.MessageTemplate ??= kvp.Value.ToString();
+				// we explicitly want this to override, preferring OriginalFormat from current state over scope
+				logEvent.MessageTemplate = kvp.Value.ToString();
 				return;
 			}
 			var value = FormatValue(kvp.Value);
@@ -228,7 +227,7 @@ private string FormatStringDictionary(IDictionary<string, object> dictionary, in
 			return stringBuilder.ToString();
 		}
 
-		private string FormatValue(object value, int depth = 0)
+		private string FormatValue(object value, int depth = 0, string? defaultFallback = null)
 		{
 			switch (value)
 			{
@@ -260,7 +259,7 @@ private string FormatValue(object value, int depth = 0)
 					if (depth < 1 && value is IEnumerable enumerable)
 						return FormatEnumerable(enumerable, depth);
 
-					return value.ToString();
+					return defaultFallback ?? value.ToString();
 			}
 		}
 

diff --git a/...integration/Elasticsearch.Extensions.Logging.IntegrationTests/LoggingToDataStreamTests.cs b/...integration/Elasticsearch.Extensions.Logging.IntegrationTests/LoggingToDataStreamTests.cs
@@ -95,5 +95,33 @@ public async Task SerializesAndDeserializesMessageTemplateAndScope()
 			loggedError.Scopes.Should().ContainSingle(s => s == "custom scope");
 		}
 
+		[Fact]
+		public async Task MessageTemplateOnLogIsNotTemplatedScope()
+		{
+			using var _ = CreateLogger(out var logger, out var provider, out var @namespace, out var waitHandle, out var listener);
+			using var scope = logger.BeginScope("My Scope {Value}", "value");
+			var dataStream = $"x-dotnet-{@namespace}";
+			var userId = 1;
+			logger.LogError("an error occurred for userId {UserId}", userId);
+
+			if (!waitHandle.WaitOne(TimeSpan.FromSeconds(10)))
+				throw new Exception($"No flush occurred in 10 seconds: {listener}", listener.ObservedException);
+
+			listener.PublishSuccess.Should().BeTrue("{0}", listener);
+			listener.ObservedException.Should().BeNull();
+
+			await Client.Indices.RefreshAsync(dataStream);
+
+			var response = Client.Search<LogEvent>(new SearchRequest(dataStream));
+
+			response.IsValidResponse.Should().BeTrue("{0}", response.DebugInformation);
+			response.Total.Should().BeGreaterThan(0);
+
+			var loggedError = response.Documents.First();
+			loggedError.Message.Should().Be("an error occurred for userId 1");
+			loggedError.MessageTemplate.Should().Be("an error occurred for userId {UserId}");
+			loggedError.Scopes.Should().ContainSingle(s => s == "My Scope value");
+		}
+
 	}
 }