Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Capture structured logging parameter names #125

Merged
merged 1 commit into from
Oct 12, 2017
Merged

Capture structured logging parameter names #125

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion src/NLog.Extensions.Logging/NLog.Extensions.Logging.csproj
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -56,7 +56,7 @@ For ASP.NET Core, use NLog.Web.AspNetCore: https://www.nuget.org/packages/NLog.W
</ItemGroup>
<ItemGroup Condition=" '$(TargetFramework)' == 'netstandard2.0' ">
<PackageReference Include="Microsoft.Extensions.Logging" Version="2.0.0" />
<PackageReference Include="NLog" Version="4.5.0-beta02" />
<PackageReference Include="NLog" Version="4.5.0-beta06" />
<PackageReference Include="System.AppContext" Version="4.3.0" />
</ItemGroup>
</Project>
63 changes: 60 additions & 3 deletions src/NLog.Extensions.Logging/NLogLogger.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
using System;
using System.Collections.Generic;
using Microsoft.Extensions.Logging;

namespace NLog.Extensions.Logging
Expand All @@ -11,6 +12,7 @@ internal class NLogLogger : Microsoft.Extensions.Logging.ILogger
private readonly Logger _logger;
private readonly NLogProviderOptions _options;

internal const string OriginalFormatPropertyName = "{OriginalFormat}";
private static readonly object EmptyEventId = default(EventId); // Cache boxing of empty EventId-struct
private static readonly object ZeroEventId = default(EventId).Id; // Cache boxing of zero EventId-Value
private Tuple<string, string, string> _eventIdPropertyNames;
Expand All @@ -35,8 +37,8 @@ public void Log<TState>(Microsoft.Extensions.Logging.LogLevel logLevel, EventId
}
var message = formatter(state, exception);

//message arguments are not needed as it is already checked that the loglevel is enabled.
var eventInfo = LogEventInfo.Create(nLogLogLevel, _logger.Name, message);
var messageTemplate = _options.EnableStructuredLogging ? state as IReadOnlyList<KeyValuePair<string, object>> : null;
LogEventInfo eventInfo = CreateLogEventInfo(nLogLogLevel, message, messageTemplate);
eventInfo.Exception = exception;
if (!_options.IgnoreEmptyEventId || eventId.Id != 0 || !string.IsNullOrEmpty(eventId.Name))
{
Expand All @@ -58,9 +60,64 @@ public void Log<TState>(Microsoft.Extensions.Logging.LogLevel logLevel, EventId
eventInfo.Properties[eventIdPropertyNames.Item3] = eventId.Name;
eventInfo.Properties["EventId"] = idIsZero && eventId.Name == null ? EmptyEventId : eventId;
}

_logger.Log(eventInfo);
}

private LogEventInfo CreateLogEventInfo(LogLevel nLogLogLevel, string message, IReadOnlyList<KeyValuePair<string, object>> parameterList)
{
if (parameterList != null && parameterList.Count > 1)
{
// More than a single parameter (last parameter is the {OriginalFormat})
var firstParameterName = parameterList[0].Key;
if (!string.IsNullOrEmpty(firstParameterName))
{
if (firstParameterName.Length != 1 || !char.IsDigit(firstParameterName[0]))
{
#if NETSTANDARD2_0
var originalFormat = parameterList[parameterList.Count - 1];
string originalMessage = null;
if (originalFormat.Key == OriginalFormatPropertyName)
{
// Attempt to capture original message with placeholders
originalMessage = originalFormat.Value as string;
}

var messageTemplateParameters = new NLogMessageParameterList(parameterList, originalMessage != null);
var eventInfo = new LogEventInfo(nLogLogLevel, _logger.Name, originalMessage ?? message, messageTemplateParameters);
if (originalMessage != null)
{
eventInfo.Parameters = new object[messageTemplateParameters.Count + 1];
for (int i = 0; i < messageTemplateParameters.Count; ++i)
eventInfo.Parameters[i] = messageTemplateParameters[i].Value;
eventInfo.Parameters[messageTemplateParameters.Count] = message;
eventInfo.MessageFormatter = (l) => (string)l.Parameters[l.Parameters.Length - 1];
}
return eventInfo;
#else
var eventInfo = LogEventInfo.Create(nLogLogLevel, _logger.Name, message);
for (int i = 0; i < parameterList.Count; ++i)
{
var parameter = parameterList[i];
if (string.IsNullOrEmpty(parameter.Key))
break; // Skip capture of invalid parameters

var parameterName = parameter.Key;
switch (parameterName[0])
{
case '@': parameterName = parameterName.Substring(1); break;
case '$': parameterName = parameterName.Substring(1); break;
}
eventInfo.Properties[parameterName] = parameter.Value;
}
return eventInfo;
#endif
}
}
}
return LogEventInfo.Create(nLogLogLevel, _logger.Name, message);
}

