Options for controlling Destructuring of request object

Question

I've run into a problem that I'm struggling to find a clean solution for, and Googling has not made me any wiser.

The situation

(1) We have our own assembly for setting up and adding a Serilog logger to any of our projects (consistent logging output, theme, etc) and this assembly has no references to any of the consuming projects (which are in different repos). Let's call this the CompanySerilog assembly.

(2) One of the consuming projects is an externally accessible API, for which the 'contract' objects are defined in an ExternalContracts assembly. i.e. the request and response objects, and any enums used as part of those objects. This ExternalContracts assembly can be given to developers integrating against the API.

(3) We want to log all requests, and use an IActionFilter to log out each request object using the Serilog structured logging approach. e.g. looping over each parameter in the context and ultimately doing a _logger.LogDebug("With {name} of {@requestObject}", name, value);

The problem

Some request objects have sensitive data which we want to mask but:

• We could define the method of destructure when creating the logger in CompanySerilog using the standard .Destructure extension, but don't know, or want to know, the specifics of the request objects because those might be from Api1, Api2 etc and this would mean adding a reference to every consuming project.
• We could add attributes to our request objects (Destructurama.Attributed) but that would mean our ExternalContracts assembly would now need a reference to that NuGet package, which in turn requires references to all the necessary Serilog packages. Strictly speaking logging concerns should not be needed in the ExternalContracts assembly: that is our problem not the consumer of our API

As I say, I've been struggling to come up with ways to solve this and can't find much in the way of information on using, for example, IDestructuringPolicy and whether it is even appropriate, or whether transformations should come into play. So far I can only think of the following options but I'm hoping someone else has run into this problem and has a wickedly clever and clean way of supporting this use-case.

Solutions?

• Stop doing structured logging and just define a ToString() for each request object that masks out values we don't want to log. This is simple, doesn't require nasty project cross-references or adding logging concerns into an external contract. But it does mean no structured logging is possible.

• Add all the needed logging references into the external contract. This would allow us to continue using in-built destruction, but means consumers of our API would have an ExternalContracts assembly that included logging assemblies

• Set up .Destructure values when configuring logging in CompanySerilog by referencing every project that will consume this assembly. Aint gonna happen!

• Something else? Please!

Answer 1

We came up with two potential solutions, which I'll share in case anyone runs into a similar problem - both involve using IDestructuringPolicy.

Solution 1

Have a single generic IDestructuringPolicy in the CompanySerilog assembly.

public class SensitiveDataDestructuringPolicy : IDestructuringPolicy
    {
        public bool TryDestructure(object value, ILogEventPropertyValueFactory propertyValueFactory, out LogEventPropertyValue result)
        {
            var props = value.GetType().GetTypeInfo().DeclaredProperties;
            var logEventProperties = new List<LogEventProperty>();

            foreach (var propertyInfo in props)
            {
                switch (propertyInfo.Name.ToLower())
                {
                    case "cardnumber":
                    case "password":
                        logEventProperties.Add(new LogEventProperty(propertyInfo.Name,propertyValueFactory.CreatePropertyValue("***")));
                        break;
                    default:
                        logEventProperties.Add(new LogEventProperty(propertyInfo.Name, propertyValueFactory.CreatePropertyValue(propertyInfo.GetValue(value))));
                        break;
                }

            }
            result = new StructureValue(logEventProperties);
            return true;
        }
    }

and when setting up the logger, use the following kind of configuration:

var logger = new LoggerConfiguration()
// snipped out all the other things that need configuring
// ...
.Destructure.With<SensitiveDataDestructuringPolicy>
.CreateLogger();

The pros of this approach:

• One place (in the logging assembly) responsible for deciding how to log objects, without knowing what types those objects will be

The cons of this approach:

• This will reflect over every property of every object, which is overkill if there are only one or two objects that need to be masked

In the end we went for a different approach, because of the cons of the first solution.

Solution 2

Have the method in CompanySerilog that creates the logger look for IDestructuringPolicies in whichever assembly is using it.

public static ILogger Create()
{
    var destructuringPolicies = GetAllDestructuringPolicies();

    var logger = new LoggerConfiguration()
    // snipped out all the other things that need configuring
    // ...
    .Destructure.With(destructuringPolicies)
    .CreateLogger();

    //Set the static instance of Serilog.Log with the same config
    Log.Logger = logger;

    logger.Debug($"Found {destructuringPolicies.Length} destructuring policies");
    return logger;
}

/// <summary>
/// Finds all classes that implement IDestructuringPolicy, in the assembly that is calling this 
/// </summary>
/// <returns></returns>
private static IDestructuringPolicy[] GetAllDestructuringPolicies()
{
    var policies = Assembly.GetEntryAssembly().GetTypes().Where(x => typeof(IDestructuringPolicy).IsAssignableFrom(x));
    var instances = policies.Select(x => (IDestructuringPolicy)Activator.CreateInstance(x));
    return instances.ToArray();
}

Now any consumer of this CompanySerilog assembly is responsible for defining how it wants to log sensitive data, by defining an IDestructuringPolicy for every class it cares about. For example:

public class RegisterNewUserDestructuringPolicy : IDestructuringPolicy
{
    public bool TryDestructure(object value, ILogEventPropertyValueFactory propertyValueFactory, out LogEventPropertyValue result)
    {
        var request = value as RegisterNewUserRequest;
        if (request == null)
        {
            result = null;
            return false;
        }

        var logEventProperties = new List<LogEventProperty>
            {
                new LogEventProperty(nameof(request.Claims), propertyValueFactory.CreatePropertyValue(request.Claims)),
                new LogEventProperty(nameof(request.Email), propertyValueFactory.CreatePropertyValue(request.Email)),
                new LogEventProperty(nameof(request.Password), propertyValueFactory.CreatePropertyValue("****")),
                new LogEventProperty(nameof(request.Roles), propertyValueFactory.CreatePropertyValue(request.Roles)),
                new LogEventProperty(nameof(request.UserName),
                    propertyValueFactory.CreatePropertyValue(request.UserName))
            };

        result = new StructureValue(logEventProperties);
        return true;
    }
}

The advantage of this approach over solution 1 is that we're now dealing with concrete types, and if that type has no policy then it will not be reflected over.

Answer 2

Sounds like a case for the adapter pattern. You don't want the external API to have logging concerns, and you don't want CompanySerilog to have to be aware of the special cases in your API. The best option may be to create a wrapper object which holds (temporarily) a reference to the request objects. Log the wrapper, which will only have the properties that you want to show in the log.

Since the wrapper will not hold any state besides the wrapped object, they can even be re-used via a pool to eliminate GC overhead.

Roughly:

public class Request {
  public string Username { get; set; } // log this
  public string Password { get; set; } // but not this
}

public class RequestLogWrapper {
  public Request WrappedRequest { private get; set; }
  public String Username { get { return WrappedRequest.Username; }
}

//To use:
var rlw = new RequestLogWrapper { Request = request };
logger.log("Got a request: {0}", rlw);