From e23e2bb7249631ee27580b3bd3cc00c5c9029141 Mon Sep 17 00:00:00 2001 From: Sergey Komisarchik Date: Thu, 6 Apr 2017 23:12:45 +0300 Subject: [PATCH] less allocations --- .../AllocationsBenchmark-report-github.md | 18 +++ .../AllocationsBenchmark-report-github.md | 19 +++ src/Serilog/Core/IScalarConversionPolicy.cs | 3 +- src/Serilog/Parameters/DepthLimiter.cs | 42 ++++-- .../Parameters/PropertyValueConverter.cs | 141 +++++++++++------- .../ByteArrayScalarConversionPolicy.cs | 4 +- .../Policies/EnumScalarConversionPolicy.cs | 4 +- .../NullableScalarConversionPolicy.cs | 39 ----- .../Policies/SimpleScalarConversionPolicy.cs | 4 +- .../AllocationsBenchmark.cs | 107 +++++++++++++ test/Serilog.PerformanceTests/Harness.cs | 9 +- .../Serilog.PerformanceTests.csproj | 22 ++- .../xunit.runner.json | 3 + test/Serilog.Tests/Context/LogContextTests.cs | 23 +-- .../Serilog.Tests/LoggerConfigurationTests.cs | 4 +- .../Parameters/PropertyValueConverterTests.cs | 57 +++++++ test/Serilog.Tests/Serilog.Tests.csproj | 2 +- 17 files changed, 350 insertions(+), 151 deletions(-) create mode 100644 results/net46/AllocationsBenchmark-report-github.md create mode 100644 results/netcoreapp1.1/AllocationsBenchmark-report-github.md mode change 100755 => 100644 src/Serilog/Parameters/PropertyValueConverter.cs delete mode 100644 src/Serilog/Policies/NullableScalarConversionPolicy.cs create mode 100644 test/Serilog.PerformanceTests/AllocationsBenchmark.cs create mode 100644 test/Serilog.PerformanceTests/xunit.runner.json diff --git a/results/net46/AllocationsBenchmark-report-github.md b/results/net46/AllocationsBenchmark-report-github.md new file mode 100644 index 000000000..d40893e56 --- /dev/null +++ b/results/net46/AllocationsBenchmark-report-github.md @@ -0,0 +1,18 @@ +``` ini + +BenchmarkDotNet=v0.10.6, OS=Windows 10 Redstone 1 (10.0.14393) +Processor=Intel Core i7-4790 CPU 3.60GHz (Haswell), ProcessorCount=8 +Frequency=3507500 Hz, Resolution=285.1033 ns, Timer=TSC + [Host] : Clr 4.0.30319.42000, 32bit LegacyJIT-v4.7.2053.0 + DefaultJob : Clr 4.0.30319.42000, 32bit LegacyJIT-v4.7.2053.0 + + +``` + | Method | Mean | Error | StdDev | Scaled | ScaledSD | Gen 0 | Allocated | + |--------------------- |-------------:|-----------:|-----------:|-------:|---------:|-------:|----------:| + | LogEmpty | 9.749 ns | 0.0346 ns | 0.0324 ns | 1.00 | 0.00 | - | 0 B | + | LogEmptyWithEnricher | 103.460 ns | 0.1742 ns | 0.1629 ns | 10.61 | 0.04 | 0.0066 | 28 B | + | LogScalar | 478.723 ns | 0.6996 ns | 0.6201 ns | 49.11 | 0.17 | 0.0591 | 248 B | + | LogDictionary | 3,867.137 ns | 13.5751 ns | 12.6982 ns | 396.67 | 1.79 | 0.3128 | 1324 B | + | LogSequence | 1,309.241 ns | 1.4345 ns | 1.3418 ns | 134.30 | 0.45 | 0.1144 | 484 B | + | LogAnonymous | 6,128.421 ns | 11.3529 ns | 10.6195 ns | 628.62 | 2.28 | 0.4654 | 1960 B | diff --git a/results/netcoreapp1.1/AllocationsBenchmark-report-github.md b/results/netcoreapp1.1/AllocationsBenchmark-report-github.md new file mode 100644 index 000000000..369846ee3 --- /dev/null +++ b/results/netcoreapp1.1/AllocationsBenchmark-report-github.md @@ -0,0 +1,19 @@ +``` ini + +BenchmarkDotNet=v0.10.6, OS=Windows 10 Redstone 1 (10.0.14393) +Processor=Intel Core i7-4790 CPU 3.60GHz (Haswell), ProcessorCount=8 +Frequency=3507500 Hz, Resolution=285.1033 ns, Timer=TSC +dotnet cli version=2.0.0-preview1-005977 + [Host] : .NET Core 4.6.25211.01, 64bit RyuJIT + DefaultJob : .NET Core 4.6.25211.01, 64bit RyuJIT + + +``` + | Method | Mean | Error | StdDev | Scaled | ScaledSD | Gen 0 | Allocated | + |--------------------- |-------------:|-----------:|-----------:|-------:|---------:|-------:|----------:| + | LogEmpty | 8.652 ns | 0.0230 ns | 0.0215 ns | 1.00 | 0.00 | - | 0 B | + | LogEmptyWithEnricher | 104.790 ns | 0.4970 ns | 0.4405 ns | 12.11 | 0.06 | 0.0132 | 56 B | + | LogScalar | 432.424 ns | 0.6263 ns | 0.5858 ns | 49.98 | 0.14 | 0.1030 | 432 B | + | LogDictionary | 3,887.068 ns | 4.4649 ns | 3.7284 ns | 449.26 | 1.16 | 0.5417 | 2296 B | + | LogSequence | 1,428.896 ns | 3.6324 ns | 3.2200 ns | 165.15 | 0.53 | 0.2079 | 880 B | + | LogAnonymous | 6,694.431 ns | 22.4848 ns | 21.0323 ns | 773.73 | 3.00 | 0.8392 | 3528 B | diff --git a/src/Serilog/Core/IScalarConversionPolicy.cs b/src/Serilog/Core/IScalarConversionPolicy.cs index f4e9ed2b5..a7fd7466a 100644 --- a/src/Serilog/Core/IScalarConversionPolicy.cs +++ b/src/Serilog/Core/IScalarConversionPolicy.cs @@ -12,9 +12,8 @@ interface IScalarConversionPolicy /// If supported, convert the provided value into an immutable scalar. /// /// The value to convert. - /// Recursively apply policies to convert additional values. /// The converted value, or null. /// True if the value could be converted under this policy. - bool TryConvertToScalar(object value, ILogEventPropertyValueFactory propertyValueFactory, out ScalarValue result); + bool TryConvertToScalar(object value, out ScalarValue result); } } \ No newline at end of file diff --git a/src/Serilog/Parameters/DepthLimiter.cs b/src/Serilog/Parameters/DepthLimiter.cs index e51b23794..6785198ab 100644 --- a/src/Serilog/Parameters/DepthLimiter.cs +++ b/src/Serilog/Parameters/DepthLimiter.cs @@ -1,4 +1,4 @@ -// Copyright 2013-2015 Serilog Contributors +// Copyright 2013-2017 Serilog Contributors // // Licensed under the Apache License, Version 2.0 (the "License"); // you may not use this file except in compliance with the License. @@ -12,6 +12,8 @@ // See the License for the specific language governing permissions and // limitations under the License. +using System; + using Serilog.Core; using Serilog.Debugging; using Serilog.Events; @@ -23,32 +25,50 @@ partial class PropertyValueConverter { class DepthLimiter : ILogEventPropertyValueFactory { + [ThreadStatic] + static int _currentDepth; + readonly int _maximumDestructuringDepth; - readonly int _currentDepth; readonly PropertyValueConverter _propertyValueConverter; - public DepthLimiter(int currentDepth, int maximumDepth, PropertyValueConverter propertyValueConverter) + public DepthLimiter(int maximumDepth, PropertyValueConverter propertyValueConverter) { _maximumDestructuringDepth = maximumDepth; - _currentDepth = currentDepth; _propertyValueConverter = propertyValueConverter; } + public void SetCurrentDepth(int depth) + { + _currentDepth = depth; + } + public LogEventPropertyValue CreatePropertyValue(object value, Destructuring destructuring) { - return DefaultIfMaximumDepth() ?? - _propertyValueConverter.CreatePropertyValue(value, destructuring, _currentDepth + 1); + var storedDepth = _currentDepth; + + var result = DefaultIfMaximumDepth(storedDepth) ?? + _propertyValueConverter.CreatePropertyValue(value, destructuring, storedDepth + 1); + + _currentDepth = storedDepth; + + return result; } - public LogEventPropertyValue CreatePropertyValue(object value, bool destructureObjects = false) + LogEventPropertyValue ILogEventPropertyValueFactory.CreatePropertyValue(object value, bool destructureObjects) { - return DefaultIfMaximumDepth() ?? - _propertyValueConverter.CreatePropertyValue(value, destructureObjects, _currentDepth + 1); + var storedDepth = _currentDepth; + + var result = DefaultIfMaximumDepth(storedDepth) ?? + _propertyValueConverter.CreatePropertyValue(value, destructureObjects, storedDepth + 1); + + _currentDepth = storedDepth; + + return result; } - LogEventPropertyValue DefaultIfMaximumDepth() + LogEventPropertyValue DefaultIfMaximumDepth(int depth) { - if (_currentDepth == _maximumDestructuringDepth) + if (depth == _maximumDestructuringDepth) { SelfLog.WriteLine("Maximum destructuring depth reached."); return new ScalarValue(null); diff --git a/src/Serilog/Parameters/PropertyValueConverter.cs b/src/Serilog/Parameters/PropertyValueConverter.cs old mode 100755 new mode 100644 index 657836dba..325799a63 --- a/src/Serilog/Parameters/PropertyValueConverter.cs +++ b/src/Serilog/Parameters/PropertyValueConverter.cs @@ -1,4 +1,4 @@ -// Copyright 2013-2015 Serilog Contributors +// Copyright 2013-2017 Serilog Contributors // // Licensed under the Apache License, Version 2.0 (the "License"); // you may not use this file except in compliance with the License. @@ -45,7 +45,7 @@ partial class PropertyValueConverter : ILogEventPropertyFactory, ILogEventProper readonly IDestructuringPolicy[] _destructuringPolicies; readonly IScalarConversionPolicy[] _scalarConversionPolicies; - readonly int _maximumDestructuringDepth; + readonly DepthLimiter _depthLimiter; readonly int _maximumStringLength; readonly int _maximumCollectionCount; readonly bool _propagateExceptions; @@ -63,8 +63,7 @@ public PropertyValueConverter( if (maximumDestructuringDepth < 0) throw new ArgumentOutOfRangeException(nameof(maximumDestructuringDepth)); if (maximumStringLength < 2) throw new ArgumentOutOfRangeException(nameof(maximumStringLength)); if (maximumCollectionCount < 1) throw new ArgumentOutOfRangeException(nameof(maximumCollectionCount)); - - _maximumDestructuringDepth = maximumDestructuringDepth; + _propagateExceptions = propagateExceptions; _maximumStringLength = maximumStringLength; _maximumCollectionCount = maximumCollectionCount; @@ -72,7 +71,6 @@ public PropertyValueConverter( _scalarConversionPolicies = new IScalarConversionPolicy[] { new SimpleScalarConversionPolicy(BuiltInScalarTypes.Concat(additionalScalarTypes)), - new NullableScalarConversionPolicy(), new EnumScalarConversionPolicy(), new ByteArrayScalarConversionPolicy() }; @@ -84,6 +82,8 @@ public PropertyValueConverter( new ReflectionTypesScalarDestructuringPolicy() }) .ToArray(); + + _depthLimiter = new DepthLimiter(maximumDestructuringDepth, this); } public LogEventProperty CreateProperty(string name, object value, bool destructureObjects = false) @@ -134,21 +134,19 @@ LogEventPropertyValue CreatePropertyValue(object value, Destructuring destructur } var valueType = value.GetType(); - var limiter = new DepthLimiter(depth, _maximumDestructuringDepth, this); + _depthLimiter.SetCurrentDepth(depth); if (destructuring == Destructuring.Destructure) { - var stringValue = value as string; - if (stringValue != null) + if (value is string stringValue) { value = TruncateIfNecessary(stringValue); } } foreach (var scalarConversionPolicy in _scalarConversionPolicies) - { - ScalarValue converted; - if (scalarConversionPolicy.TryConvertToScalar(value, limiter, out converted)) + { + if (scalarConversionPolicy.TryConvertToScalar(value, out var converted)) return converted; } @@ -156,37 +154,26 @@ LogEventPropertyValue CreatePropertyValue(object value, Destructuring destructur { foreach (var destructuringPolicy in _destructuringPolicies) { - LogEventPropertyValue result; - if (destructuringPolicy.TryDestructure(value, limiter, out result)) + if (destructuringPolicy.TryDestructure(value, _depthLimiter, out var result)) return result; } } - if (TryConvertEnumerable(value, destructuring, valueType, limiter, out var enumerableResult)) + if (TryConvertEnumerable(value, destructuring, valueType, out var enumerableResult)) return enumerableResult; - if (TryConvertValueTuple(value, destructuring, valueType, limiter, out var tupleResult)) + if (TryConvertValueTuple(value, destructuring, valueType, out var tupleResult)) return tupleResult; - if (destructuring == Destructuring.Destructure) - { - var type = value.GetType(); - var typeTag = type.Name; - if (typeTag.Length <= 0 || IsCompilerGeneratedType(type)) - { - typeTag = null; - } - - return new StructureValue(GetProperties(value, limiter), typeTag); - } + if (TryConvertCompilerGeneratedType(value, destructuring, valueType, out var compilerGeneratedResult)) + return compilerGeneratedResult; return new ScalarValue(value.ToString()); - } + } - bool TryConvertEnumerable(object value, Destructuring destructuring, Type valueType, DepthLimiter limiter, out LogEventPropertyValue result) + bool TryConvertEnumerable(object value, Destructuring destructuring, Type valueType, out LogEventPropertyValue result) { - var enumerable = value as IEnumerable; - if (enumerable != null) + if (value is IEnumerable enumerable) { // Only dictionaries with 'scalar' keys are permitted, as // more complex keys may not serialize to unique values for @@ -196,35 +183,54 @@ bool TryConvertEnumerable(object value, Destructuring destructuring, Type valueT // Only actual dictionaries are supported, as arbitrary types // can implement multiple IDictionary interfaces and thus introduce // multiple different interpretations. - if (IsValueTypeDictionary(valueType)) + if (TryGetDictionary(value, valueType, out var dictionary)) { - var typeInfo = typeof(KeyValuePair<,>).MakeGenericType(valueType.GenericTypeArguments).GetTypeInfo(); - var keyProperty = typeInfo.GetDeclaredProperty("Key"); - var valueProperty = typeInfo.GetDeclaredProperty("Value"); - - result = new DictionaryValue(enumerable - .Cast() - .Take(_maximumCollectionCount) - .Select(kvp => new KeyValuePair( - (ScalarValue) limiter.CreatePropertyValue(keyProperty.GetValue(kvp), destructuring), - limiter.CreatePropertyValue(valueProperty.GetValue(kvp), destructuring))) - .Where(kvp => kvp.Key.Value != null)); + result = new DictionaryValue(MapToDictionaryElements(dictionary, destructuring)); return true; - } - result = new SequenceValue(enumerable - .Cast() - .Take(_maximumCollectionCount) - .Select(o => limiter.CreatePropertyValue(o, destructuring))); + IEnumerable> MapToDictionaryElements(IDictionary dictionaryEntries, Destructuring destructure) + { + var count = 0; + foreach (DictionaryEntry entry in dictionaryEntries) + { + if (++count > _maximumCollectionCount) + { + yield break; + } + + var pair = new KeyValuePair( + (ScalarValue)_depthLimiter.CreatePropertyValue(entry.Key, destructure), + _depthLimiter.CreatePropertyValue(entry.Value, destructure)); + + if (pair.Key.Value != null) + yield return pair; + } + } + } + result = new SequenceValue(MapToSequenceElements(enumerable, destructuring)); return true; + + IEnumerable MapToSequenceElements(IEnumerable sequence, Destructuring destructure) + { + var count = 0; + foreach (var element in sequence) + { + if (++count > _maximumCollectionCount) + { + yield break; + } + + yield return _depthLimiter.CreatePropertyValue(element, destructure); + } + } } result = null; return false; } - static bool TryConvertValueTuple(object value, Destructuring destructuring, Type valueType, DepthLimiter limiter, out LogEventPropertyValue result) + bool TryConvertValueTuple(object value, Destructuring destructuring, Type valueType, out LogEventPropertyValue result) { if (!(value is IStructuralEquatable && valueType.IsConstructedGenericType)) { @@ -254,7 +260,7 @@ static bool TryConvertValueTuple(object value, Destructuring destructuring, Type if (field.IsPublic && !field.IsStatic) { var fieldValue = field.GetValue(value); - var propertyValue = limiter.CreatePropertyValue(fieldValue, destructuring); + var propertyValue = _depthLimiter.CreatePropertyValue(fieldValue, destructuring); elements.Add(propertyValue); } } @@ -267,6 +273,24 @@ static bool TryConvertValueTuple(object value, Destructuring destructuring, Type return false; } + bool TryConvertCompilerGeneratedType(object value, Destructuring destructuring, Type valueType, out LogEventPropertyValue result) + { + if (destructuring == Destructuring.Destructure) + { + var typeTag = valueType.Name; + if (typeTag.Length <= 0 || IsCompilerGeneratedType(valueType)) + { + typeTag = null; + } + + result = new StructureValue(GetProperties(value), typeTag); + return true; + } + + result = null; + return false; + } + LogEventPropertyValue Stringify(object value) { var stringified = value.ToString(); @@ -284,11 +308,18 @@ string TruncateIfNecessary(string text) return text; } - bool IsValueTypeDictionary(Type valueType) + bool TryGetDictionary(object value, Type valueType, out IDictionary dictionary) { - return valueType.IsConstructedGenericType && - valueType.GetGenericTypeDefinition() == typeof (Dictionary<,>) && - IsValidDictionaryKeyType(valueType.GenericTypeArguments[0]); + if (valueType.IsConstructedGenericType && + valueType.GetGenericTypeDefinition() == typeof(Dictionary<,>) && + IsValidDictionaryKeyType(valueType.GenericTypeArguments[0])) + { + dictionary = (IDictionary)value; + return true; + } + + dictionary = null; + return false; } bool IsValidDictionaryKeyType(Type valueType) @@ -297,7 +328,7 @@ bool IsValidDictionaryKeyType(Type valueType) valueType.GetTypeInfo().IsEnum; } - IEnumerable GetProperties(object value, ILogEventPropertyValueFactory recursive) + IEnumerable GetProperties(object value) { foreach (var prop in value.GetType().GetPropertiesRecursive()) { @@ -322,7 +353,7 @@ IEnumerable GetProperties(object value, ILogEventPropertyValue propValue = "The property accessor threw an exception: " + ex.InnerException.GetType().Name; } - yield return new LogEventProperty(prop.Name, recursive.CreatePropertyValue(propValue, true)); + yield return new LogEventProperty(prop.Name, _depthLimiter.CreatePropertyValue(propValue, Destructuring.Destructure)); } } diff --git a/src/Serilog/Policies/ByteArrayScalarConversionPolicy.cs b/src/Serilog/Policies/ByteArrayScalarConversionPolicy.cs index d0180eaf8..38504f9cc 100644 --- a/src/Serilog/Policies/ByteArrayScalarConversionPolicy.cs +++ b/src/Serilog/Policies/ByteArrayScalarConversionPolicy.cs @@ -1,4 +1,4 @@ -// Copyright 2013-2015 Serilog Contributors +// Copyright 2013-2017 Serilog Contributors // // Licensed under the Apache License, Version 2.0 (the "License"); // you may not use this file except in compliance with the License. @@ -25,7 +25,7 @@ class ByteArrayScalarConversionPolicy : IScalarConversionPolicy { const int MaximumByteArrayLength = 1024; - public bool TryConvertToScalar(object value, ILogEventPropertyValueFactory propertyValueFactory, out ScalarValue result) + public bool TryConvertToScalar(object value, out ScalarValue result) { var bytes = value as byte[]; if (bytes == null) diff --git a/src/Serilog/Policies/EnumScalarConversionPolicy.cs b/src/Serilog/Policies/EnumScalarConversionPolicy.cs index 2a215cba4..ebb59a7de 100644 --- a/src/Serilog/Policies/EnumScalarConversionPolicy.cs +++ b/src/Serilog/Policies/EnumScalarConversionPolicy.cs @@ -1,4 +1,4 @@ -// Copyright 2013-2015 Serilog Contributors +// Copyright 2013-2017 Serilog Contributors // // Licensed under the Apache License, Version 2.0 (the "License"); // you may not use this file except in compliance with the License. @@ -20,7 +20,7 @@ namespace Serilog.Policies { class EnumScalarConversionPolicy : IScalarConversionPolicy { - public bool TryConvertToScalar(object value, ILogEventPropertyValueFactory propertyValueFactory, out ScalarValue result) + public bool TryConvertToScalar(object value, out ScalarValue result) { if (value.GetType().GetTypeInfo().IsEnum) { diff --git a/src/Serilog/Policies/NullableScalarConversionPolicy.cs b/src/Serilog/Policies/NullableScalarConversionPolicy.cs deleted file mode 100644 index e4a19f138..000000000 --- a/src/Serilog/Policies/NullableScalarConversionPolicy.cs +++ /dev/null @@ -1,39 +0,0 @@ -// Copyright 2013-2015 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.Core; -using Serilog.Events; - -namespace Serilog.Policies -{ - class NullableScalarConversionPolicy : IScalarConversionPolicy - { - public bool TryConvertToScalar(object value, ILogEventPropertyValueFactory propertyValueFactory, out ScalarValue result) - { - var type = value.GetType(); - if (!type.IsConstructedGenericType || type.GetGenericTypeDefinition() != typeof(Nullable<>)) - { - result = null; - return false; - } - - var targetType = type.GenericTypeArguments[0]; - - var innerValue = Convert.ChangeType(value, targetType); - result = propertyValueFactory.CreatePropertyValue(innerValue) as ScalarValue; - return result != null; - } - } -} diff --git a/src/Serilog/Policies/SimpleScalarConversionPolicy.cs b/src/Serilog/Policies/SimpleScalarConversionPolicy.cs index 4a87b6d4f..56c599848 100644 --- a/src/Serilog/Policies/SimpleScalarConversionPolicy.cs +++ b/src/Serilog/Policies/SimpleScalarConversionPolicy.cs @@ -1,4 +1,4 @@ -// Copyright 2013-2015 Serilog Contributors +// Copyright 2013-2017 Serilog Contributors // // Licensed under the Apache License, Version 2.0 (the "License"); // you may not use this file except in compliance with the License. @@ -28,7 +28,7 @@ public SimpleScalarConversionPolicy(IEnumerable scalarTypes) _scalarTypes = new HashSet(scalarTypes); } - public bool TryConvertToScalar(object value, ILogEventPropertyValueFactory propertyValueFactory, out ScalarValue result) + public bool TryConvertToScalar(object value, out ScalarValue result) { if (_scalarTypes.Contains(value.GetType())) { diff --git a/test/Serilog.PerformanceTests/AllocationsBenchmark.cs b/test/Serilog.PerformanceTests/AllocationsBenchmark.cs new file mode 100644 index 000000000..1805e01b4 --- /dev/null +++ b/test/Serilog.PerformanceTests/AllocationsBenchmark.cs @@ -0,0 +1,107 @@ +using Serilog.Events; +using Serilog.Parsing; +using Serilog.Core.Enrichers; + +using System; +using System.Linq; +using System.Collections.Generic; + +using BenchmarkDotNet.Attributes; + +namespace Serilog.PerformanceTests +{ + [MemoryDiagnoser] + public class AllocationsBenchmark + { + readonly ILogger _logger; + readonly ILogger _enrichedLogger; + readonly LogEvent _emptyEvent; + readonly object _dictionaryValue; + readonly object _anonymousObject; + readonly object _sequence; + + public AllocationsBenchmark() + { + _logger = new LoggerConfiguration().CreateLogger(); + + _enrichedLogger = _logger.ForContext(new PropertyEnricher("Prop", "Value")); + + _emptyEvent = new LogEvent( + DateTimeOffset.Now, + LogEventLevel.Information, + null, + new MessageTemplate(Enumerable.Empty()), + Enumerable.Empty()); + + _anonymousObject = new + { + Level11 = "Val1", + Level12 = new + { + Level21 = (int?)42, + Level22 = new + { + Level31 = System.Reflection.BindingFlags.FlattenHierarchy, + Level32 = new + { + X = 3, + Y = "4", + Z = (short?)5 + } + } + } + }; + + _dictionaryValue = new Dictionary { + { "Level11", "Val1" }, + { "Level12", new Dictionary() { + { "Level21", (int?)42 }, + { "Level22", new Dictionary() { + { "Level31", System.Reflection.BindingFlags.FlattenHierarchy }, + { "Level32", new { X = 3, Y = "4", Z = (short?)5 } } + } + } + } + } + }; + + _sequence = new List { "1", 2, (int?)3, "4", (short)5 }; + } + + [Benchmark(Baseline = true)] + public void LogEmpty() + { + _logger.Write(_emptyEvent); + } + + [Benchmark] + public void LogEmptyWithEnricher() + { + _enrichedLogger.Write(_emptyEvent); + } + + [Benchmark] + public void LogScalar() + { + _logger.Information("Template: {ScalarValue}", "42"); + } + + [Benchmark] + public void LogDictionary() + { + _logger.Information("Template: {DictionaryValue}", _dictionaryValue); + } + + [Benchmark] + public void LogSequence() + { + _logger.Information("Template: {SequenceValue}", _sequence); + } + + [Benchmark] + public void LogAnonymous() + { + _logger.Information("Template: {@AnonymousObject}.", _anonymousObject); + } + } +} diff --git a/test/Serilog.PerformanceTests/Harness.cs b/test/Serilog.PerformanceTests/Harness.cs index 72d32eef4..dd283c70f 100644 --- a/test/Serilog.PerformanceTests/Harness.cs +++ b/test/Serilog.PerformanceTests/Harness.cs @@ -1,5 +1,5 @@ -// Copyright 2013-2016 Serilog Contributors +// Copyright 2013-2017 Serilog Contributors // // Licensed under the Apache License, Version 2.0 (the "License"); // you may not use this file except in compliance with the License. @@ -20,6 +20,13 @@ namespace Serilog.PerformanceTests { public class Harness { + // dotnet test -c Release -f net46 --filter "FullyQualifiedName=Serilog.PerformanceTests.Harness.AllocationsBenchmark" + [Fact] + public void AllocationsBenchmark() + { + BenchmarkRunner.Run(); + } + [Fact] public void MessageTemplateCacheBenchmark() { diff --git a/test/Serilog.PerformanceTests/Serilog.PerformanceTests.csproj b/test/Serilog.PerformanceTests/Serilog.PerformanceTests.csproj index 9b54fe0d9..dcb0d41ae 100644 --- a/test/Serilog.PerformanceTests/Serilog.PerformanceTests.csproj +++ b/test/Serilog.PerformanceTests/Serilog.PerformanceTests.csproj @@ -1,31 +1,27 @@  - netcoreapp1.1;net452 + netcoreapp1.1;net46 Serilog.PerformanceTests ../../assets/Serilog.snk true true - Serilog.PerformanceTests - true - - $(PackageTargetFallback);dnxcore50;portable-net45+win8 - + + + + + + - - - - - - - + + diff --git a/test/Serilog.PerformanceTests/xunit.runner.json b/test/Serilog.PerformanceTests/xunit.runner.json new file mode 100644 index 000000000..34b2fe2cd --- /dev/null +++ b/test/Serilog.PerformanceTests/xunit.runner.json @@ -0,0 +1,3 @@ +{ + "shadowCopy": false +} \ No newline at end of file diff --git a/test/Serilog.Tests/Context/LogContextTests.cs b/test/Serilog.Tests/Context/LogContextTests.cs index 4809f2bff..1020d439b 100644 --- a/test/Serilog.Tests/Context/LogContextTests.cs +++ b/test/Serilog.Tests/Context/LogContextTests.cs @@ -192,32 +192,13 @@ public async Task ContextPropertiesCrossAsyncCalls() #if APPDOMAIN // Must not actually try to pass context across domains, // since user property types may not be serializable. - [Fact(Skip = "Needs to be updated for dotnet runner.")] + [Fact] public void DoesNotPreventCrossDomainCalls() { - var projectRoot = Environment.CurrentDirectory; - while (!File.Exists(Path.Combine(projectRoot, "global.json"))) - { - projectRoot = Directory.GetParent(projectRoot).FullName; - } - AppDomain domain = null; try { - const string configuration = -#if DEBUG - "Debug"; -#else - "Release"; -#endif - - var domaininfo = new AppDomainSetup - { - ApplicationBase = projectRoot, - PrivateBinPath = @"test\Serilog.Tests\bin\Debug\net452\win7-x64".Replace("Debug", configuration) - }; - var evidence = AppDomain.CurrentDomain.Evidence; - domain = AppDomain.CreateDomain("LogContextTest", evidence, domaininfo); + domain = AppDomain.CreateDomain("LogContextTests", null, AppDomain.CurrentDomain.SetupInformation); var callable = (RemotelyCallable)domain.CreateInstanceAndUnwrap(typeof(RemotelyCallable).Assembly.FullName, typeof(RemotelyCallable).FullName); diff --git a/test/Serilog.Tests/LoggerConfigurationTests.cs b/test/Serilog.Tests/LoggerConfigurationTests.cs index c757a2dfd..61808a6aa 100644 --- a/test/Serilog.Tests/LoggerConfigurationTests.cs +++ b/test/Serilog.Tests/LoggerConfigurationTests.cs @@ -268,10 +268,10 @@ public void MaximumDestructuringDepthIsEffective() } }; - var xs = LogAndGetAsString(x, conf => conf.Destructure.ToMaximumStringLength(3), "@"); + var xs = LogAndGetAsString(x, conf => conf.Destructure.ToMaximumDepth(3), "@"); Assert.Contains("C", xs); - Assert.DoesNotContain(xs, "D"); + Assert.DoesNotContain("D", xs); } [Fact] diff --git a/test/Serilog.Tests/Parameters/PropertyValueConverterTests.cs b/test/Serilog.Tests/Parameters/PropertyValueConverterTests.cs index 3728fb0a2..732b737ad 100644 --- a/test/Serilog.Tests/Parameters/PropertyValueConverterTests.cs +++ b/test/Serilog.Tests/Parameters/PropertyValueConverterTests.cs @@ -1,7 +1,11 @@ using System; using System.Collections.Generic; using System.Linq; +using System.Threading.Tasks; +using System.Threading; + using Xunit; + using Serilog.Core; using Serilog.Events; using Serilog.Parameters; @@ -17,6 +21,59 @@ public class PropertyValueConverterTests readonly PropertyValueConverter _converter = new PropertyValueConverter(10, 1000, 1000, Enumerable.Empty(), Enumerable.Empty(), false); + [Fact] + public async Task MaximumDepthIsEffectiveAndThreadSafe() + { + var _converter = new PropertyValueConverter(3, 1000, 1000, Enumerable.Empty(), Enumerable.Empty(), false); + + var barrier = new Barrier(participantCount: 3); + + var t1 = + Task.Run(() => DoThreadTest(new { Root = new { B = new { C = new { D = new { E = "F" } } } } }, + result => + { + Assert.Contains("B", result); + Assert.Contains("C", result); + Assert.DoesNotContain("D", result); + Assert.DoesNotContain("E", result); + })); + + var t2 = + Task.Run(() => DoThreadTest(new { Root = new { Y = new { Z = "5" } } }, + result => + { + Assert.Contains("Y", result); + Assert.Contains("Z", result); + })); + + var t3 = + Task.Run(() => DoThreadTest(new { Root = new { M = new { N = new { V = 8 } } } }, + result => + { + Assert.Contains("M", result); + Assert.Contains("N", result); + Assert.DoesNotContain("V", result); + })); + + await Task.WhenAll(t1, t2, t3); + + void DoThreadTest(object logObject, Action assertAction) + { + for (var i = 0; i < 100; ++i) + { + barrier.SignalAndWait(); + + var propValue = _converter.CreatePropertyValue(logObject, true); + + Assert.IsType(propValue); + + var result = ((StructureValue)propValue).Properties.SingleOrDefault(p => p.Name == "Root")?.Value?.ToString(); + + assertAction.Invoke(result); + } + } + } + [Fact] public void UnderDestructuringAByteArrayIsAScalarValue() { diff --git a/test/Serilog.Tests/Serilog.Tests.csproj b/test/Serilog.Tests/Serilog.Tests.csproj index c6ff91916..1c0981998 100644 --- a/test/Serilog.Tests/Serilog.Tests.csproj +++ b/test/Serilog.Tests/Serilog.Tests.csproj @@ -30,7 +30,7 @@ $(DefineConstants);APPDOMAIN;REMOTING;GETCURRENTMETHOD - $(DefineConstants);ASYNCLOCAL;GETCURRENTMETHOD + $(DefineConstants);APPDOMAIN;ASYNCLOCAL;GETCURRENTMETHOD