Skip to content

Commit

Permalink
Merge pull request serilog#981 from skomis-mm/less_alloc
Browse files Browse the repository at this point in the history
PropertyValueConverter improvements
  • Loading branch information
nblumhardt authored Jun 6, 2017
2 parents cfb1ef9 + e23e2bb commit e953401
Show file tree
Hide file tree
Showing 17 changed files with 350 additions and 151 deletions.
18 changes: 18 additions & 0 deletions results/net46/AllocationsBenchmark-report-github.md
Original file line number Diff line number Diff line change
@@ -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 |
19 changes: 19 additions & 0 deletions results/netcoreapp1.1/AllocationsBenchmark-report-github.md
Original file line number Diff line number Diff line change
@@ -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 |
3 changes: 1 addition & 2 deletions src/Serilog/Core/IScalarConversionPolicy.cs
Original file line number Diff line number Diff line change
Expand Up @@ -12,9 +12,8 @@ interface IScalarConversionPolicy
/// If supported, convert the provided value into an immutable scalar.
/// </summary>
/// <param name="value">The value to convert.</param>
/// <param name="propertyValueFactory">Recursively apply policies to convert additional values.</param>
/// <param name="result">The converted value, or null.</param>
/// <returns>True if the value could be converted under this policy.</returns>
bool TryConvertToScalar(object value, ILogEventPropertyValueFactory propertyValueFactory, out ScalarValue result);
bool TryConvertToScalar(object value, out ScalarValue result);
}
}
42 changes: 31 additions & 11 deletions src/Serilog/Parameters/DepthLimiter.cs
Original file line number Diff line number Diff line change
@@ -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.
Expand All @@ -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;
Expand All @@ -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);
Expand Down
141 changes: 86 additions & 55 deletions src/Serilog/Parameters/PropertyValueConverter.cs
100755 → 100644
Original file line number Diff line number Diff line change
@@ -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.
Expand Down Expand Up @@ -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;
Expand All @@ -63,16 +63,14 @@ 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;

_scalarConversionPolicies = new IScalarConversionPolicy[]
{
new SimpleScalarConversionPolicy(BuiltInScalarTypes.Concat(additionalScalarTypes)),
new NullableScalarConversionPolicy(),
new EnumScalarConversionPolicy(),
new ByteArrayScalarConversionPolicy()
};
Expand All @@ -84,6 +82,8 @@ public PropertyValueConverter(
new ReflectionTypesScalarDestructuringPolicy()
})
.ToArray();

_depthLimiter = new DepthLimiter(maximumDestructuringDepth, this);
}

public LogEventProperty CreateProperty(string name, object value, bool destructureObjects = false)
Expand Down Expand Up @@ -134,59 +134,46 @@ 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;
}

if (destructuring == Destructuring.Destructure)
{
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
Expand All @@ -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<object>()
.Take(_maximumCollectionCount)
.Select(kvp => new KeyValuePair<ScalarValue, LogEventPropertyValue>(
(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<object>()
.Take(_maximumCollectionCount)
.Select(o => limiter.CreatePropertyValue(o, destructuring)));
IEnumerable<KeyValuePair<ScalarValue, LogEventPropertyValue>> MapToDictionaryElements(IDictionary dictionaryEntries, Destructuring destructure)
{
var count = 0;
foreach (DictionaryEntry entry in dictionaryEntries)
{
if (++count > _maximumCollectionCount)
{
yield break;
}

var pair = new KeyValuePair<ScalarValue, LogEventPropertyValue>(
(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<LogEventPropertyValue> 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))
{
Expand Down Expand Up @@ -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);
}
}
Expand All @@ -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();
Expand All @@ -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)
Expand All @@ -297,7 +328,7 @@ bool IsValidDictionaryKeyType(Type valueType)
valueType.GetTypeInfo().IsEnum;
}

IEnumerable<LogEventProperty> GetProperties(object value, ILogEventPropertyValueFactory recursive)
IEnumerable<LogEventProperty> GetProperties(object value)
{
foreach (var prop in value.GetType().GetPropertiesRecursive())
{
Expand All @@ -322,7 +353,7 @@ IEnumerable<LogEventProperty> 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));
}
}

Expand Down
Loading

0 comments on commit e953401

Please sign in to comment.