Skip to content

Commit 40ae58e

Browse files
nblumhardtnblumhardt
authored
Merge pull request #59 from serilog/dev
1.3.0 Release
2 parents 5e5798a + 98ed6d6 commit 40ae58e

File tree

8 files changed

+196
-16
lines changed

8 files changed

+196
-16
lines changed

‎README.md‎

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,4 @@
1-
# Serilog.Extensions.Logging
2-
[![Build status](https://ci.appveyor.com/api/projects/status/865nohxfiq1rnby0/branch/master?svg=true)](https://ci.appveyor.com/project/serilog/serilog-framework-logging/history) [![NuGet Version](http://img.shields.io/nuget/v/Serilog.Extensions.Logging.svg?style=flat)](https://www.nuget.org/packages/Serilog.Extensions.Logging/)
1+
# Serilog.Extensions.Logging [![Build status](https://ci.appveyor.com/api/projects/status/865nohxfiq1rnby0/branch/master?svg=true)](https://ci.appveyor.com/project/serilog/serilog-framework-logging/history) [![NuGet Version](http://img.shields.io/nuget/v/Serilog.Extensions.Logging.svg?style=flat)](https://www.nuget.org/packages/Serilog.Extensions.Logging/)
32

43

54
A Serilog provider for [Microsoft.Extensions.Logging](https://www.nuget.org/packages/Microsoft.Extensions.Logging), the logging subsystem used by ASP.NET Core.

‎samples/WebSample/Controllers/HomeController.cs‎

Lines changed: 19 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -4,22 +4,40 @@
44
using System.Threading.Tasks;
55
using Microsoft.AspNetCore.Mvc;
66
using Serilog;
7+
using Microsoft.Extensions.Logging;
78

89
namespace WebSample.Controllers
910
{
1011
public class HomeController : Controller
1112
{
13+
ILogger<HomeController> _logger;
14+
15+
public HomeController(ILogger<HomeController> logger)
16+
{
17+
_logger = logger;
18+
}
19+
1220
public IActionResult Index()
1321
{
14-
Log.Information("Hello from the Index!");
22+
_logger.LogInformation("Before");
23+
24+
using (_logger.BeginScope("Some name"))
25+
using (_logger.BeginScope(42))
26+
using (_logger.BeginScope("Formatted {WithValue}", 12345))
27+
using (_logger.BeginScope(new Dictionary<string, object> { ["ViaDictionary"] = 100 }))
28+
{
29+
_logger.LogInformation("Hello from the Index!");
30+
}
1531

32+
_logger.LogInformation("After");
1633
return View();
1734
}
1835

1936
public IActionResult About()
2037
{
2138
ViewData["Message"] = "Your application description page.";
2239

40+
// Directly through Serilog
2341
Log.Information("This is a handler for {Path}", Request.Path);
2442

2543
return View();

‎samples/WebSample/appsettings.json‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,8 @@
1212
],
1313
"WriteTo": [
1414
"Trace",
15-
"LiterateConsole"
15+
"LiterateConsole",
16+
{"Name": "Seq", "Args": {"serverUrl": "http://localhost:5341" }}
1617
]
1718
}
1819
}

‎samples/WebSample/project.json‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -23,7 +23,8 @@
2323
"Serilog.Extensions.Logging": { "target": "project" },
2424
"Serilog.Settings.Configuration": "2.1.0-dev-00028",
2525
"Serilog.Sinks.Trace": "2.0.0",
26-
"Serilog.Sinks.Literate": "2.0.0"
26+
"Serilog.Sinks.Literate": "2.0.0",
27+
"Serilog.Sinks.Seq": "3.1.1"
2728
},
2829

2930
"tools": {

‎src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs‎

Lines changed: 26 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,8 @@
1212
using Serilog.Core;
1313
using Serilog.Events;
1414
using FrameworkLogger = Microsoft.Extensions.Logging.ILogger;
15+
using System.Collections.Generic;
16+
using Serilog.Context;
1517

1618
namespace Serilog.Extensions.Logging
1719
{
@@ -21,6 +23,7 @@ namespace Serilog.Extensions.Logging
2123
public class SerilogLoggerProvider : ILoggerProvider, ILogEventEnricher
2224
{
2325
internal const string OriginalFormatPropertyName = "{OriginalFormat}";
26+
internal const string ScopePropertyName = "Scope";
2427

2528
// May be null; if it is, Log.Logger will be lazily used
2629
readonly ILogger _logger;
@@ -54,15 +57,36 @@ public FrameworkLogger CreateLogger(string name)
5457
/// <inheritdoc />
5558
public IDisposable BeginScope<T>(T state)
5659
{
57-
return new SerilogLoggerScope(this, state);
60+
if (CurrentScope != null)
61+
return new SerilogLoggerScope(this, state);
62+
63+
// The outermost scope pushes and pops the Serilog `LogContext` - once
64+
// this enricher is on the stack, the `CurrentScope` property takes care
65+
// of the rest of the `BeginScope()` stack.
66+
var popSerilogContext = LogContext.PushProperties(this);
67+
return new SerilogLoggerScope(this, state, popSerilogContext);
5868
}
5969

6070
/// <inheritdoc />
6171
public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
6272
{
73+
List<LogEventPropertyValue> scopeItems = null;
6374
for (var scope = CurrentScope; scope != null; scope = scope.Parent)
6475
{
65-
scope.Enrich(logEvent, propertyFactory);
76+
LogEventPropertyValue scopeItem;
77+
scope.EnrichAndCreateScopeItem(logEvent, propertyFactory, out scopeItem);
78+
79+
if (scopeItem != null)
80+
{
81+
scopeItems = scopeItems ?? new List<LogEventPropertyValue>();
82+
scopeItems.Add(scopeItem);
83+
}
84+
}
85+
86+
if (scopeItems != null)
87+
{
88+
scopeItems.Reverse();
89+
logEvent.AddPropertyIfAbsent(new LogEventProperty(ScopePropertyName, new SequenceValue(scopeItems)));
6690
}
6791
}
6892

‎src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerScope.cs‎

Lines changed: 33 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -3,29 +3,30 @@
33

44
using System;
55
using System.Collections.Generic;
6-
using Serilog.Context;
76
using Serilog.Core;
87
using Serilog.Events;
98

109
namespace Serilog.Extensions.Logging
1110
{
12-
class SerilogLoggerScope : IDisposable, ILogEventEnricher
11+
class SerilogLoggerScope : IDisposable
1312
{
13+
const string NoName = "None";
14+
1415
readonly SerilogLoggerProvider _provider;
1516
readonly object _state;
16-
readonly IDisposable _popSerilogContext;
17+
readonly IDisposable _chainedDisposable;
1718

1819
// An optimization only, no problem if there are data races on this.
1920
bool _disposed;
2021

21-
public SerilogLoggerScope(SerilogLoggerProvider provider, object state)
22+
public SerilogLoggerScope(SerilogLoggerProvider provider, object state, IDisposable chainedDisposable = null)
2223
{
2324
_provider = provider;
2425
_state = state;
2526

2627
Parent = _provider.CurrentScope;
2728
_provider.CurrentScope = this;
28-
_popSerilogContext = LogContext.PushProperties(this);
29+
_chainedDisposable = chainedDisposable;
2930
}
3031

3132
public SerilogLoggerScope Parent { get; }
@@ -44,24 +45,48 @@ public void Dispose()
4445
_provider.CurrentScope = Parent;
4546
}
4647

47-
_popSerilogContext.Dispose();
48+
_chainedDisposable?.Dispose();
4849
}
4950
}
5051

51-
public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
52+
public void EnrichAndCreateScopeItem(LogEvent logEvent, ILogEventPropertyFactory propertyFactory, out LogEventPropertyValue scopeItem)
5253
{
54+
if (_state == null)
55+
{
56+
scopeItem = null;
57+
return;
58+
}
59+
5360
var stateProperties = _state as IEnumerable<KeyValuePair<string, object>>;
5461
if (stateProperties != null)
5562
{
63+
scopeItem = null; // Unless it's `FormattedLogValues`, these are treated as property bags rather than scope items.
64+
5665
foreach (var stateProperty in stateProperties)
5766
{
5867
if (stateProperty.Key == SerilogLoggerProvider.OriginalFormatPropertyName && stateProperty.Value is string)
68+
{
69+
scopeItem = new ScalarValue(_state.ToString());
5970
continue;
71+
}
72+
73+
var key = stateProperty.Key;
74+
var destructureObject = false;
6075

61-
var property = propertyFactory.CreateProperty(stateProperty.Key, stateProperty.Value);
76+
if (key.StartsWith("@"))
77+
{
78+
key = key.Substring(1);
79+
destructureObject = true;
80+
}
81+
82+
var property = propertyFactory.CreateProperty(key, stateProperty.Value, destructureObject);
6283
logEvent.AddPropertyIfAbsent(property);
6384
}
6485
}
86+
else
87+
{
88+
scopeItem = propertyFactory.CreateProperty(NoName, _state).Value;
89+
}
6590
}
6691
}
6792
}

‎src/Serilog.Extensions.Logging/project.json‎

Lines changed: 7 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
{
2-
"version": "1.2.0-*",
2+
"version": "1.3.0-*",
33
"description": "Serilog provider for Microsoft.Extensions.Logging",
44
"authors": [ "Microsoft", "Serilog Contributors" ],
55
"packOptions": {
@@ -21,6 +21,12 @@
2121
"net4.5": {
2222
"dependencies": { "System.Runtime": "4.0.0" }
2323
},
24+
"net4.6": {
25+
"dependencies": { "System.Runtime": "4.0.20" },
26+
"buildOptions": {
27+
"define": [ "ASYNCLOCAL" ]
28+
}
29+
},
2430
"netstandard1.3": {
2531
"buildOptions": {
2632
"define": ["ASYNCLOCAL"]

‎test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs‎

Lines changed: 106 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -288,6 +288,106 @@ public void WhenDisposeIsTrueProvidedLoggerIsDisposed()
288288
Assert.True(logger.IsDisposed);
289289
}
290290

291+
[Fact]
292+
public void BeginScopeDestructuresObjectsWhenDestructurerIsUsedInMessageTemplate()
293+
{
294+
var t = SetUp(LogLevel.Trace);
295+
var logger = t.Item1;
296+
var sink = t.Item2;
297+
298+
using (logger.BeginScope("{@Person}", new Person { FirstName = "John", LastName = "Smith" }))
299+
{
300+
logger.Log(LogLevel.Information, 0, TestMessage, null, null);
301+
}
302+
303+
Assert.Equal(1, sink.Writes.Count);
304+
Assert.True(sink.Writes[0].Properties.ContainsKey("Person"));
305+
306+
var person = (StructureValue)sink.Writes[0].Properties["Person"];
307+
var firstName = (ScalarValue)person.Properties.Single(p => p.Name == "FirstName").Value;
308+
var lastName = (ScalarValue)person.Properties.Single(p => p.Name == "LastName").Value;
309+
Assert.Equal("John", firstName.Value);
310+
Assert.Equal("Smith", lastName.Value);
311+
}
312+
313+
[Fact]
314+
public void BeginScopeDestructuresObjectsWhenDestructurerIsUsedInDictionary()
315+
{
316+
var t = SetUp(LogLevel.Trace);
317+
var logger = t.Item1;
318+
var sink = t.Item2;
319+
320+
using (logger.BeginScope(new Dictionary<string, object> {{ "@Person", new Person { FirstName = "John", LastName = "Smith" }}}))
321+
{
322+
logger.Log(LogLevel.Information, 0, TestMessage, null, null);
323+
}
324+
325+
Assert.Equal(1, sink.Writes.Count);
326+
Assert.True(sink.Writes[0].Properties.ContainsKey("Person"));
327+
328+
var person = (StructureValue)sink.Writes[0].Properties["Person"];
329+
var firstName = (ScalarValue)person.Properties.Single(p => p.Name == "FirstName").Value;
330+
var lastName = (ScalarValue)person.Properties.Single(p => p.Name == "LastName").Value;
331+
Assert.Equal("John", firstName.Value);
332+
Assert.Equal("Smith", lastName.Value);
333+
}
334+
335+
[Fact]
336+
public void BeginScopeDoesNotModifyKeyWhenDestructurerIsNotUsedInMessageTemplate()
337+
{
338+
var t = SetUp(LogLevel.Trace);
339+
var logger = t.Item1;
340+
var sink = t.Item2;
341+
342+
using (logger.BeginScope("{FirstName}", "John"))
343+
{
344+
logger.Log(LogLevel.Information, 0, TestMessage, null, null);
345+
}
346+
347+
Assert.Equal(1, sink.Writes.Count);
348+
Assert.True(sink.Writes[0].Properties.ContainsKey("FirstName"));
349+
}
350+
351+
[Fact]
352+
public void BeginScopeDoesNotModifyKeyWhenDestructurerIsNotUsedInDictionary()
353+
{
354+
var t = SetUp(LogLevel.Trace);
355+
var logger = t.Item1;
356+
var sink = t.Item2;
357+
358+
using (logger.BeginScope(new Dictionary<string, object> { { "FirstName", "John"}}))
359+
{
360+
logger.Log(LogLevel.Information, 0, TestMessage, null, null);
361+
}
362+
363+
Assert.Equal(1, sink.Writes.Count);
364+
Assert.True(sink.Writes[0].Properties.ContainsKey("FirstName"));
365+
}
366+
367+
[Fact]
368+
public void NamedScopesAreCaptured()
369+
{
370+
var t = SetUp(LogLevel.Trace);
371+
var logger = t.Item1;
372+
var sink = t.Item2;
373+
374+
using (logger.BeginScope("Outer"))
375+
using (logger.BeginScope("Inner"))
376+
{
377+
logger.Log(LogLevel.Information, 0, TestMessage, null, null);
378+
}
379+
380+
Assert.Equal(1, sink.Writes.Count);
381+
382+
LogEventPropertyValue scopeValue;
383+
Assert.True(sink.Writes[0].Properties.TryGetValue(SerilogLoggerProvider.ScopePropertyName, out scopeValue));
384+
385+
var items = (scopeValue as SequenceValue)?.Elements.Select(e => ((ScalarValue)e).Value).Cast<string>().ToArray();
386+
Assert.Equal(2, items.Length);
387+
Assert.Equal("Outer", items[0]);
388+
Assert.Equal("Inner", items[1]);
389+
}
390+
291391
private class FoodScope : IEnumerable<KeyValuePair<string, object>>
292392
{
293393
readonly string _name;
@@ -327,5 +427,11 @@ IEnumerator IEnumerable.GetEnumerator()
327427
return GetEnumerator();
328428
}
329429
}
430+
431+
private class Person
432+
{
433+
public string FirstName { get; set; }
434+
public string LastName { get; set; }
435+
}
330436
}
331437
}

0 commit comments

Comments
 (0)