0

I have below code to prepare the logEventInfo object to log the data. I am using the Nlog. I found it is convenient to use reflection to add the name and value dynamically. But I know there is a big performance impact.

public static LogEventInfo ToLogEventInfo(this ILogItem data, string message, Exception ex = null)
        {
            var eventInfo = new LogEventInfo();

            if (ex != null)
                eventInfo.Exception = ex;

            if (data != null)
            {
                data.EventMessage = message;
                data.LogTime = TimeZoneInfo.ConvertTime(DateTime.Now, TimeZoneInfo.Utc);
                data.LogId = Guid.NewGuid();

                var properties = data.GetType().GetProperties();
                foreach (PropertyInfo property in properties) //Possibly a performance impact.
                {
                    eventInfo.Properties[property.Name] = property.GetValue(data, null);
                }
            }
            else
            {
                if (!string.IsNullOrEmpty(message))
                    eventInfo.Message = message;
            }

            return eventInfo;
        }

This ToLogEvenInfo function will be called in a loop. The data will be looped may be millions. Is there a better way to implement the below function? Thanks a lot.

wadefanyaoxia
  • 597
  • 1
  • 8
  • 21
  • 1
    You can always [race you horses](https://ericlippert.com/2012/12/17/performance-rant/) and compare it with an overload of `ToLogEventInfo` for some concrete type. – Guru Stron Apr 18 '23 at 20:55
  • 1
    _"Possibly a performance impact"_ - for sure a performance impact. The question is if it is noticable in the great scheme of things and if it affects your app or can be ignored. – Guru Stron Apr 18 '23 at 20:56
  • Also note that there are ways to mitigate this impact. For example by "caching" the reflection using some runtime compilation with expression tress, similar to what is done [here](https://stackoverflow.com/a/62454454/2501279), but without generics, just preserving some kind of `ConcurrentDictionary>` cache. – Guru Stron Apr 18 '23 at 21:00
  • Or maybe playing with some kind of json serialization. – Guru Stron Apr 18 '23 at 21:02

1 Answers1

0

Notice that NLog Jsonlayout has no issue with performing reflection, so you can just add the ILogItem to the LogEventInfo.Properties, and then use NLog JsonLayout with includeAllProperties="true" and maxRecursionLimit="1". You can also make use of ${event-properties:item=LogItem:format=@}:

  <layout type="JsonLayout" includeAllProperties="true" maxRecursionLimit="1" excludeProperties="LogItem" >
    <attribute name="Time" layout="${date:format=O}" />
    <attribute name="Level" layout="${level:upperCase=true}"/>
    <attribute name="LogItem" encode="false" layout="${event-properties:item=LogItem:format=@}" />
  </layout>

The Microsoft System.Text.Json Serializer should be fast when handling basic DTO-classes. But can explode in your face when meeting special object-values, as it expects to both serialize and deserialize all objects by default.

But if you are just interested in making the reflection a little faster, then this should work well.

static ConcurrentDictionary<Type, Func<object, IEnumerable<KeyValuePair<string, object>>> _typeProperties = new();

static IEnumerable<KeyValuePair<string, object> ResolveProperties(object value)
{
    if (!_typeProperties.TryGetValue(value.GetType(), out var propertyResolver))
    {
       var properties = value.GetType().GetProperties();

       propertyResolver = (v) => {
          foreach (PropertyInfo property in properties)
          {
             var propertyName = property.Name;
             var propertyValue = property.GetValue(v, null);
             yield new KeyValuePair<string, object>(propertyName, propertyValue);
          }
       _typeProperties.TryAdd(value.GetType(), propertyResolver);
    }
    return propertyResolver.Invoke(this);
}

You can optimize it even further by compiling property.GetValue(..) with expression-trees. Maybe something like this:


private static Func<object, object> GenerateGetterLambda(PropertyInfo property)
{
    // Define our instance parameter, which will be the input of the Func
    var objParameterExpr = Expression.Parameter(typeof(object), "instance");
    // 1. Cast the instance to the correct type
    var instanceExpr = Expression.TypeAs(objParameterExpr, property.DeclaringType);
    // 2. Call the getter and retrieve the value of the property
    var propertyExpr = Expression.Property(instanceExpr, property);
    // 3. Convert the property's value to object
    var propertyObjExpr = Expression.Convert(propertyExpr, typeof(object));
    // Create a lambda expression of the latest call & compile it
    return Expression.Lambda<Func<object, object>>(propertyObjExpr, objParameterExpr).Compile();
}

static IEnumerable<KeyValuePair<string, object> ResolveProperties(object value)
{
    if (!_typeProperties.TryGetValue(value.GetType(), out var propertyResolver))
    {
       var slowProperties = value.GetType().GetProperties();
       var fastProperties = new Func<object, object>[slowProperties.Length];
       for (int i = 0; i < slowProperties.Length; ++i)
          fastProperties = GenerateGetterLambda(slowProperties[i]);

       propertyResolver = (v) => {
          for (int i = 0; i < slowProperties.Length; ++i)
          {
             var propertyName = slowProperties[i].Name;
             var propertyValue = fastProperties[i].Invoke(v);
             yield new KeyValuePair<string, object>(propertyName, propertyValue);
          }
       _typeProperties.TryAdd(value.GetType(), propertyResolver);
    }
    return propertyResolver.Invoke(this);
}

See also: https://blog.zhaytam.com/2020/11/17/expression-trees-property-getter/

Rolf Kristensen
  • 17,785
  • 1
  • 51
  • 70
  • Thank you so much ! I am not restricted to just use the reflection. I just realize the Nlog already did reflection and I have removed my reflection. Thanks ! – wadefanyaoxia Apr 19 '23 at 19:30