Controlling Logged Data

Controlling Logged Data

By default, ETW will log the parameters exactly as they are presented in the method signature. Sometimes you want your logging interface to have a particular signature, while your logged data needs to have a different format.

For example:

• Your method has a large number of parameters, but you only want some of them to have their own logging column, and the rest to be bundled into one field.
• Your method has an object in the parameter list, and you want to extract fields from it.
• You are proxying an existing interface, and you want to log it an entirely different way.

Since ESP implements its own EventSource and proxies your interface to it, ESP can perform some nifty mapping while it does it.

Say you have the following interface:

interface IEmailer
{
	void Send(Email email, DateTime when);
	void Receive(Email email);
	void Cancel(string from, string to, DateTime earliest, DateTime latest);
}

class Email
{
	public string From;
	public string To;
	public string Subject;
	public string Body;
	public IEnumerable<byte[]> Attachments; 
}

Let's see the different ways we can log these methods.

Controlling Logged Data Through Attributes

If you are working with logging interfaces, it may be easiest to annotate the interface methods with some attributes. Some examples:

void Cancel(
	[TraceAs("Sender")] string from, 
	[TraceAs("Recipient")] string to,
	[TraceAs("Range")] DateTime earliest, 
	[TraceAs("Range")] DateTime latest);

Here we have:

• Renamed from to Sender
• Renamed to to Recipient
• Combined earliest and latest into a Dictionary<string, string> called Range
  • The JSON serializer would serialize this as { "earliest":earliest, "latest":latest }

We can also apply the TraceAs attribute to the method itself.

[TraceAs("Data")]
void Cancel(
	[TraceAs("Sender")] string from, 
	[TraceAs("Recipient")] string to,
	DateTime earliest, 
	DateTime latest);

Here, earliest and latest are bundled together into a column called "Data", but Sender and Recipient are still separate.

TraceAs also has a Format parameter, if you need to format something special:

void MoveMoney([TraceAs(Format="$0.00")]double money);

We can also ignore parameters. Suppose we don't care when an email was sent:

void Send(Email email, [TraceIgnore] DateTime when);

Another handy thing is to extract fields directly out of objects. This is a lot easier than implementing your own custom serializer.

void Send(
	[TraceMember("From"), TraceMember("To")] Email email
	DateTime when
)

Here, we are extracting From and To out of the email and making them their own logging parameters.

We could also rename the columns as we log them:

void Send(
	[TraceMember("From", "Sender"), TraceMember("To", "Recipient")] Email email
	DateTime when
)

Now the log will contain three columns:

• Sender = from
• Recipient = to
• when = when

Controlling Logged Data Through the TraceParameterProvider

If you are using an existing interface, rather than a logging interface, you may not want to put attributes on the interface. For example, if you are proxying the IEmailer interface so you get free logging, you don't want log attributes on the interface. That code belongs somewhere else.

You can also add rules to the TraceParameterProvider to tell it how you like your data logged. The TPP has a powerful fluent interface for defining rules. Just add them at startup before you create any logging interfaces.

Here's take a common case. Every time we log an interface that takes an Email, we don't want it logged as a blob. We want to explode out the sender and recipient:

TraceParameterProvider.Default
	.ForAnything()
		.With<Email>()
			.Trace(e => e.From) 
			.Trace(e => e.To);

Let's take it apart:

• ForAnything() - this rule matches ANY interface and ANY method.
• With() - this rule matches ANY parameter of type Email.
• Trace(expression) - extract the From and To fields. ESP will look at these simple expressions and know to log them as "From" and "To". If you use a complicated expression, it won't know what to call it.

Ok, this isn't exactly what we want. Let's make a few changes.

TraceParameterProvider.Default
	.For<IEmailer>()
		.With<Email>()
			.Trace(e => e.From).As("Sender") 
			.Trace(e => e.To).As("Recipient");

We made two changes:

• For() - this rule only matches IEmailer methods
• As(alias) - renames From to Sender and To to Recipient.

Now, we also want to log the subject and the body, but we want to combine them into a dictionary:

			.Trace(e => e.Subject, e => e.Body)

If you specify more than one item in a Trace, they get combined into a dictionary. But let's say we want to rename those things:

			.Trace(e => e.Subject).As("s")
				.And(e => e.Body).As("b")
				.TogetherAs("message");

We have renamed the individual values, as well as the output parameter. This would be logged as:

message = { "s":Subject, "b":Body }

Also, we want to log the attachments as a base 64 value:

			.Trace(e => String.Join("/", e.Attachments.Select(Convert.ToBase64String).ToArray()))
				.As("attachments")

Now, by default, ESP will log any parameter that does not have a rule or a TraceIgnore attribute. We can also create an Ignore rule:

				.Ignore("when");

But we only want our ignore rule to apply to the Send method:

TraceParameterProvider.Default
	.For<IEmailer>(m => m.Send(Any<Email>.Value, Any<DateTime>.Value)
		.Ignore("when"); 

Let's put it all together:

TraceParameterProvider.Default
	.For<IEmailer>()
		.With<Email>()
			.Trace(e => e.From).As("Sender") 
			.Trace(e => e.To).As("Recipient")
			.Trace(e => e.Subject).As("s")
				.And(e => e.Body).As("b")
				.TogetherAs("message")
			.Trace(e => String.Join("/", e.Attachments.Select(Convert.ToBase64String).ToArray()))
				.As("attachments")
	.For<IEmailer>(m => m.Send(Any<Email>.Value, Any<DateTime>.Value)
		.Ignore("when"); 

So:

• ForAnything(), For(), For(method) - filters by interface or method
• With(), With(parameterName) - filters by parameter type or name
• Trace(parameterName), Trace(expression) - traces data
• As(alias), TogetherAs(alias) - let you rename outputs
• Ignore(parameterName), Ignore(), Ignore(parameterName) - let you ignore parameters

You can use these rules for lots of cool things:

• Control serialization of objects without writing your own TraceSerializationProvider
• Emit context data without writing your own TraceContextProvider.
  • See Adding Additional Logging Context

Transforming Logged Data using a custom TraceTransformAttribute

An extensible TraceTransformAttribute is also provided. You can use this attribute to define your own transformation methods which can be applied via attributes:

interface IBill
{
	void CreditCardPayment ([TraceMaskCardNumber] string cardnumber, DateTime expiration)
}

The TraceMaskCardNumber attribute could be constructed as follows:

public class TraceMaskCardNumberAttribute : TraceTransformAttribute
{		
	public override MethodInfo GetTransformMethod(Type inputType)
	{
		return GetType().GetMethod("MaskAccount");
	}

	public static string MaskAccount(string input)
	{
		return input.Substring(0, 4)  new string('x', input.Length - 4);
	}
}

The method returned by the overridden GetTransformMethod() will be invoked for each input parameter the attribute is applied to. The method must have a single input parameter whose type matches the trace parameter type the attribute is applied to. For example, if the above TraceMaskCardNumberAttribute were to be applied to a trace parameter with a type of DateTime an exception would be thrown when the parameter mappings are evaluated for the interface.

Controlling Logged Data Through a Custom TraceParameterProvider

You can also implement your own TraceParameterProvider. It would need to inspect a method and generate a set of rules that would specify the logged parameters and how to generate them.

The features above are pretty powerful, so you probably don't need to do this.