Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

SerilogLoggerFactory and AddProvider() infrastructure #132

Merged
merged 10 commits into from
May 21, 2019

Conversation

nblumhardt
Copy link
Member

@nblumhardt nblumhardt commented Feb 8, 2019

For #130

The Sample project uses the new LoggerProviderCollection/WriteTo.Providers() mechanism to send events back through dynamically-added providers, and providers registered in IoC.

If you run it you'll see interleaved madness, because the two console sinks aren't synchronized (not really a realistic use case):

image

Commenting out the Serilog console sink, you'll see what we end up with from the MEL console provider:

image

And commenting out AddConsole() will get you just Serilog's sink:

image

A lot is sketchy/TODO (too much to list here!), but - every log event raised through any interface, both Serilog loggers and MEL loggers, goes through the exact same (Serilog) pipeline, uses the same level controls and filters, and ends up at the same sinks/providers.

Ergonomics should be able to be improved at a higher level, in packages like Serilog.AspNetCore/the hosting equivalent.

@merbla
Copy link
Contributor

merbla commented Feb 11, 2019

Be interesting to push this thru the pipe to flush any performance implications. Should be minimal as it is representative of another sink.

@nblumhardt
Copy link
Member Author

Thanks for the 👀, @merbla.

I don't think it's ready for wider consumption just yet, there are a few things to hash out (such as how to make sure the state object we pass through to the provider is maximally useful for it), but the amount of code shouldn't be huge.

I'll have to look into whether named loggers are worth caching - not sure what the default factory does, here, but if they're cached it could turn out that providers rely on this don't optimize for frequent logger creation. A pretty good chance this will be a perf bottleneck.

@nblumhardt nblumhardt changed the title Proof-of-concept AddProvider() infrastructure SerilogLoggerFactory and AddProvider() infrastructure Mar 6, 2019
@nblumhardt
Copy link
Member Author

nblumhardt commented Mar 15, 2019

I've got this to a point now where it works with the default AddConsole() provider (shots above), with the AddSeq() provider:

image

And with the NReco.Logging.File AddFile() provider:

2019-03-15T10:54:58.4836271+10:00	INFO	[Sample.Program]	[0]	Started at 03/15/2019 00:54:58 +00:00 and 0x2A is hex of 42
2019-03-15T10:54:58.5203575+10:00	CRIT	[Sample.Program]	[0]	Unexpected critical error starting application
2019-03-15T10:54:58.5243554+10:00	CRIT	[Sample.Program]	[0]	Unexpected critical errorSystem.Exception: Boom!
   at Sample.Program.Main(String[] args)


2019-03-15T10:54:58.5253536+10:00	FAIL	[Sample.Program]	[0]	Unexpected error
2019-03-15T10:54:58.5253536+10:00	WARN	[Sample.Program]	[0]	Unexpected warning
2019-03-15T10:54:58.5303543+10:00	INFO	[Sample.Program]	[0]	Waiting for user input
2019-03-15T10:55:00.8609016+10:00	INFO	[Sample.Program]	[0]	User pressed { Key: 13, KeyChar: 
 }
2019-03-15T10:55:00.8609016+10:00	INFO	[Sample.Program]	[0]	Stopping at 03/15/2019 00:55:00 +00:00
2019-03-15T10:55:00.8609016+10:00	INFO	[Sample.Program]	[0]	Stopping
2019-03-15T10:55:00.8609016+10:00	INFO	[Sample.Program]	[0]	

2019-03-15T10:55:00.8619020+10:00	INFO	[Sample.Program]	[0]	RESULT         START TIME       END TIME   DURATION(ms)
2019-03-15T10:55:00.8619020+10:00	INFO	[Sample.Program]	[0]	------         ----- ----       --- ----   ------------
2019-03-15T10:55:00.8619020+10:00	INFO	[Sample.Program]	[0]	SUCCESS          54:58 AM        55:0 AM      2446.2364

(The sample program produces a very ugly set of logs, it goes waaay back, now - we should probably update it to something more instructive :-D )

Next up, I will:

  • Make the implementation a bit less egregiously allocatey
  • Figure out what the user experience, e.g. through helpers like UseSerilog(), should look like
  • Write some tests
  • Hook into the configuration story?

@nblumhardt
Copy link
Member Author

See e.g.: opentracing-contrib/csharp-netcore#42

@nblumhardt
Copy link
Member Author

Here's how the OpenTracing contrib provider uses the values passed in via Log(): https://github.com/opentracing-contrib/csharp-netcore/blob/master/src/OpenTracing.Contrib.NetCore/Logging/OpenTracingLogger.cs#L33

We should preserve the OriginalFormatPropertyName for full compatibility with this.

@nblumhardt
Copy link
Member Author

Turns out we were already using FormattedLogValues and thus exposing the original format string. Cleaned things up with a new SerilogLogValues type nonetheless.

There are a lot of perf gains to make, but I think this is ready to go through the wringer now to see where/how it breaks or falls short.

Marked as 3.0.0-* because I think the extended functionality here is pushing into new-major-version territory. This might be re-targeted to a MEL 3.0 release when it's done.

@nblumhardt
Copy link
Member Author

@serilog/reviewers-core anyone keen to dig in? :-)

factory.AddProvider(provider);

return factory;
});
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This provider registration functionality would need to be wrapped up by UseSerilog() in the two alternative hosting projects.

@nblumhardt
Copy link
Member Author

If no one has time to get up to speed with this, I think we'd be best off sending it to dev and iterating there. This is one part of what should be (I think) a substantial "modernization" of this lib, now that some of the dust seems to be settling around the whole logging story.

Any concerns, let me know, otherwise I'll YOLO it through in a day or two :-)

@nblumhardt nblumhardt merged commit 79127bd into serilog:dev May 21, 2019
@nblumhardt nblumhardt mentioned this pull request Aug 19, 2019
@nblumhardt nblumhardt added this to the 3.0.0 milestone Aug 20, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants