diff --git a/CHANGES.md b/CHANGES.md deleted file mode 100644 index cb900c4..0000000 --- a/CHANGES.md +++ /dev/null @@ -1,12 +0,0 @@ -1.2.0 - - * #45 - Make the provider type public so that it can be embedded more easily in other providers - -1.1.0 - - * #41 - Provide a `dispose` flag to instruct provider to take ownership of the Serilog logger - -1.0.0 - - * Initial version - diff --git a/README.md b/README.md index fe2934f..905fc55 100644 --- a/README.md +++ b/README.md @@ -1,11 +1,14 @@ # 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/) - A Serilog provider for [Microsoft.Extensions.Logging](https://www.nuget.org/packages/Microsoft.Extensions.Logging), the logging subsystem used by ASP.NET Core. -### ASP.NET Core 2.0+ Instructions +### ASP.NET Core Instructions + +**ASP.NET Core** applications should prefer [Serilog.AspNetCore](https://github.com/serilog/serilog-aspnetcore) and `UseSerilog()` instead. -**ASP.NET Core 2.0** applications should prefer [Serilog.AspNetCore](https://github.com/serilog/serilog-aspnetcore) and `UseSerilog()` instead. +### Non-web .NET Core Instructions + +**Non-web .NET Core** applications should prefer [Serilog.Extensions.Hosting](https://github.com/serilog/serilog-extensions-hosting) and `UseSerilog()` instead. ### .NET Core 1.0, 1.1 and Default Provider Integration @@ -77,6 +80,69 @@ That's it! With the level bumped up a little you should see log output like: [22:14:45.741 DBG] Handled. Status code: 304 File: /css/site.css ``` +### Notes on Log Scopes + +_Microsoft.Extensions.Logging_ provides the `BeginScope` API, which can be used to add arbitrary properties to log events within a certain region of code. The API comes in two forms: + +1. The method: `IDisposable BeginScope(TState state)` +2. The extension method: `IDisposable BeginScope(this ILogger logger, string messageFormat, params object[] args)` + +Using the extension method will add a `Scope` property to your log events. This is most useful for adding simple "scope strings" to your events, as in the following code: + +```cs +using (_logger.BeginScope("Transaction")) { + _logger.LogInformation("Beginning..."); + _logger.LogInformation("Completed in {DurationMs}ms...", 30); +} +// Example JSON output: +// {"@t":"2020-10-29T19:05:56.4126822Z","@m":"Beginning...","@i":"f6a328e9","SourceContext":"SomeNamespace.SomeService","Scope":["Transaction"]} +// {"@t":"2020-10-29T19:05:56.4176816Z","@m":"Completed in 30ms...","@i":"51812baa","DurationMs":30,"SourceContext":"SomeNamespace.SomeService","Scope":["Transaction"]} +``` + +If you simply want to add a "bag" of additional properties to your log events, however, this extension method approach can be overly verbose. For example, to add `TransactionId` and `ResponseJson` properties to your log events, you would have to do something like the following: + +```cs +// WRONG! Prefer the dictionary approach below instead +using (_logger.BeginScope("TransactionId: {TransactionId}, ResponseJson: {ResponseJson}", 12345, jsonString)) { + _logger.LogInformation("Completed in {DurationMs}ms...", 30); +} +// Example JSON output: +// { +// "@t":"2020-10-29T19:05:56.4176816Z", +// "@m":"Completed in 30ms...", +// "@i":"51812baa", +// "DurationMs":30, +// "SourceContext":"SomeNamespace.SomeService", +// "TransactionId": 12345, +// "ResponseJson": "{ \"Key1\": \"Value1\", \"Key2\": \"Value2\" }", +// "Scope":["TransactionId: 12345, ResponseJson: { \"Key1\": \"Value1\", \"Key2\": \"Value2\" }"] +// } +``` + +Not only does this add the unnecessary `Scope` property to your event, but it also duplicates serialized values between `Scope` and the intended properties, as you can see here with `ResponseJson`. If this were "real" JSON like an API response, then a potentially very large block of text would be duplicated within your log event! Moreover, the template string within `BeginScope` is rather arbitrary when all you want to do is add a bag of properties, and you start mixing enriching concerns with formatting concerns. + +A far better alternative is to use the `BeginScope(TState state)` method. If you provide any `IEnumerable>` to this method, then Serilog will output the key/value pairs as structured properties _without_ the `Scope` property, as in this example: + +```cs +var scopeProps = new Dictionary { + { "TransactionId", 12345 }, + { "ResponseJson", jsonString }, +}; +using (_logger.BeginScope(scopeProps) { + _logger.LogInformation("Transaction completed in {DurationMs}ms...", 30); +} +// Example JSON output: +// { +// "@t":"2020-10-29T19:05:56.4176816Z", +// "@m":"Completed in 30ms...", +// "@i":"51812baa", +// "DurationMs":30, +// "SourceContext":"SomeNamespace.SomeService", +// "TransactionId": 12345, +// "ResponseJson": "{ \"Key1\": \"Value1\", \"Key2\": \"Value2\" }" +// } +``` + ### Credits This package evolved from an earlier package _Microsoft.Framework.Logging.Serilog_ [provided by the ASP.NET team](https://github.com/aspnet/Logging/pull/182). diff --git a/appveyor.yml b/appveyor.yml index dc593a6..628e491 100644 --- a/appveyor.yml +++ b/appveyor.yml @@ -1,13 +1,8 @@ version: '{build}' skip_tags: true image: Visual Studio 2019 -configuration: Release install: - ps: mkdir -Force ".\build\" | Out-Null - #- ps: Invoke-WebRequest "https://raw.githubusercontent.com/dotnet/cli/release/2.0.0/scripts/obtain/dotnet-install.ps1" -OutFile ".\build\installcli.ps1" - #- ps: $env:DOTNET_INSTALL_DIR = "$pwd\.dotnetcli" - #- ps: '& .\build\installcli.ps1 -InstallDir "$env:DOTNET_INSTALL_DIR" -NoPath -Version 2.0.0-preview2-006497' - #- ps: $env:Path = "$env:DOTNET_INSTALL_DIR;$env:Path" build_script: - ps: ./Build.ps1 test: off @@ -16,7 +11,7 @@ artifacts: deploy: - provider: NuGet api_key: - secure: N59tiJECUYpip6tEn0xvdmDAEiP9SIzyLEFLpwiigm/8WhJvBNs13QxzT1/3/JW/ + secure: kYR3BYzJm3wSFbFjPhgTzuDHHcE8ApoNUmHvJvunWZ39nyrqVk6J6srjzYVQ7/gX skip_symbols: true on: branch: /^(master|dev)$/ diff --git a/assets/serilog-extension-nuget.png b/assets/serilog-extension-nuget.png new file mode 100644 index 0000000..75e36fb Binary files /dev/null and b/assets/serilog-extension-nuget.png differ diff --git a/global.json b/global.json index 6b64107..e3bbb00 100644 --- a/global.json +++ b/global.json @@ -1,5 +1,7 @@ { "sdk": { - "version": "2.2.103" + "allowPrerelease": false, + "version": "3.1.100", + "rollForward": "latestFeature" } } diff --git a/serilog-extensions-logging.sln.DotSettings b/serilog-extensions-logging.sln.DotSettings index 4009815..c2fd9da 100644 --- a/serilog-extensions-logging.sln.DotSettings +++ b/serilog-extensions-logging.sln.DotSettings @@ -8,4 +8,5 @@ True True True - True \ No newline at end of file + True + True \ No newline at end of file diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/CachingMessageTemplateParser.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/CachingMessageTemplateParser.cs new file mode 100644 index 0000000..d47e84f --- /dev/null +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/CachingMessageTemplateParser.cs @@ -0,0 +1,67 @@ +// Copyright (c) Serilog Contributors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + + +using System; +using Serilog.Events; +using Serilog.Parsing; +using System.Collections; + +namespace Serilog.Extensions.Logging +{ + class CachingMessageTemplateParser + { + readonly MessageTemplateParser _innerParser = new MessageTemplateParser(); + + readonly object _templatesLock = new object(); + readonly Hashtable _templates = new Hashtable(); + + const int MaxCacheItems = 1000; + const int MaxCachedTemplateLength = 1024; + + public MessageTemplate Parse(string messageTemplate) + { + if (messageTemplate == null) throw new ArgumentNullException(nameof(messageTemplate)); + + if (messageTemplate.Length > MaxCachedTemplateLength) + return _innerParser.Parse(messageTemplate); + + // ReSharper disable once InconsistentlySynchronizedField + // ignored warning because this is by design + var result = (MessageTemplate)_templates[messageTemplate]; + if (result != null) + return result; + + result = _innerParser.Parse(messageTemplate); + + lock (_templatesLock) + { + // Exceeding MaxCacheItems is *not* the sunny day scenario; all we're doing here is preventing out-of-memory + // conditions when the library is used incorrectly. Correct use (templates, rather than + // direct message strings) should barely, if ever, overflow this cache. + + // Changing workloads through the lifecycle of an app instance mean we can gain some ground by + // potentially dropping templates generated only in startup, or only during specific infrequent + // activities. + + if (_templates.Count == MaxCacheItems) + _templates.Clear(); + + _templates[messageTemplate] = result; + } + + return result; + } + } +} diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/LoggerProviderCollection.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/LoggerProviderCollection.cs index 6ecb000..7a0e08b 100644 --- a/src/Serilog.Extensions.Logging/Extensions/Logging/LoggerProviderCollection.cs +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/LoggerProviderCollection.cs @@ -26,7 +26,7 @@ namespace Serilog.Extensions.Logging /// public class LoggerProviderCollection : IDisposable { - volatile ILoggerProvider[] _providers = new ILoggerProvider[0]; + volatile ILoggerProvider[] _providers = Array.Empty(); /// /// Add to the collection. @@ -36,16 +36,16 @@ public void AddProvider(ILoggerProvider provider) { if (provider == null) throw new ArgumentNullException(nameof(provider)); - var existing = _providers; - var added = existing.Concat(new[] {provider}).ToArray(); + ILoggerProvider[] existing, added; -#pragma warning disable 420 // ref to a volatile field - while (Interlocked.CompareExchange(ref _providers, added, existing) != existing) -#pragma warning restore 420 + do { existing = _providers; added = existing.Concat(new[] { provider }).ToArray(); } +#pragma warning disable 420 // ref to a volatile field + while (Interlocked.CompareExchange(ref _providers, added, existing) != existing); +#pragma warning restore 420 } /// diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/LoggerProviderCollectionSink.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/LoggerProviderCollectionSink.cs index 94838ea..afe4a29 100644 --- a/src/Serilog.Extensions.Logging/Extensions/Logging/LoggerProviderCollectionSink.cs +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/LoggerProviderCollectionSink.cs @@ -13,6 +13,7 @@ // limitations under the License. using System; +using Microsoft.Extensions.Logging; using Serilog.Core; using Serilog.Events; @@ -30,6 +31,7 @@ public LoggerProviderCollectionSink(LoggerProviderCollection providers) public void Emit(LogEvent logEvent) { string categoryName = null; + EventId eventId = default; if (logEvent.Properties.TryGetValue("SourceContext", out var sourceContextProperty) && sourceContextProperty is ScalarValue sourceContextValue && @@ -37,6 +39,18 @@ sourceContextProperty is ScalarValue sourceContextValue && { categoryName = sourceContext; } + if (logEvent.Properties.TryGetValue("EventId", out var eventIdPropertyValue) && eventIdPropertyValue is StructureValue structuredEventId) + { + string name = null; + var id = 0; + foreach (var item in structuredEventId.Properties) + { + if (item.Name == "Id" && item.Value is ScalarValue sv && sv.Value is int i) id = i; + if (item.Name == "Name" && item.Value is ScalarValue sv2 && sv2.Value is string s) name = s; + } + + eventId = new EventId(id, name); + } var level = LevelConvert.ToExtensionsLevel(logEvent.Level); var slv = new SerilogLogValues(logEvent.MessageTemplate, logEvent.Properties); @@ -47,7 +61,7 @@ sourceContextProperty is ScalarValue sourceContextValue && logger.Log( level, - default, + eventId, slv, logEvent.Exception, (s, e) => s.ToString()); diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs index 007e73d..1b1f895 100644 --- a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs @@ -9,7 +9,7 @@ using Serilog.Events; using FrameworkLogger = Microsoft.Extensions.Logging.ILogger; using System.Reflection; -using Serilog.Parsing; +using Serilog.Debugging; namespace Serilog.Extensions.Logging { @@ -18,7 +18,7 @@ class SerilogLogger : FrameworkLogger readonly SerilogLoggerProvider _provider; readonly ILogger _logger; - static readonly MessageTemplateParser MessageTemplateParser = new MessageTemplateParser(); + static readonly CachingMessageTemplateParser MessageTemplateParser = new CachingMessageTemplateParser(); // It's rare to see large event ids, as they are category-specific static readonly LogEventProperty[] LowEventIdValues = Enumerable.Range(0, 48) @@ -60,6 +60,18 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except return; } + try + { + Write(level, eventId, state, exception, formatter); + } + catch (Exception ex) + { + SelfLog.WriteLine($"Failed to write event through {typeof(SerilogLogger).Name}: {ex}"); + } + } + + void Write(LogEventLevel level, EventId eventId, TState state, Exception exception, Func formatter) + { var logger = _logger; string messageTemplate = null; @@ -78,6 +90,11 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except if (logger.BindProperty(property.Key.Substring(1), property.Value, true, out var destructured)) properties.Add(destructured); } + else if (property.Key.StartsWith("$")) + { + if (logger.BindProperty(property.Key.Substring(1), property.Value?.ToString(), true, out var stringified)) + properties.Add(stringified); + } else { if (logger.BindProperty(property.Key, property.Value, false, out var bound)) @@ -154,4 +171,4 @@ internal static LogEventProperty CreateEventIdProperty(EventId eventId) return new LogEventProperty("EventId", new StructureValue(properties)); } } -} \ No newline at end of file +} diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs index f4daf8a..d51c2c0 100644 --- a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerProvider.cs @@ -69,8 +69,7 @@ public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) List scopeItems = null; for (var scope = CurrentScope; scope != null; scope = scope.Parent) { - LogEventPropertyValue scopeItem; - scope.EnrichAndCreateScopeItem(logEvent, propertyFactory, out scopeItem); + scope.EnrichAndCreateScopeItem(logEvent, propertyFactory, out LogEventPropertyValue scopeItem); if (scopeItem != null) { diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerScope.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerScope.cs index 424d459..dd0803c 100644 --- a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerScope.cs +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLoggerScope.cs @@ -57,8 +57,7 @@ public void EnrichAndCreateScopeItem(LogEvent logEvent, ILogEventPropertyFactory return; } - var stateProperties = _state as IEnumerable>; - if (stateProperties != null) + if (_state is IEnumerable> stateProperties) { scopeItem = null; // Unless it's `FormattedLogValues`, these are treated as property bags rather than scope items. @@ -72,14 +71,21 @@ public void EnrichAndCreateScopeItem(LogEvent logEvent, ILogEventPropertyFactory var key = stateProperty.Key; var destructureObject = false; + var value = stateProperty.Value; if (key.StartsWith("@")) { key = key.Substring(1); destructureObject = true; } - - var property = propertyFactory.CreateProperty(key, stateProperty.Value, destructureObject); + + if (key.StartsWith("$")) + { + key = key.Substring(1); + value = value?.ToString(); + } + + var property = propertyFactory.CreateProperty(key, value, destructureObject); logEvent.AddPropertyIfAbsent(property); } } diff --git a/src/Serilog.Extensions.Logging/Serilog.Extensions.Logging.csproj b/src/Serilog.Extensions.Logging/Serilog.Extensions.Logging.csproj index 9a3e564..f6d4bc1 100644 --- a/src/Serilog.Extensions.Logging/Serilog.Extensions.Logging.csproj +++ b/src/Serilog.Extensions.Logging/Serilog.Extensions.Logging.csproj @@ -2,7 +2,7 @@ Low-level Serilog provider for Microsoft.Extensions.Logging - 3.0.1 + 3.1.0 Microsoft;Serilog Contributors netstandard2.0 true @@ -13,18 +13,21 @@ true Serilog.Extensions.Logging serilog;Microsoft.Extensions.Logging - http://serilog.net/images/serilog-extension-nuget.png + serilog-extension-nuget.png https://github.com/serilog/serilog-extensions-logging - http://www.apache.org/licenses/LICENSE-2.0 + Apache-2.0 https://github.com/serilog/serilog-extensions-logging git false Serilog - 7.3 - + + + + + diff --git a/src/Serilog.Extensions.Logging/SerilogLoggerFactoryExtensions.cs b/src/Serilog.Extensions.Logging/SerilogLoggerFactoryExtensions.cs index c2aa06d..5292603 100644 --- a/src/Serilog.Extensions.Logging/SerilogLoggerFactoryExtensions.cs +++ b/src/Serilog.Extensions.Logging/SerilogLoggerFactoryExtensions.cs @@ -20,7 +20,7 @@ public static class SerilogLoggerFactoryExtensions /// When true, dispose when the framework disposes the provider. If the /// logger is not specified but is true, the method will be /// called on the static class instead. - /// The logger factory. + /// Reference to the supplied . public static ILoggerFactory AddSerilog( this ILoggerFactory factory, ILogger logger = null, diff --git a/src/Serilog.Extensions.Logging/SerilogLoggingBuilderExtensions.cs b/src/Serilog.Extensions.Logging/SerilogLoggingBuilderExtensions.cs index 27bb6dd..2cf0008 100644 --- a/src/Serilog.Extensions.Logging/SerilogLoggingBuilderExtensions.cs +++ b/src/Serilog.Extensions.Logging/SerilogLoggingBuilderExtensions.cs @@ -32,7 +32,7 @@ public static class SerilogLoggingBuilderExtensions /// When true, dispose when the framework disposes the provider. If the /// logger is not specified but is true, the method will be /// called on the static class instead. - /// The logger factory. + /// Reference to the supplied . public static ILoggingBuilder AddSerilog(this ILoggingBuilder builder, ILogger logger = null, bool dispose = false) { if (builder == null) throw new ArgumentNullException(nameof(builder)); diff --git a/test/Serilog.Extensions.Logging.Tests/LoggerProviderCollectionSinkTests.cs b/test/Serilog.Extensions.Logging.Tests/LoggerProviderCollectionSinkTests.cs new file mode 100644 index 0000000..0be1b4c --- /dev/null +++ b/test/Serilog.Extensions.Logging.Tests/LoggerProviderCollectionSinkTests.cs @@ -0,0 +1,85 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using Microsoft.Extensions.Logging; +using Serilog.Extensions.Logging.Tests.Support; +using Xunit; + +namespace Serilog.Extensions.Logging.Tests +{ + public class LoggerProviderCollectionSinkTests + { + const string Name = "test"; + const string TestMessage = "This is a test"; + + static Tuple SetUp(LogLevel logLevel) + { + var providers = new LoggerProviderCollection(); + var provider = new ExtensionsProvider(logLevel); + providers.AddProvider(provider); + var serilogLogger = new LoggerConfiguration() + .WriteTo.Providers(providers) + .MinimumLevel.Is(LevelConvert.ToSerilogLevel(logLevel)) + .CreateLogger(); + + var logger = (SerilogLogger)new SerilogLoggerProvider(serilogLogger).CreateLogger(Name); + + return new Tuple(logger, provider); + } + + [Fact] + public void LogsCorrectLevel() + { + var (logger, sink) = SetUp(LogLevel.Trace); + + logger.Log(LogLevel.Trace, 0, TestMessage, null, null); + logger.Log(LogLevel.Debug, 0, TestMessage, null, null); + logger.Log(LogLevel.Information, 0, TestMessage, null, null); + logger.Log(LogLevel.Warning, 0, TestMessage, null, null); + logger.Log(LogLevel.Error, 0, TestMessage, null, null); + logger.Log(LogLevel.Critical, 0, TestMessage, null, null); + + Assert.Equal(6, sink.Writes.Count); + Assert.Equal(LogLevel.Trace, sink.Writes[0].logLevel); + Assert.Equal(LogLevel.Debug, sink.Writes[1].logLevel); + Assert.Equal(LogLevel.Information, sink.Writes[2].logLevel); + Assert.Equal(LogLevel.Warning, sink.Writes[3].logLevel); + Assert.Equal(LogLevel.Error, sink.Writes[4].logLevel); + Assert.Equal(LogLevel.Critical, sink.Writes[5].logLevel); + } + + [Fact] + public void LogsCorrectEventId() + { + var (logger, sink) = SetUp(LogLevel.Trace); + + logger.Log(LogLevel.Trace, new EventId(1, nameof(LogLevel.Trace)), TestMessage, null, null); + logger.Log(LogLevel.Debug, new EventId(2, nameof(LogLevel.Debug)), TestMessage, null, null); + logger.Log(LogLevel.Information, new EventId(3, nameof(LogLevel.Information)), TestMessage, null, null); + logger.Log(LogLevel.Warning, new EventId(4, nameof(LogLevel.Warning)), TestMessage, null, null); + logger.Log(LogLevel.Error, new EventId(5, nameof(LogLevel.Error)), TestMessage, null, null); + logger.Log(LogLevel.Critical, new EventId(6, nameof(LogLevel.Critical)), TestMessage, null, null); + + Assert.Equal(6, sink.Writes.Count); + + Assert.Equal(1, sink.Writes[0].eventId.Id); + Assert.Equal(nameof(LogLevel.Trace), sink.Writes[0].eventId.Name); + + Assert.Equal(2, sink.Writes[1].eventId.Id); + Assert.Equal(nameof(LogLevel.Debug), sink.Writes[1].eventId.Name); + + Assert.Equal(3, sink.Writes[2].eventId.Id); + Assert.Equal(nameof(LogLevel.Information), sink.Writes[2].eventId.Name); + + Assert.Equal(4, sink.Writes[3].eventId.Id); + Assert.Equal(nameof(LogLevel.Warning), sink.Writes[3].eventId.Name); + + Assert.Equal(5, sink.Writes[4].eventId.Id); + Assert.Equal(nameof(LogLevel.Error), sink.Writes[4].eventId.Name); + + Assert.Equal(6, sink.Writes[5].eventId.Id); + Assert.Equal(nameof(LogLevel.Critical), sink.Writes[5].eventId.Name); + } + } +} diff --git a/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs b/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs index d2d5bac..f37e9eb 100644 --- a/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs +++ b/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs @@ -162,6 +162,21 @@ public void SingleScopeProperty() Assert.Equal("\"pizza\"", sink.Writes[0].Properties["Name"].ToString()); } + [Fact] + public void StringifyScopeProperty() + { + var (logger, sink) = SetUp(LogLevel.Trace); + + using (logger.BeginScope("{$values}", new [] { 1, 2, 3, 4 })) + { + logger.Log(LogLevel.Information, 0, TestMessage, null, null); + } + + Assert.Equal(1, sink.Writes.Count); + Assert.True(sink.Writes[0].Properties.ContainsKey("values")); + Assert.Equal("\"System.Int32[]\"", sink.Writes[0].Properties["values"].ToString()); + } + [Fact] public void NestedScopeSameProperty() { @@ -219,6 +234,24 @@ public void CarriesMessageTemplateProperties() Assert.Empty(selfLog.ToString()); } + [Fact] + public void CarriesMessageTemplatePropertiesWhenStringificationIsUsed() + { + var selfLog = new StringWriter(); + SelfLog.Enable(selfLog); + var (logger, sink) = SetUp(LogLevel.Trace); + var array = new[] { 1, 2, 3, 4 }; + + logger.LogInformation("{$array}", array); + + Assert.True(sink.Writes[0].Properties.ContainsKey("array")); + Assert.Equal("\"System.Int32[]\"", sink.Writes[0].Properties["array"].ToString()); + Assert.Equal("{$array}", sink.Writes[0].MessageTemplate.Text); + + SelfLog.Disable(); + Assert.Empty(selfLog.ToString()); + } + [Fact] public void CarriesEventIdIfNonzero() { @@ -239,6 +272,7 @@ public void CarriesEventIdIfNonzero() public void WhenDisposeIsFalseProvidedLoggerIsNotDisposed() { var logger = new DisposeTrackingLogger(); + // ReSharper disable once RedundantArgumentDefaultValue var provider = new SerilogLoggerProvider(logger, false); provider.Dispose(); Assert.False(logger.IsDisposed); @@ -406,5 +440,15 @@ public void LowAndHighNumberedEventIdsAreMapped(int id) var scalar = Assert.IsType(idValue); Assert.Equal(id, scalar.Value); } + + [Fact] + public void MismatchedMessageTemplateParameterCountIsHandled() + { + var (logger, sink) = SetUp(LogLevel.Trace); + + logger.LogInformation("Some test message with {Two} {Properties}", "OneProperty"); + + Assert.Equal(0, sink.Writes.Count); + } } } diff --git a/test/Serilog.Extensions.Logging.Tests/Support/ExtensionsProvider.cs b/test/Serilog.Extensions.Logging.Tests/Support/ExtensionsProvider.cs new file mode 100644 index 0000000..583293c --- /dev/null +++ b/test/Serilog.Extensions.Logging.Tests/Support/ExtensionsProvider.cs @@ -0,0 +1,45 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; +using System.Collections.Generic; +using Microsoft.Extensions.Logging; +using Serilog.Events; + +namespace Serilog.Extensions.Logging.Tests.Support +{ + public class ExtensionsProvider : ILoggerProvider, Microsoft.Extensions.Logging.ILogger + { + private readonly LogLevel enabledLevel; + public List<(LogLevel logLevel, EventId eventId, object state, Exception exception, string message)> Writes { get; set; } = new List<(LogLevel logLevel, EventId eventId, object state, Exception exception, string message)>(); + + public ExtensionsProvider(LogLevel enabledLevel) + { + this.enabledLevel = enabledLevel; + } + + public Microsoft.Extensions.Logging.ILogger CreateLogger(string categoryName) + { + return this; + } + + public IDisposable BeginScope(TState state) + { + return this; + } + + public bool IsEnabled(LogLevel logLevel) + { + return enabledLevel <= logLevel; + } + + public void Log(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func formatter) + { + Writes.Add((logLevel, eventId, state, exception, formatter(state, exception))); + } + + public void Dispose() + { + } + } +} \ No newline at end of file