/// <summary>
/// Is logging enabled for this logger at this <paramref name="logLevel"/>?
/// </summary>
Expand Down Expand Up @@ -119,7 +176,7 @@ public IDisposable BeginScope<TState>(TState state)
{
throw new ArgumentNullException(nameof(state));
}

return NestedDiagnosticsLogicalContext.Push(state);
}
}
Expand Down
126 changes: 126 additions & 0 deletions src/NLog.Extensions.Logging/NLogMessageParameterList.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,126 @@
using System;
using System.Collections;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.Threading.Tasks;

namespace NLog.Extensions.Logging
{
#if NETSTANDARD2_0
/// <summary>
/// Converts Microsoft Extension Logging ParameterList into NLog MessageTemplate ParameterList
/// </summary>
internal class NLogMessageParameterList : IList<NLog.MessageTemplates.MessageTemplateParameter>
{
private IReadOnlyList<KeyValuePair<string, object>> _parameterList;

public NLogMessageParameterList(IReadOnlyList<KeyValuePair<string, object>> parameterList, bool includesOriginalMessage)
{
List<KeyValuePair<string, object>> validParameterList = includesOriginalMessage ? null : new List<KeyValuePair<string, object>>();
for (int i = 0; i < parameterList.Count; ++i)
{
if (!string.IsNullOrEmpty(parameterList[i].Key) && (parameterList[i].Key != NLogLogger.OriginalFormatPropertyName || i == parameterList.Count - 1))
{
if (validParameterList != null)
{
if (parameterList[i].Key != NLogLogger.OriginalFormatPropertyName)
validParameterList.Add(parameterList[i]);
}
}
else
{
if (validParameterList == null)
{
validParameterList = new List<KeyValuePair<string, object>>();
for (int j = 0; j < i; ++i)
validParameterList.Add(parameterList[j]);
}
}
}
if (validParameterList != null)
{
validParameterList.Add(new KeyValuePair<string, object>());
}
_parameterList = validParameterList ?? parameterList;
}

public NLog.MessageTemplates.MessageTemplateParameter this[int index]
{
get
{
var parameter = _parameterList[index];
var parameterName = parameter.Key;
NLog.MessageTemplates.CaptureType captureType = NLog.MessageTemplates.CaptureType.Normal;
switch (parameterName[0])
{
case '@':
parameterName = parameterName.Substring(1);
captureType = NLog.MessageTemplates.CaptureType.Serialize;
break;
case '$':
parameterName = parameterName.Substring(1);
captureType = NLog.MessageTemplates.CaptureType.Stringify;
break;
}
return new NLog.MessageTemplates.MessageTemplateParameter(parameter.Key, parameter.Value, null, captureType);
}
set => throw new NotImplementedException();
}

public int Count => _parameterList.Count - 1;

public bool IsReadOnly => true;

public void Add(NLog.MessageTemplates.MessageTemplateParameter item)
{
throw new NotImplementedException();
}

public void Clear()
{
throw new NotImplementedException();
}

public bool Contains(NLog.MessageTemplates.MessageTemplateParameter item)
{
throw new NotImplementedException();
}

public void CopyTo(NLog.MessageTemplates.MessageTemplateParameter[] array, int arrayIndex)
{
throw new NotImplementedException();
}

public IEnumerator<NLog.MessageTemplates.MessageTemplateParameter> GetEnumerator()
{
return _parameterList.Take(_parameterList.Count - 1).Select(p => new NLog.MessageTemplates.MessageTemplateParameter(p.Key, p.Value, null)).GetEnumerator();
}

public int IndexOf(NLog.MessageTemplates.MessageTemplateParameter item)
{
throw new NotImplementedException();
}

public void Insert(int index, NLog.MessageTemplates.MessageTemplateParameter item)
{
throw new NotImplementedException();
}

public bool Remove(NLog.MessageTemplates.MessageTemplateParameter item)
{
throw new NotImplementedException();
}

public void RemoveAt(int index)
{
throw new NotImplementedException();
}

IEnumerator IEnumerable.GetEnumerator()
{
return GetEnumerator();
}
}
#endif
}
5 changes: 5 additions & 0 deletions src/NLog.Extensions.Logging/NLogProviderOptions.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,11 @@ public class NLogProviderOptions
/// <c>default(EventId)</c></remarks>
public bool IgnoreEmptyEventId { get; set; }

