From 1fe8dfaa2e695435bdaebaef2e246756db120195 Mon Sep 17 00:00:00 2001 From: Stuart Cam Date: Wed, 26 Feb 2020 15:27:57 +1100 Subject: [PATCH] NLog Layout (#44) Add an NLog Layout for ECS --- README.md | 27 +- .../ApmTraceIdLayoutRenderer.cs | 8 +- .../ApmTransactionIdLayoutRenderer.cs | 8 +- .../ElasticApmEnricher.cs | 4 +- .../ElasticApmEnricherExtension.cs | 7 +- src/Elastic.CommonSchema.NLog/EcsLayout.cs | 434 ++++++++++++++++++ .../Elastic.CommonSchema.NLog.csproj | 17 + src/Elastic.CommonSchema.NLog/README.md | 66 +++ .../LogEventConverter.cs | 7 +- src/Generator/CodeConfiguration.cs | 2 + src/Generator/NLogHelper.cs | 35 ++ src/Generator/Schema/EcsSpecification.cs | 4 +- src/ecs-dotnet.sln | 14 + .../Elastic.Apm.NLog.Test.csproj | 1 + tests/Elastic.Apm.NLog.Test/NLogTests.cs | 4 + .../ApmTests.cs | 44 ++ .../Elastic.CommonSchema.NLog.Tests.csproj | 26 ++ .../LogTestsBase.cs | 59 +++ .../MessageTests.cs | 49 ++ .../OutputTests.cs | 38 ++ .../LogTestsBase.cs | 4 +- 21 files changed, 833 insertions(+), 25 deletions(-) create mode 100644 src/Elastic.CommonSchema.NLog/EcsLayout.cs create mode 100644 src/Elastic.CommonSchema.NLog/Elastic.CommonSchema.NLog.csproj create mode 100644 src/Elastic.CommonSchema.NLog/README.md create mode 100644 src/Generator/NLogHelper.cs create mode 100644 tests/Elastic.CommonSchema.NLog.Tests/ApmTests.cs create mode 100644 tests/Elastic.CommonSchema.NLog.Tests/Elastic.CommonSchema.NLog.Tests.csproj create mode 100644 tests/Elastic.CommonSchema.NLog.Tests/LogTestsBase.cs create mode 100644 tests/Elastic.CommonSchema.NLog.Tests/MessageTests.cs create mode 100644 tests/Elastic.CommonSchema.NLog.Tests/OutputTests.cs diff --git a/README.md b/README.md index fb25cb28..d943bac8 100644 --- a/README.md +++ b/README.md @@ -14,11 +14,12 @@ Official NuGet packages can be referenced from [NuGet.org](https://www.nuget.org | Package Name | Purpose | Download | | ----------------------- | ---------------- | -----------------| -| `Elastic.CommonSchema` | Foundational project that contains a full C# representation of ECS, used by the other integrations listed. | [![NuGet Release][ElasticCommonSchema-image]][ElasticCommonSchema-nuget-url] | -| `Elastic.CommonSchema.Serilog` | Formats a Serilog log message into a JSON representation that can be indexed into Elasticsearch. | [![NuGet Release][ElasticCommonSchemaSerilog-image]][ElasticCommonSchemaSerilog-nuget-url] | -| `Elastic.Apm.SerilogEnricher` | Adds transaction id and trace id to every Serilog log message that is created during a transaction. This works in conjunction with the Elastic.CommonSchema.Serilog package and forms a solution to distributed tracing with Serilog. | [![NuGet Release][ElasticApmSerilogEnricher-image]][ElasticApmSerilogEnricher-nuget-url] | -| `Elastic.Apm.NLog` | Introduces two special placeholder variables (ElasticApmTraceId and ElasticApmTransactionId) for use within your NLog templates. | [![NuGet Release][ElasticApmNLog-image]][ElasticApmNLog-nuget-url] | -| `Elastic.CommonSchema.BenchmarkDotNetExporter` | An exporter for BenchmarkDotnet that can index benchmarking results directly into Elasticsearch, which can be helpful for detecting code-related performance problems over time. | [![NuGet Release][ElasticBenchmarkDotNetExporter-image]][ElasticBenchmarkDotNetExporter-nuget-url] | +| `Elastic.CommonSchema` | Foundational project that contains a full C# representation of ECS, used by the other integrations listed. | [![NuGet Release][ElasticCommonSchema-image]][ElasticCommonSchema-nuget-url] | +| `Elastic.CommonSchema.Serilog` | Formats a Serilog log message into a JSON representation that can be indexed into Elasticsearch. | [![NuGet Release][ElasticCommonSchemaSerilog-image]][ElasticCommonSchemaSerilog-nuget-url] | +| `Elastic.CommonSchema.NLog` | Formats an NLog message into a JSON representation that can be indexed into Elasticsearch. | [![NuGet Release][ElasticCommonSchemaNLog-image]][ElasticCommonSchemaNLog-nuget-url] | +| `Elastic.Apm.SerilogEnricher` | Adds transaction id and trace id to every Serilog log message that is created during a transaction. This works in conjunction with the Elastic.CommonSchema.Serilog package and forms a solution to distributed tracing with Serilog. | [![NuGet Release][ElasticApmSerilogEnricher-image]][ElasticApmSerilogEnricher-nuget-url] | +| `Elastic.Apm.NLog` | Introduces two special placeholder variables (ElasticApmTraceId and ElasticApmTransactionId) for use within your NLog templates. | [![NuGet Release][ElasticApmNLog-image]][ElasticApmNLog-nuget-url] | +| `Elastic.CommonSchema.BenchmarkDotNetExporter` | An exporter for BenchmarkDotnet that can index benchmarking results directly into Elasticsearch, which can be helpful for detecting code-related performance problems over time. | [![NuGet Release][ElasticBenchmarkDotNetExporter-image]][ElasticBenchmarkDotNetExporter-nuget-url] | [ElasticCommonSchema-nuget-url]:https://www.nuget.org/packages/Elastic.CommonSchema/ [ElasticCommonSchema-image]:https://img.shields.io/nuget/v/Elastic.CommonSchema.svg @@ -26,6 +27,9 @@ Official NuGet packages can be referenced from [NuGet.org](https://www.nuget.org [ElasticCommonSchemaSerilog-nuget-url]:https://www.nuget.org/packages/Elastic.CommonSchema.Serilog/ [ElasticCommonSchemaSerilog-image]:https://img.shields.io/nuget/v/Elastic.CommonSchema.Serilog.svg +[ElasticCommonSchemaNLog-nuget-url]:https://www.nuget.org/packages/Elastic.CommonSchema.NLog/ +[ElasticCommonSchemaNLog-image]:https://img.shields.io/nuget/v/Elastic.CommonSchema.NLog.svg + [ElasticApmSerilogEnricher-nuget-url]:https://www.nuget.org/packages/Elastic.Apm.SerilogEnricher/ [ElasticApmSerilogEnricher-image]:https://img.shields.io/nuget/v/Elastic.Apm.SerilogEnricher.svg @@ -53,6 +57,19 @@ var logger = new LoggerConfiguration() .CreateLogger(); ``` +### [Elastic.CommonSchema.NLog](https://github.com/elastic/ecs-dotnet/tree/master/src/Elastic.CommonSchema.NLog) + +Formats an NLog event into a JSON representation that adheres to the Elastic Common Schema. [Learn more...](https://github.com/elastic/ecs-dotnet/tree/master/src/Elastic.CommonSchema.NLog) + +```csharp +Layout.Register("EcsLayout"); // Register the ECS layout. +var config = new Config.LoggingConfiguration(); +var memoryTarget = new EventInfoMemoryTarget { Layout = Layout.FromString("EcsLayout") }; // Use the layout. +config.AddRule(LogLevel.Debug, LogLevel.Fatal, memoryTarget); +var factory = new LogFactory(config); +var logger = factory.GetCurrentClassLogger(); +``` + ## APM ### [Elastic.Apm.SerilogEnricher](https://github.com/elastic/ecs-dotnet/tree/master/src/Elastic.Apm.SerilogEnricher) diff --git a/src/Elastic.Apm.NLog/ApmTraceIdLayoutRenderer.cs b/src/Elastic.Apm.NLog/ApmTraceIdLayoutRenderer.cs index 4cc6490d..1737efb6 100644 --- a/src/Elastic.Apm.NLog/ApmTraceIdLayoutRenderer.cs +++ b/src/Elastic.Apm.NLog/ApmTraceIdLayoutRenderer.cs @@ -9,14 +9,16 @@ namespace Elastic.Apm.NLog { - [LayoutRenderer("ElasticApmTraceId")] + [LayoutRenderer(Name)] [ThreadSafe] public class ApmTraceIdLayoutRenderer : LayoutRenderer { + public const string Name = "ElasticApmTraceId"; + protected override void Append(StringBuilder builder, LogEventInfo logEvent) { - if (!Agent.IsConfigured) return; - if (Agent.Tracer.CurrentTransaction == null) return; + if (!Agent.IsConfigured || Agent.Tracer?.CurrentTransaction == null) + return; builder.Append(Agent.Tracer.CurrentTransaction.TraceId); } diff --git a/src/Elastic.Apm.NLog/ApmTransactionIdLayoutRenderer.cs b/src/Elastic.Apm.NLog/ApmTransactionIdLayoutRenderer.cs index 95601c08..64504f82 100644 --- a/src/Elastic.Apm.NLog/ApmTransactionIdLayoutRenderer.cs +++ b/src/Elastic.Apm.NLog/ApmTransactionIdLayoutRenderer.cs @@ -9,14 +9,16 @@ namespace Elastic.Apm.NLog { - [LayoutRenderer("ElasticApmTransactionId")] + [LayoutRenderer(Name)] [ThreadSafe] public class ApmTransactionIdLayoutRenderer : LayoutRenderer { + public const string Name = "ElasticApmTransactionId"; + protected override void Append(StringBuilder builder, LogEventInfo logEvent) { - if (!Agent.IsConfigured) return; - if (Agent.Tracer.CurrentTransaction == null) return; + if (!Agent.IsConfigured || Agent.Tracer?.CurrentTransaction == null) + return; builder.Append(Agent.Tracer.CurrentTransaction.Id); } diff --git a/src/Elastic.Apm.SerilogEnricher/ElasticApmEnricher.cs b/src/Elastic.Apm.SerilogEnricher/ElasticApmEnricher.cs index 3092bcbd..164248bd 100644 --- a/src/Elastic.Apm.SerilogEnricher/ElasticApmEnricher.cs +++ b/src/Elastic.Apm.SerilogEnricher/ElasticApmEnricher.cs @@ -15,8 +15,8 @@ public sealed class ElasticApmEnricher : ILogEventEnricher { public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) { - if (!Agent.IsConfigured) return; - if (Agent.Tracer.CurrentTransaction == null) return; + if (!Agent.IsConfigured || Agent.Tracer.CurrentTransaction == null) + return; logEvent.AddPropertyIfAbsent(propertyFactory.CreateProperty( "ElasticApmTransactionId", Agent.Tracer.CurrentTransaction.Id)); diff --git a/src/Elastic.Apm.SerilogEnricher/ElasticApmEnricherExtension.cs b/src/Elastic.Apm.SerilogEnricher/ElasticApmEnricherExtension.cs index 0877d3ae..0f2dfc5d 100644 --- a/src/Elastic.Apm.SerilogEnricher/ElasticApmEnricherExtension.cs +++ b/src/Elastic.Apm.SerilogEnricher/ElasticApmEnricherExtension.cs @@ -17,11 +17,10 @@ public static class ElasticApmEnricherExtension /// Logger enrichment configuration. /// Configuration object allowing method chaining. /// If is null. - public static LoggerConfiguration WithElasticApmCorrelationInfo( - this LoggerEnrichmentConfiguration enrichmentConfiguration - ) + public static LoggerConfiguration WithElasticApmCorrelationInfo(this LoggerEnrichmentConfiguration enrichmentConfiguration) { - if (enrichmentConfiguration == null) throw new ArgumentNullException(nameof(enrichmentConfiguration)); + if (enrichmentConfiguration == null) + throw new ArgumentNullException(nameof(enrichmentConfiguration)); return enrichmentConfiguration.With(); } diff --git a/src/Elastic.CommonSchema.NLog/EcsLayout.cs b/src/Elastic.CommonSchema.NLog/EcsLayout.cs new file mode 100644 index 00000000..8e4d8496 --- /dev/null +++ b/src/Elastic.CommonSchema.NLog/EcsLayout.cs @@ -0,0 +1,434 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information + +using System; +using System.Collections.Generic; +using System.Diagnostics; +using System.IO; +using System.Text; +using NLog; +using NLog.Config; +using NLog.Layouts; +using NLog.Targets; + +namespace Elastic.CommonSchema.NLog +{ + [Layout(Name)] + [ThreadSafe] + [ThreadAgnostic] + public class EcsLayout : Layout + { + public const string Name = nameof(EcsLayout); + + private readonly Layout _disableThreadAgnostic = "${threadid:cached=true}"; + + public EcsLayout() + { + IncludeAllProperties = true; + + ProcessId = "${processid}"; + ProcessName = "${processname:FullName=false}"; + ProcessExecutable = "${processname:FullName=true}"; + ProcessTitle = "${processinfo:MainWindowTitle}"; + ProcessThreadId = "${threadid}"; + + HostName = "${machinename}"; + HostIp = "${local-ip:cachedSeconds=60}"; // NLog 4.6.8 + + ServerUser = "${environment-user}"; // NLog 4.6.4 + + // These values are set by the Elastic.Apm.NLog package + ApmTraceId = "${ElasticApmTraceId}"; + ApmTransactionId = "${ElasticApmTransactionId}"; + } + + private static class SpecialKeys + { + public const string DefaultLogger = "Elastic.CommonSchema.NLog"; + } + + public Layout AgentId { get; set; } + public Layout AgentName { get; set; } + public Layout AgentType { get; set; } + public Layout AgentVersion { get; set; } + + public Layout ApmTraceId { get; set; } + public Layout ApmTransactionId { get; set; } + + /// + /// Allow dynamically disabling to + /// ensure correct async context capture when necessary + /// + public Layout DisableThreadAgnostic => IncludeMdlc ? _disableThreadAgnostic : null; + + public Layout EventAction { get; set; } + public Layout EventCategory { get; set; } + public Layout EventId { get; set; } + public Layout EventKind { get; set; } + public Layout EventSeverity { get; set; } + + public Layout HostId { get; set; } + public Layout HostIp { get; set; } + public Layout HostName { get; set; } + + public bool IncludeAllProperties { get; set; } + + public bool IncludeMdlc { get; set; } + + [ArrayParameter(typeof(TargetPropertyWithContext), "label")] + public IList Labels { get; } = new List(); + + [ArrayParameter(typeof(TargetPropertyWithContext), "metadata")] + public IList Metadata { get; } = new List(); + + public Layout ProcessExecutable { get; set; } + public Layout ProcessId { get; set; } + public Layout ProcessName { get; set; } + public Layout ProcessThreadId { get; set; } + public Layout ProcessTitle { get; set; } + + public Layout ServerAddress { get; set; } + public Layout ServerIp { get; set; } + public Layout ServerUser { get; set; } + + [ArrayParameter(typeof(TargetPropertyWithContext), "tag")] + public IList Tags { get; } = new List(); + + protected override void RenderFormattedMessage(LogEventInfo logEventInfo, StringBuilder target) + { + var ecsEvent = new Base + { + Timestamp = logEventInfo.TimeStamp, + Message = logEventInfo.FormattedMessage, + Ecs = new Ecs { Version = Base.Version }, + Log = GetLog(logEventInfo), + Event = GetEvent(logEventInfo), + Metadata = GetMetadata(logEventInfo), + Process = GetProcess(logEventInfo), + Trace = GetTrace(logEventInfo), + Transaction = GetTransaction(logEventInfo), + Error = GetError(logEventInfo.Exception), + Tags = GetTags(logEventInfo), + Labels = GetLabels(logEventInfo), + Agent = GetAgent(logEventInfo), + Server = GetServer(logEventInfo), + Host = GetHost(logEventInfo) + }; + + var output = ecsEvent.Serialize(); + target.Append(output); + } + + protected override string GetFormattedMessage(LogEventInfo logEvent) + { + var sb = new StringBuilder(); + RenderFormattedMessage(logEvent, sb); + return sb.ToString(); + } + + private static Error GetError(Exception exception) => + exception != null + ? new Error + { + Message = exception.Message, + StackTrace = CatchError(exception), + Code = exception.GetType().ToString() + } + : null; + + private static string CatchError(Exception error) + { + if (error == null) + return string.Empty; + + var i = 1; + var fullText = new StringWriter(); + var frame = new StackTrace(error, true).GetFrame(0); + + fullText.WriteLine($"Exception {i++:D2} ==================================="); + fullText.WriteLine($"Type: {error.GetType()}"); + fullText.WriteLine($"Source: {error.TargetSite?.DeclaringType?.AssemblyQualifiedName}"); + fullText.WriteLine($"Message: {error.Message}"); + fullText.WriteLine($"Trace: {error.StackTrace}"); + fullText.WriteLine($"Location: {frame.GetFileName()}"); + fullText.WriteLine($"Method: {frame.GetMethod()} ({frame.GetFileLineNumber()}, {frame.GetFileColumnNumber()})"); + + var exception = error.InnerException; + while (exception != null) + { + frame = new StackTrace(exception, true).GetFrame(0); + fullText.WriteLine($"\tException {i++:D2} inner --------------------------"); + fullText.WriteLine($"\tType: {exception.GetType()}"); + fullText.WriteLine($"\tSource: {exception.TargetSite?.DeclaringType?.AssemblyQualifiedName}"); + fullText.WriteLine($"\tMessage: {exception.Message}"); + fullText.WriteLine($"\tLocation: {frame.GetFileName()}"); + fullText.WriteLine($"\tMethod: {frame.GetMethod()} ({frame.GetFileLineNumber()}, {frame.GetFileColumnNumber()})"); + + exception = exception.InnerException; + } + + return fullText.ToString(); + } + + private IDictionary GetMetadata(LogEventInfo e) + { + if ((!IncludeAllProperties || !e.HasProperties) && Metadata?.Count == 0 && !IncludeMdlc) + return null; + + var metadata = new Dictionary(); + + if (IncludeAllProperties && e.HasProperties) + { + foreach (var prop in e.Properties) + Populate(metadata, prop.Key?.ToString(), prop.Value); + } + + if (IncludeMdlc) + { + foreach (var key in MappedDiagnosticsLogicalContext.GetNames()) + { + if (string.IsNullOrEmpty(key)) + continue; + + var propertyValue = MappedDiagnosticsLogicalContext.GetObject(key); + Populate(metadata, key, propertyValue); + } + } + + if (Metadata?.Count > 0) + { + foreach (var targetPropertyWithContext in Metadata) + { + var value = targetPropertyWithContext.Layout?.Render(e); + if (!string.IsNullOrEmpty(value) || targetPropertyWithContext.IncludeEmptyValue) + Populate(metadata, targetPropertyWithContext.Name, value); + } + } + + return metadata.Count > 0 + ? metadata + : null; + } + + private static Log GetLog(LogEventInfo logEventInfo) + { + var log = new Log + { + Level = logEventInfo.Level.ToString(), + Logger = SpecialKeys.DefaultLogger, + Original = logEventInfo.Message + }; + + return log; + } + + private string[] GetTags(LogEventInfo e) + { + if (Tags?.Count == 0) + return null; + + if (Tags.Count == 1) + { + var tag = Tags[0].Layout.Render(e); + return GetTagsSplit(tag); + } + + var tags = new List(Tags.Count); + foreach (var targetPropertyWithContext in Tags) + { + var tag = targetPropertyWithContext.Layout.Render(e); + tags.AddRange(GetTagsSplit(tag)); + } + return tags.ToArray(); + } + + private static string[] GetTagsSplit(string tags) => + string.IsNullOrEmpty(tags) + ? Array.Empty() + : tags.Split(new[] { ';', ',', ' ', '\t', '\n' }, StringSplitOptions.RemoveEmptyEntries); + + private IDictionary GetLabels(LogEventInfo e) + { + if (Labels?.Count == 0) + return null; + + var labels = new Dictionary(); + for (var i = 0; i < Labels?.Count; ++i) + { + var value = Labels[i].Layout?.Render(e); + if (!string.IsNullOrEmpty(value) || Labels[i].IncludeEmptyValue) + Populate(labels, Labels[i].Name, value); + } + return labels.Count > 0 + ? labels + : null; + } + + private Event GetEvent(LogEventInfo logEventInfo) + { + var eventCategory = EventCategory?.Render(logEventInfo); + var eventSeverity = EventSeverity?.Render(logEventInfo); + + var evnt = new Event + { + Created = logEventInfo.TimeStamp, + Category = !string.IsNullOrEmpty(eventCategory) ? new[] { eventCategory } : null, + Action = EventAction?.Render(logEventInfo), + Id = EventId?.Render(logEventInfo), + Kind = EventKind?.Render(logEventInfo), + Severity = !string.IsNullOrEmpty(eventSeverity) + ? long.Parse(eventSeverity) + : GetSysLogSeverity(logEventInfo.Level), + Timezone = TimeZoneInfo.Local.StandardName + }; + + return evnt; + } + + private Agent GetAgent(LogEventInfo logEventInfo) + { + var agentId = AgentId?.Render(logEventInfo); + var agentName = AgentName?.Render(logEventInfo); + var agentType = AgentType?.Render(logEventInfo); + var agentVersion = AgentVersion?.Render(logEventInfo); + + if (string.IsNullOrEmpty(agentId) + && string.IsNullOrEmpty(agentName) + && string.IsNullOrEmpty(agentType) + && string.IsNullOrEmpty(agentVersion)) + return null; + + var agent = new Agent + { + Id = agentId, + Name = agentName, + Type = agentType, + Version = agentVersion + }; + + return agent; + } + + private Process GetProcess(LogEventInfo logEventInfo) + { + var processId = ProcessId?.Render(logEventInfo); + var processName = ProcessName?.Render(logEventInfo); + var processTitle = ProcessTitle?.Render(logEventInfo); + var processExecutable = ProcessExecutable?.Render(logEventInfo); + var processThreadId = ProcessThreadId?.Render(logEventInfo); + + if (string.IsNullOrEmpty(processId) + && string.IsNullOrEmpty(processName) + && string.IsNullOrEmpty(processTitle) + && string.IsNullOrEmpty(processExecutable) + && string.IsNullOrEmpty(processThreadId)) + return null; + + return new Process + { + Title = processTitle, + Name = processName, + Pid = !string.IsNullOrEmpty(processId) ? long.Parse(processId) : 0, + Executable = processExecutable, + Thread = !string.IsNullOrEmpty(processId) ? new ProcessThread { Id = long.Parse(processId) } : null + }; + } + + private Server GetServer(LogEventInfo logEventInfo) + { + var serverUser = ServerUser?.Render(logEventInfo); + var serverAddress = ServerAddress?.Render(logEventInfo); + var serverIp = ServerIp?.Render(logEventInfo); + if (string.IsNullOrEmpty(serverUser) && string.IsNullOrEmpty(serverAddress) && string.IsNullOrEmpty(serverIp)) + return null; + + return new Server + { + User = !string.IsNullOrEmpty(serverUser) + ? new User { Name = serverUser } + : null, + Address = serverAddress, + Ip = serverIp + }; + } + + private Trace GetTrace(LogEventInfo logEventInfo) + { + var traceId = ApmTraceId?.Render(logEventInfo); + if (string.IsNullOrEmpty(traceId)) + return null; + + return new Trace + { + Id = traceId + }; + } + + private Transaction GetTransaction(LogEventInfo logEventInfo) + { + var transactionId = ApmTransactionId?.Render(logEventInfo); + if (string.IsNullOrEmpty(transactionId)) + return null; + + return new Transaction + { + Id = transactionId + }; + } + + private Host GetHost(LogEventInfo logEventInfo) + { + var hostId = HostId?.Render(logEventInfo); + var hostName = HostName?.Render(logEventInfo); + var hostIp = HostIp?.Render(logEventInfo); + + if (string.IsNullOrEmpty(hostId) + && string.IsNullOrEmpty(hostName) + && string.IsNullOrEmpty(hostIp)) + return null; + + var host = new Host + { + Id = hostId, + Name = hostName, + Ip = string.IsNullOrEmpty(hostIp) ? null : new[] { hostIp } + }; + + return host; + } + + private static long GetSysLogSeverity(LogLevel logLevel) + { + if (logLevel == LogLevel.Trace || logLevel == LogLevel.Debug) + return 7; + + if (logLevel == LogLevel.Info) + return 6; + + if (logLevel == LogLevel.Warn) + return 4; + + if (logLevel == LogLevel.Error) + return 3; + + return 2; // LogLevel.Fatal + } + + private static void Populate(IDictionary propertyBag, string key, object value) + { + if (string.IsNullOrEmpty(key)) + return; + + while (propertyBag.ContainsKey(key)) + { + if (string.Equals(value.ToString(), propertyBag[key].ToString(), StringComparison.Ordinal)) + return; + + key += "_1"; + } + + propertyBag.Add(key, value); + } + } +} diff --git a/src/Elastic.CommonSchema.NLog/Elastic.CommonSchema.NLog.csproj b/src/Elastic.CommonSchema.NLog/Elastic.CommonSchema.NLog.csproj new file mode 100644 index 00000000..f3ecc662 --- /dev/null +++ b/src/Elastic.CommonSchema.NLog/Elastic.CommonSchema.NLog.csproj @@ -0,0 +1,17 @@ + + + + + netstandard2.0;netstandard2.1;net461 + Elastic Common Schema (ECS) NLog Layout + NLog Layout that formats log events in accordance with Elastic Common Schema (ECS). + + + + + + + + + + diff --git a/src/Elastic.CommonSchema.NLog/README.md b/src/Elastic.CommonSchema.NLog/README.md new file mode 100644 index 00000000..8ab9678d --- /dev/null +++ b/src/Elastic.CommonSchema.NLog/README.md @@ -0,0 +1,66 @@ +# Elastic Common Schema NLog Layout + +This Layout implementation formats an NLog event into a JSON representation that adheres to the Elastic Common Schema specification. + +## Packages + +The .NET assemblies are published to NuGet under the package name [Elastic.CommonSchema.NLog](http://nuget.org/packages/Elastic.CommonSchema.NLog) + +## How to Enable + +```csharp +Layout.Register("EcsLayout"); // Register the ECS layout. +var config = new Config.LoggingConfiguration(); +var memoryTarget = new EventInfoMemoryTarget { Layout = Layout.FromString("EcsLayout") }; // Use the layout. +config.AddRule(LogLevel.Debug, LogLevel.Fatal, memoryTarget); +var factory = new LogFactory(config); +var logger = factory.GetCurrentClassLogger(); +``` + +In the code snippet above `Layout.Register("EcsLayout")` registers the `EcsLayout` with NLog. +The `Layout = Layout.FromString("EcsLayout")` line then instructs NLog to use the registered layout. +The sample above uses the memory target, but you are free to use any target of your choice, perhaps consider using a +filesystem target and [Elastic Filebeat](https://www.elastic.co/downloads/beats/filebeat) for durable and reliable ingestion. + +An example of the output is given below: + +```json +{ + "@timestamp":"2020-02-20T16:07:06.7109766+11:00", + "log.level":"Info", + "message":"Info \"X\" 2.2", + "_metadata":{ + "value_x":"X", + "some_y":2.2 + }, + "ecs":{ + "version":"1.4.0" + }, + "event":{ + "severity":6, + "timezone":"AUS Eastern Standard Time", + "created":"2020-02-20T16:07:06.7109766+11:00" + }, + "host":{ + "name":"LAPTOP" + }, + "log":{ + "logger":"Elastic.CommonSchema.NLog", + "original":"Info {ValueX} {SomeY}" + }, + "process":{ + "thread":{ + "id":17592 + }, + "pid":17592, + "name":"dotnet", + "executable":"C:\\Program Files\\dotnet\\dotnet.exe" + } +} +``` + +## Copyright and License + +This software is Copyright (c) 2014-2020 by Elasticsearch BV. + +This is free software, licensed under: [The Apache License Version 2.0](https://github.com/elastic/ecs-dotnet/blob/master/license.txt). diff --git a/src/Elastic.CommonSchema.Serilog/LogEventConverter.cs b/src/Elastic.CommonSchema.Serilog/LogEventConverter.cs index de0e512e..7ff68615 100644 --- a/src/Elastic.CommonSchema.Serilog/LogEventConverter.cs +++ b/src/Elastic.CommonSchema.Serilog/LogEventConverter.cs @@ -21,7 +21,7 @@ namespace Elastic.CommonSchema.Serilog /// /// Elastic Common Schema converter for LogEvent /// - public class LogEventConverter + public static class LogEventConverter { private static class SpecialKeys { @@ -57,6 +57,7 @@ public static Base ConvertToEcs(LogEvent logEvent, IEcsTextFormatterConfiguratio var ecsEvent = new Base { Timestamp = logEvent.Timestamp, + Message = logEvent.RenderMessage(), Ecs = new Ecs { Version = Base.Version }, Log = GetLog(logEvent, exceptions, configuration), Agent = GetAgent(logEvent), @@ -84,8 +85,6 @@ public static Base ConvertToEcs(LogEvent logEvent, IEcsTextFormatterConfiguratio if (configuration.MapCustom != null) ecsEvent = configuration.MapCustom(ecsEvent, logEvent); - ecsEvent.Message = logEvent.RenderMessage(); - return ecsEvent; } @@ -350,7 +349,7 @@ private static string CatchErrors(IReadOnlyCollection errors) while (exception != null) { frame = new StackTrace(exception, true).GetFrame(0); - fullText.WriteLine($"\tException {i:D2} inner --------------------------"); + fullText.WriteLine($"\tException {i++:D2} inner --------------------------"); fullText.WriteLine($"\tType: {exception.GetType()}"); fullText.WriteLine($"\tSource: {exception.TargetSite?.DeclaringType?.AssemblyQualifiedName}"); fullText.WriteLine($"\tMessage: {exception.Message}"); diff --git a/src/Generator/CodeConfiguration.cs b/src/Generator/CodeConfiguration.cs index 822aac84..95021e31 100644 --- a/src/Generator/CodeConfiguration.cs +++ b/src/Generator/CodeConfiguration.cs @@ -12,6 +12,8 @@ public static class CodeConfiguration public static string ElasticCommonSchemaGeneratedFolder { get; } = $@"{Root}Elastic.CommonSchema/"; public static string ElasticCommonSchemaNESTGeneratedFolder { get; } = $@"{Root}Elastic.CommonSchemaNEST/"; + public static string ElasticNLogGeneratedFolder { get; } = $@"{Root}Elastic.CommonSchema.NLog/"; + private static string Root { get diff --git a/src/Generator/NLogHelper.cs b/src/Generator/NLogHelper.cs new file mode 100644 index 00000000..dbd96c42 --- /dev/null +++ b/src/Generator/NLogHelper.cs @@ -0,0 +1,35 @@ +using System.Text; +using Generator.Schema; + +namespace Generator +{ + public static class NLogHelper + { + public static bool Encode(this Field field) + { + switch (field.ObjectType) + { + case FieldType.Boolean: + case FieldType.Float: + case FieldType.Integer: + case FieldType.Long: + return false; + default: + return true; + } + } + + public static string GetMapping(Field field) + { + switch (field.FlatName) + { + case "@timestamp": return "${date}"; + case "log.level": return "${level}"; + case "labels": return ""; + case "message": return "${message}"; + case "ecs.version": return field.Schema.FullVersion; + default: return string.Empty; + } + } + } +} diff --git a/src/Generator/Schema/EcsSpecification.cs b/src/Generator/Schema/EcsSpecification.cs index 0dbb2758..312490cb 100644 --- a/src/Generator/Schema/EcsSpecification.cs +++ b/src/Generator/Schema/EcsSpecification.cs @@ -43,11 +43,11 @@ public IEnumerable> BaseFieldsOrdered list.Add(Tuple.Create("WriteTimestamp", baseRootObject.Fields.Single(f => f.Key == "@timestamp").Value)); // HACK in the log.level - list.Add(Tuple.Create("WriteLogLevel", new Field { Name = "log.level", Schema = baseRootObject })); + list.Add(Tuple.Create("WriteLogLevel", new Field { Name = "log.level", Schema = baseRootObject, FlatName = "log.level" })); list.Add(Tuple.Create("WriteMessage", baseRootObject.Fields.Single(f => f.Key == "message").Value)); // HACK in _metadata - list.Add(Tuple.Create("WriteProp", new Field { Name = "_metadata", Schema = baseRootObject })); + list.Add(Tuple.Create("WriteProp", new Field { Name = "_metadata", Schema = baseRootObject, FlatName = "_metadata" })); list.AddRange(baseRootObject.GetFieldsFlat().Where(f => f.Name != "@timestamp" && f.Name != "message") .Select(f => Tuple.Create("WriteProp", f))); return list; diff --git a/src/ecs-dotnet.sln b/src/ecs-dotnet.sln index 089bcffa..b7521c9f 100644 --- a/src/ecs-dotnet.sln +++ b/src/ecs-dotnet.sln @@ -55,6 +55,10 @@ Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "Elastic.CommonSchema.Benchm EndProject Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "Elastic.CommonSchema.BenchmarkDotNetExporter.IntegrationTests", "..\tests\Elastic.CommonSchema.BenchmarkDotNetExporter.IntegrationTests\Elastic.CommonSchema.BenchmarkDotNetExporter.IntegrationTests.csproj", "{4138E98A-4714-4139-BD89-D9FF4F2A3A73}" EndProject +Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "Elastic.CommonSchema.NLog", "Elastic.CommonSchema.NLog\Elastic.CommonSchema.NLog.csproj", "{0881CC2E-BFBB-40DB-BA5B-B3D23A985F73}" +EndProject +Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "Elastic.CommonSchema.NLog.Tests", "..\tests\Elastic.CommonSchema.NLog.Tests\Elastic.CommonSchema.NLog.Tests.csproj", "{89ADA999-1A1D-4B51-8CEE-39A553F669D1}" +EndProject Global GlobalSection(SolutionConfigurationPlatforms) = preSolution Debug|Any CPU = Debug|Any CPU @@ -119,6 +123,14 @@ Global {4138E98A-4714-4139-BD89-D9FF4F2A3A73}.Debug|Any CPU.Build.0 = Debug|Any CPU {4138E98A-4714-4139-BD89-D9FF4F2A3A73}.Release|Any CPU.ActiveCfg = Release|Any CPU {4138E98A-4714-4139-BD89-D9FF4F2A3A73}.Release|Any CPU.Build.0 = Release|Any CPU + {0881CC2E-BFBB-40DB-BA5B-B3D23A985F73}.Debug|Any CPU.ActiveCfg = Debug|Any CPU + {0881CC2E-BFBB-40DB-BA5B-B3D23A985F73}.Debug|Any CPU.Build.0 = Debug|Any CPU + {0881CC2E-BFBB-40DB-BA5B-B3D23A985F73}.Release|Any CPU.ActiveCfg = Release|Any CPU + {0881CC2E-BFBB-40DB-BA5B-B3D23A985F73}.Release|Any CPU.Build.0 = Release|Any CPU + {89ADA999-1A1D-4B51-8CEE-39A553F669D1}.Debug|Any CPU.ActiveCfg = Debug|Any CPU + {89ADA999-1A1D-4B51-8CEE-39A553F669D1}.Debug|Any CPU.Build.0 = Debug|Any CPU + {89ADA999-1A1D-4B51-8CEE-39A553F669D1}.Release|Any CPU.ActiveCfg = Release|Any CPU + {89ADA999-1A1D-4B51-8CEE-39A553F669D1}.Release|Any CPU.Build.0 = Release|Any CPU EndGlobalSection GlobalSection(NestedProjects) = preSolution {A1DEDE4E-0876-41E8-8DF0-8F85EAF3FAFA} = {7610B796-BB3E-4CB2-8296-79BBFF6D23FC} @@ -136,5 +148,7 @@ Global {EE4EA2DE-411D-400C-9BF6-8F6AFC17697C} = {3582B07D-C2B0-49CC-B676-EAF806EB010E} {6BE3084A-D84D-4782-9915-6E41575712C7} = {7610B796-BB3E-4CB2-8296-79BBFF6D23FC} {4138E98A-4714-4139-BD89-D9FF4F2A3A73} = {3582B07D-C2B0-49CC-B676-EAF806EB010E} + {0881CC2E-BFBB-40DB-BA5B-B3D23A985F73} = {7610B796-BB3E-4CB2-8296-79BBFF6D23FC} + {89ADA999-1A1D-4B51-8CEE-39A553F669D1} = {3582B07D-C2B0-49CC-B676-EAF806EB010E} EndGlobalSection EndGlobal diff --git a/tests/Elastic.Apm.NLog.Test/Elastic.Apm.NLog.Test.csproj b/tests/Elastic.Apm.NLog.Test/Elastic.Apm.NLog.Test.csproj index c4401e2f..5564d8b6 100644 --- a/tests/Elastic.Apm.NLog.Test/Elastic.Apm.NLog.Test.csproj +++ b/tests/Elastic.Apm.NLog.Test/Elastic.Apm.NLog.Test.csproj @@ -20,6 +20,7 @@ + diff --git a/tests/Elastic.Apm.NLog.Test/NLogTests.cs b/tests/Elastic.Apm.NLog.Test/NLogTests.cs index e2e6cf75..4f36f6f9 100644 --- a/tests/Elastic.Apm.NLog.Test/NLogTests.cs +++ b/tests/Elastic.Apm.NLog.Test/NLogTests.cs @@ -2,11 +2,15 @@ // Elasticsearch B.V licenses this file to you under the Apache 2.0 License. // See the LICENSE file in the project root for more information +using System.Collections.Generic; using Elastic.Apm.Test.Common; +using Elastic.CommonSchema.NLog; using FluentAssertions; using NLog; +using NLog.Layouts; using NLog.Targets; using Xunit; +using Config=NLog.Config; namespace Elastic.Apm.NLog.Test { diff --git a/tests/Elastic.CommonSchema.NLog.Tests/ApmTests.cs b/tests/Elastic.CommonSchema.NLog.Tests/ApmTests.cs new file mode 100644 index 00000000..42278961 --- /dev/null +++ b/tests/Elastic.CommonSchema.NLog.Tests/ApmTests.cs @@ -0,0 +1,44 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information + +using System.Diagnostics; +using System.Linq; +using Elastic.Apm; +using FluentAssertions; +using Xunit; + +namespace Elastic.CommonSchema.NLog.Tests +{ + public class ApmTests : LogTestsBase + { + [Fact] + public void ElasticApmEndUpOnEcsLog() => TestLogger((logger, getLogEvents) => + { + if (!Apm.Agent.IsConfigured) + Apm.Agent.Setup(new AgentComponents()); + + string traceId = null; + string transactionId = null; + + // Start a new activity to make sure it does not override Tracing.Trace.Id + Activity.Current = new Activity("test").Start(); + + Apm.Agent.Tracer.CaptureTransaction("test", "test", (transaction) => + { + traceId = transaction.TraceId; + transactionId = transaction.Id; + logger.Info("My log message!"); + + var logEvents = getLogEvents(); + logEvents.Should().HaveCount(1); + + var ecsEvents = ToEcsEvents(logEvents); + var (_, info) = ecsEvents.First(); + + info.Trace.Id.Should().Be(traceId); + info.Transaction.Id.Should().Be(transactionId); + }); + }); + } +} diff --git a/tests/Elastic.CommonSchema.NLog.Tests/Elastic.CommonSchema.NLog.Tests.csproj b/tests/Elastic.CommonSchema.NLog.Tests/Elastic.CommonSchema.NLog.Tests.csproj new file mode 100644 index 00000000..2f477c5e --- /dev/null +++ b/tests/Elastic.CommonSchema.NLog.Tests/Elastic.CommonSchema.NLog.Tests.csproj @@ -0,0 +1,26 @@ + + + + netcoreapp3.0 + + false + + + + + + + + + + + + + + + + + + + + diff --git a/tests/Elastic.CommonSchema.NLog.Tests/LogTestsBase.cs b/tests/Elastic.CommonSchema.NLog.Tests/LogTestsBase.cs new file mode 100644 index 00000000..aac369fd --- /dev/null +++ b/tests/Elastic.CommonSchema.NLog.Tests/LogTestsBase.cs @@ -0,0 +1,59 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information + +using System; +using System.Collections.Generic; +using System.Linq; +using System.Reflection; +using Elastic.Apm.NLog; +using NLog; +using NLog.LayoutRenderers; +using Config=NLog.Config; +using NLog.Layouts; +using NLog.Targets; + +namespace Elastic.CommonSchema.NLog.Tests +{ + public abstract class LogTestsBase + { + private class EventInfoMemoryTarget : TargetWithContext + { + public readonly IList Events = new List(); + protected override void Write(LogEventInfo logEvent) => Events.Add(logEvent); + } + + protected List ToFormattedStrings(List logEvents) => + logEvents + .Select(l => new EcsLayout().Render(l)) + .ToList(); + + protected List<(string Json, Base Base)> ToEcsEvents(List logEvents) => + ToFormattedStrings(logEvents) + .Select(s => (s, Base.Deserialize(s))) + .ToList(); + + protected static void TestLogger(Action>> act) + { + var configurationItemFactory = new Config.ConfigurationItemFactory(); + configurationItemFactory.RegisterItemsFromAssembly(Assembly.GetAssembly(typeof(EcsLayout))); + + // These layout renderers need to registered statically as ultimately ConfigurationItemFactory.Default is called in the call stack. + LayoutRenderer.Register(ApmTraceIdLayoutRenderer.Name); //generic + LayoutRenderer.Register(ApmTransactionIdLayoutRenderer.Name); //generic + + var layout = new SimpleLayout(EcsLayout.Name, configurationItemFactory); + + var memoryTarget = new EventInfoMemoryTarget { Layout = layout }; + + var loggingConfiguration = new Config.LoggingConfiguration(); + loggingConfiguration.AddRule(LogLevel.Trace, LogLevel.Fatal, memoryTarget); + + var factory = new LogFactory(loggingConfiguration); + + List GetLogEvents() => memoryTarget.Events.ToList(); + var logger = factory.GetCurrentClassLogger(); + act(logger, GetLogEvents); + } + } +} diff --git a/tests/Elastic.CommonSchema.NLog.Tests/MessageTests.cs b/tests/Elastic.CommonSchema.NLog.Tests/MessageTests.cs new file mode 100644 index 00000000..5ea4e791 --- /dev/null +++ b/tests/Elastic.CommonSchema.NLog.Tests/MessageTests.cs @@ -0,0 +1,49 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information + +using System.Linq; +using FluentAssertions; +using Xunit; + +namespace Elastic.CommonSchema.NLog.Tests +{ + public class MessageTests : LogTestsBase + { + [Fact] + public void SeesMessage() => TestLogger((logger, getLogEvents) => + { + logger.Info("My log message!"); + + var logEvents = getLogEvents(); + logEvents.Should().HaveCount(1); + + var ecsEvents = ToEcsEvents(logEvents); + + var (_, info) = ecsEvents.First(); + info.Message.Should().Be("My log message!"); + }); + + [Fact] + public void SeesMessageWithProp() => TestLogger((logger, getLogEvents) => + { + logger.Info("Info {ValueX} {SomeY}", "X", 2.2); + + var logEvents = getLogEvents(); + logEvents.Should().HaveCount(1); + + var ecsEvents = ToEcsEvents(logEvents); + + var (_, info) = ecsEvents.First(); + info.Message.Should().Be("Info \"X\" 2.2"); + info.Metadata.Should().ContainKey("value_x"); + info.Metadata.Should().ContainKey("some_y"); + + var x = info.Metadata["value_x"] as string; + x.Should().NotBeNull().And.Be("X"); + + var y = info.Metadata["some_y"] as double?; + y.Should().HaveValue().And.Be(2.2); + }); + } +} diff --git a/tests/Elastic.CommonSchema.NLog.Tests/OutputTests.cs b/tests/Elastic.CommonSchema.NLog.Tests/OutputTests.cs new file mode 100644 index 00000000..c2c314c6 --- /dev/null +++ b/tests/Elastic.CommonSchema.NLog.Tests/OutputTests.cs @@ -0,0 +1,38 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information + +using System; +using System.Linq; +using FluentAssertions; +using Xunit; +using Xunit.Abstractions; + +namespace Elastic.CommonSchema.NLog.Tests +{ + public class OutputTests : LogTestsBase + { + [Fact] + public void LogMultiple() => TestLogger((logger, getLogEvents) => + { + logger.Info("My log message!"); + logger.Info("Test output to NLog!"); + Action sketchy = () => throw new Exception("I threw up."); + var exception = Record.Exception(sketchy); + logger.Error(exception, "Here is an error."); + Assert.NotNull(exception); + + var logEvents = getLogEvents(); + logEvents.Should().HaveCount(3); + + var ecsEvents = ToEcsEvents(logEvents); + var (_, error) = ecsEvents.Last(); + error.Log.Level.Should().Be("Error"); + error.Error.Should().NotBeNull(); + + var (_, info) = ecsEvents.First(); + info.Log.Level.Should().Be("Info"); + info.Error.Should().BeNull(); + }); + } +} diff --git a/tests/Elastic.CommonSchema.Serilog.Tests/LogTestsBase.cs b/tests/Elastic.CommonSchema.Serilog.Tests/LogTestsBase.cs index 3563d151..c90b9b86 100644 --- a/tests/Elastic.CommonSchema.Serilog.Tests/LogTestsBase.cs +++ b/tests/Elastic.CommonSchema.Serilog.Tests/LogTestsBase.cs @@ -19,7 +19,7 @@ public abstract class LogTestsBase protected EcsTextFormatter Formatter { get; } = new EcsTextFormatter(); - public LogTestsBase(ITestOutputHelper output) => + protected LogTestsBase(ITestOutputHelper output) => LoggerConfiguration = new LoggerConfiguration() .MinimumLevel.Verbose() .WriteTo.Console(Formatter) @@ -37,7 +37,7 @@ protected void TestLogger(Action>> act) act(LoggerConfiguration.CreateLogger().ForContext(GetType()), GetLogEvents); } - protected List ToFormattedStrings(List logEvents) => + private List ToFormattedStrings(List logEvents) => logEvents .Select(l => {