jonwagner / EventSourceProxy

EventSourceProxy (ESP) is the easiest way to add scalable Event Tracing for Windows (ETW) logging to your .NET program
Other
97 stars 20 forks source link

Add a Blob-logging mode #4

Closed jonwagner closed 10 years ago

jonwagner commented 11 years ago

Best practices for logging use existing values as parameters to a method:

void EmailChanged(string old, string new);

Some event stores (like SLAB Azure storage) will create a new column for each parameter in each method. This can get unwieldy if you are logging a lot of things (which you should).

One technique for minimizing the data columns (see Issue #3) is to wrap the parameters in an object:

void EmailChanged(object data); log.EmailChanged(new { old = "foo", new = "bar" });

This works (if you enable the JSONTraceSerializer for the appropriate logging levels), but there is a small performance impact. First, the data is copied into a new temporary object, then that object is serialized to JSON.

What we want is a way to use the parameterized calls, but have the data logged as a single blob.

Most likely, this would work as follows:

Example (assume I think of better names):

interface IMyLog { void EmailChanged(string old, string new); }
var log = ESP.ImplementBlobbyLog<IMyLog>();
log.EmailChanged("foo", "bar");

Inside of ESP, we would implement:

class MyLogEventSource : EventSource, IMyLog { void IMyLog.Log(string old, string new) { base.Log(insert serialization here); } }

Comments?

pbolduc commented 11 years ago

The user may not want to have all of their parameters json serialized together. In our case, a number of methods (but not all) have a 'request id' or 'collation id' to help finding related events. General rule is if searching is required, it should be in it's own column, otherwise, create a dynamic object with various properties that give additional parameters about the event (Exception details, Request details, User details).

I have also seen EventSource classes having problems when the method parameters do not match the parameters to EventSource.WriteEvent(). The resultant EventSource implementation must be valid. Semantic Logging Block has a validator. We use this call in our unit tests to ensure the generated EventSource will work.

EventSourceAnalyzer.InspectAll(SemanticLoggingEventSource.Log);
jonwagner commented 11 years ago

You are right that the method that calls WriteEvent has to match the parameters to WriteEvent, but the interface that gets exposed to the application can be entirely different. There are a few cases where ESP already needs to handle this (e.g. automatic interface proxies).

So a better statement of your problem is that you would like to log all of the parameters, but have some of them stored in separate columns, and others stored as blobs. To me, it sounds like it would be a good idea to take that decision out of the application code and moving it to a place where you manage the logging. Then app coders would just pass in parameters.

A better example would be:

void EmailChanged(int userId, string old, string new)

A good solution would allow:

One possible design would be to attribute the interface parameters to tell ESP which parameters are which:

void EmailChanged([Searchable]int userId, [Rollup]string old, [Rollup] string new);

The proxy generator could then send userId to WriteEvent and the other parameters as a JSON object.

I could see that get extended so a provider would allow that information to get injected from a configuration or programmatically.

Another attribute-based design might allow separate rollups:

void EmailChanged(int userId, [Rollup("email")]string old, [Rollup("email")] string new);

In this case, anything without an attribute gets serialized with it's own name. Anything with a Rollup gets rolled up into the object with the given name, and the default Rollup would probably just be ("data"). This would also work nicely with a provider model.

ibebbs commented 10 years ago

If I could just drop in here...

I'm just getting to grips with EventSourceProxy and am super impressed with it so far. The ability to "promote" certain method parameters out of the serialized form and into discrete schema/payload values is about the only thing stopping us adopting this framework across our application suite.

I cloned the source to see if I could implement it but must admit I'm a little lost so far (to be fair, I was only looking for a few minutes before I found this thread). Do you see the functionality outlined above (although preferably following the "provider" model - I prefer to keep aspects separate) being implemented any time soon?

jonwagner commented 10 years ago

If I can come up with a design people like, I can probably get to it in the next week or two.

It's not a small project. You probably would have to be pretty familiar with the code. Something like (notes for me):

  1. From the interface method definition, gather up all of the parameters into the logging buckets.
  2. In the underlying class, implement a logging method with the parameters set to the buckets rather than the parameter list.
  3. In the implementation of the interface method, call the logging method, pushing the parameter or serializing the logging bucket as appropriate.
ibebbs commented 10 years ago

Sounds promising.

Rather than "rolling up" parameters into serialized/discrete parameters, my use case is more oriented to "un-rolling" or "promoting" object values into discrete schema values. I was envisaging a serialization provider that, in place of (or addition to) returning a string, returned a Dictionary<string, object> representing Schema keys and payload values.

Alternatively, how about an "inspecting" serializer to which you pass a bunch of Expression instances which inspect and return a value. The expression can be examined to evaluate a schema name and return type and compiled to quickly retrieve payload values at runtime.

For example, with an EmailChanged signature as follows:

void EmailChanged(IEmail email)

I would like to register something like:

EventSourceImplementer.RegisterProvider(new InspectingObjectSerializer( new Expression [] { source => source.UserId, source => source.Old, source => source.New } ));

And would expect to see three discrete values (prefixed by the container objects parameter name to differential multiple parameters of the same type) in the logged event; email.UserId, email.Old, email.New.

What do you think? I'd be happy to invest some time helping implement the InspectingObjectSerializer.

Cheers, Ian

jonwagner commented 10 years ago

I should be able to get some of the internal work done this week. I'll create it in a branch so you can play with it and add providers that work the way you like.

ibebbs commented 10 years ago

That's awesome, thanks Jon.

I actually have some example code ready along with a couple of unit tests which I think might help communicate my intention. If you let me know which branch you intend on commit these changes to, I'll add the appropriate files to the solution there.

Cheers, Ian

jonwagner commented 10 years ago

I made some progress today. I got the internals to the point where the mappings can be pretty dynamic.

Now I'm playing with a default provider that looks for [TraceAs("foo")] attributes on parameters and bunches them up. Once that works, I'll upload the branch so you can play with your own providers.

jonwagner commented 10 years ago

I uploaded a "Bundle" branch that has the TraceAs attribute, and the ability to add your own TraceParameterProvider. I don't think it's the final version of this code, but it's good enough to start with.

My TODO list:

jonwagner commented 10 years ago

Ian - I moved your suggestion to a new open Issue #6. It's related, but different enough that I want to track it separately.

jonwagner commented 10 years ago

I finished the work on bundling parameters.

There are a few ways you can use it:

  1. Attributes
    • [TraceAs("name")] or [TraceAsData] - the latter is equivalent to [TraceAs("data")]
    • Apply to a whole method to roll up all parameters into the given bucket.
    • Apply to an individual parameter to rename the parameter or put it with other things with the name.
  2. Provider
    • Register a TraceParameterProvider that inspects a given method and returns the bundling of the parameter.

This will be in the next major build.

And now off to working on unbundling parameters...

jonwagner commented 10 years ago

Online wiki documentation has been updated with the latest docs. See Controlling Logged Data.

jonwagner commented 10 years ago

This feature is in v2.0.

v2.0.0-alpha1 is now in nuget. Be sure to select "Include pre-release packages" to get this version.

After some final testing, I'll push out an official 2.0.