/// <summary>
/// Attempt to capture parameter names and values and insert into <see cref="LogEventInfo.Properties" />-dictionary
/// </summary>
public bool EnableStructuredLogging { get; set; }

/// <summary>Initializes a new instance of the <see cref="T:System.Object" /> class.</summary>
public NLogProviderOptions()
{
Expand Down
35 changes: 29 additions & 6 deletions test/LoggerTests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -24,7 +24,6 @@ public void TestInit()

var target = GetTarget();
Assert.Equal("NLog.Extensions.Logging.Tests.LoggerTests.Runner|DEBUG|init runner |0", target.Logs.FirstOrDefault());

}

[Fact]
Expand All @@ -34,7 +33,24 @@ public void TestEventId()

var target = GetTarget();
Assert.Equal("NLog.Extensions.Logging.Tests.LoggerTests.Runner|DEBUG|message with id |20", target.Logs.FirstOrDefault());

}

[Fact]
public void TestParameters()
{
GetRunner().LogDebugWithParameters();

var target = GetTarget();
Assert.Equal("NLog.Extensions.Logging.Tests.LoggerTests.Runner|DEBUG|message with id and 1 parameters |0", target.Logs.FirstOrDefault());
}

[Fact]
public void TestStructuredLogging()
{
GetRunner().LogDebugWithStructuredParameters();

var target = GetTarget();
Assert.Equal("NLog.Extensions.Logging.Tests.LoggerTests.Runner|DEBUG|message with id and 1 parameters |01", target.Logs.FirstOrDefault());
}

[Theory]
Expand Down Expand Up @@ -152,12 +168,11 @@ private static IServiceProvider BuildDi()
var serviceProvider = services.BuildServiceProvider();
var loggerFactory = serviceProvider.GetRequiredService<ILoggerFactory>();

loggerFactory.AddNLog();
loggerFactory.AddNLog(new NLogProviderOptions() { EnableStructuredLogging = true });
loggerFactory.ConfigureNLog("nlog.config");
return serviceProvider;
}


public class Runner
{
private readonly ILogger<Runner> _logger;
Expand All @@ -167,7 +182,6 @@ public Runner(ILoggerFactory fac)
_logger = fac.CreateLogger<Runner>();
}


public void LogDebugWithId()
{
_logger.LogDebug(20, "message with id");
Expand Down Expand Up @@ -200,6 +214,16 @@ public void Log(Microsoft.Extensions.Logging.LogLevel logLevel, int eventId, Exc
}
}

public void LogDebugWithParameters()
{
_logger.LogDebug("message with id and {0} parameters", "1");
}

public void LogDebugWithStructuredParameters()
{
_logger.LogDebug("message with id and {ParameterCount} parameters", "1");
}

public void LogWithScope()
{
using (_logger.BeginScope("scope1"))
Expand All @@ -211,7 +235,6 @@ public void LogWithScope()
public void Init()
{
_logger.LogDebug("init runner");

}
}
}
Expand Down
2 changes: 1 addition & 1 deletion test/NLog.Extensions.Logging.Tests.csproj
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@
<ItemGroup Condition=" '$(TargetFramework)' == 'netcoreapp2.0' ">
<PackageReference Include="Microsoft.Extensions.DependencyInjection" Version="2.0.0" />
<PackageReference Include="Microsoft.Extensions.Logging" Version="2.0.0" />
<PackageReference Include="NLog" Version="4.5.0-beta02" />
<PackageReference Include="NLog" Version="4.5.0-beta06" />
<PackageReference Include="System.AppContext" Version="4.3.0" />
</ItemGroup>

Expand Down
2 changes: 1 addition & 1 deletion test/nlog.config
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,7 @@
<targets>
<!-- write logs to file -->
<target xsi:type="Memory" name="target1"
layout="${logger}|${uppercase:${level}}|${message} ${exception}|${event-properties:EventId}" />
layout="${logger}|${uppercase:${level}}|${message} ${exception}|${event-properties:EventId}${event-properties:ParameterCount}" />

</targets>

Expand Down