New Project: Simple Logging Facade

[Colin Eberhardt]

This is a little off topic, but I just had to share ...

Philipp Sumi and myself have been working on the Simple Logging Facade
(SLF) for the past few months, and finally today we have made our
first release:

http://slf.codeplex.com/

SLF provides a simple logging framework for use in .NET applications
(including Silverlight), which can be used standalone, or as a façade
to a number of other logging frameworks (NLog, log4net, Entlib).

You can read more about SLF on Philipp's blog and codeproject:

http://www.hardcodet.net/2009/12/slf-introduction
http://www.codeproject.com/KB/trace/ArtOfLogging.aspx

Regards,
Colin E.

[Sacha Barber]

Sounds an awful lot like Daniels Clog stuff (sorry boys)

 

http://clog.codeplex.com/

--
Sacha Barber
sacha....@gmail.com

[Philipp Sumi]

Not at all. Actually, I've already been thinking about writing a Clog façade for SLF :)

[Colin Eberhardt]

Hi Sacha,

Just to expand on Philipp's response. SLF is pretty much as the name
suggests, a simple logging facade. Whereas Clog is a complex logging
facade (although a very useful one!).

Personally I am using SLF at the moment within a sore component that
is being used by a web and desktop application. The web team opted for
NLog while the desktop team opted for log4net, using SLF in the core
component means that I can defer logging framework binding until
runtime, allowing it to log to NLog or log4net when used in these two
different contexts.

Colin E.

On Dec 2, 2:56 pm, Sacha Barber <sacha.bar...@gmail.com> wrote:
> Sounds an awful lot like Daniels Clog stuff (sorry boys)
>
> http://clog.codeplex.com/
>
> On Wed, Dec 2, 2009 at 2:52 PM, Colin Eberhardt

> <colin.eberha...@gmail.com>wrote:

>
>
>
>
>
> > This is a little off topic, but I just had to share ...
>
> > Philipp Sumi and myself have been working on the Simple Logging Facade
> > (SLF) for the past few months, and finally today we have made our
> > first release:
>
> >http://slf.codeplex.com/
>
> > SLF provides a simple logging framework for use in .NET applications
> > (including Silverlight), which can be used standalone, or as a façade
> > to a number of other logging frameworks (NLog, log4net, Entlib).
>
> > You can read more about SLF on Philipp's blog and codeproject:
>
> >http://www.hardcodet.net/2009/12/slf-introduction
> >http://www.codeproject.com/KB/trace/ArtOfLogging.aspx
>
> > Regards,
> > Colin E.
>
> --
> Sacha Barber

> sacha.bar...@gmail.com

[Sacha Barber]

Yeah I jusy read up some posts on Philips site and can see where you boys are coming from.

 

I may well use this for my loggin inside of Cinch.

--
Sacha Barber
sacha....@gmail.com

[Colin Eberhardt]

In that case, I might buy you a pint ;-)

On Dec 2, 3:15 pm, Sacha Barber <sacha.bar...@gmail.com> wrote:
> Yeah I jusy read up some posts on Philips site and can see where you boys
> are coming from.
>
> I may well use this for my loggin inside of Cinch.
>
> On Wed, Dec 2, 2009 at 3:04 PM, Colin Eberhardt

> <colin.eberha...@gmail.com>wrote:

> sacha.bar...@gmail.com

[Daniel Vaughan]

Hey guys, did someone say logging. 
More logging goodness!

Ok, speaking about Clog - Clog is more complex, but easy to use and
allows one to do quite a lot: logging from Silverlight, Desktop, with
Filters, to multiple logging providers log4net entlib logging etc (at
the same time).

One thing I find critical in any logging infrastructure is to be able
to identify the origin of log messages. When using a facade, this
information can get lost. How did you guys solve that? I have two
approaches in Clog. For the Silverlight version I use a combination of
the URL and control type, for the desktop CLR I use stack frame
counting and provide a configurable skip frame count parameter.

[Peter O'Hanlon]

OT - Daniel, I'm going to be using Clog in Goldlight.

--
Peter O'Hanlon

[Philipp Sumi]

> I may well use this for my loggin inside of Cinch.

Yeah, using a façade in a library/framework is quite convenient (not necessarily SLF). You can do extensive logging, and the users of your framework just can decide what the façade should do with the messages. I'm currently working on an IO-heavy framework that does just that: Whenever something goes wrong, it requests a named logger at runtime and writes warnings and errors to it:

 

try

{

  //do crazy IO stuff

}

catch(Exception e)

{

  LoggerService.GetLogger("my-framework-name").Fatal(e, "Detailed Info");

  throw or whatever;

}

 

Per default, SLF will just discard these messages (no loggers configured at all), but the user can activate logging very easily by configuring SLF in code or app.config. Given that IO errors are pretty likely during development, this might prove pretty valuable when it comes to bug hunting :)

 

 

 

 

 

From: Sacha Barber [mailto:sacha....@gmail.com]

Sent: Mittwoch, 2. Dezember 2009 16:15
To: wpf-di...@googlegroups.com

[Daniel Vaughan]

Cool Pete. :) Clog has saved me lots of time and I use it in all my
projects.

[Colin Eberhardt]

Hi Daniel,

> One thing I find critical in any logging infrastructure is to be able
> to identify the origin of log messages. When using a facade, this
> information can get lost. How did you guys solve that? I have two
> approaches in Clog. For the Silverlight version I use a combination of
> the URL and control type, for the desktop CLR I use stack frame
> counting and provide a configurable skip frame count parameter.

Right now we do not solve that. Personally I have never found the need
to turn on the line number or call stack features of logging
frameworks. SLF would certainly prevent log4net from outputting a
useable line number, however with NLog you can output the top stack
frames, so SLF would be added to the stack.

I generally tend to favour clearly named loggers and unambiguous
logging messages. With this combination you shouldn't need stack or
line number information.

However, it is well worth thinking about for future SLF versions.

Colin E.

[Bill Kempf]

Really interesting library. I'm a little curious why you chose to use
custom loggers, like the DebugLogger from the samples, instead of just
relying an the built in TraceSource functionality? With
Ukadc.Diagnostics the TraceSoruce stuff proves to be a very powerful
logging facility. I've even hacked together a way to use heirarchical
named TraceSoruces (i.e. when you request a "Foo.Bar.Baz" logger, if
there's no logger with that name it will try "Foo.Bar" then "Foo" and
finally use a default). I understand that I can easily plug this into
SLF, I'm just curious as to why SLF didn't default to using
TraceSource?

--
Quidquid latine dictum sit, altum sonatur.
- Whatever is said in Latin sounds profound.

War is peace. Freedom is slavery. Bugs are features.

[Daniel Vaughan]

One thing I really like with Clog is that I was able to create a
simple Output window log strategy, so that you can jump to the source
code line from right within Visual Studio by double clicking on the
log message in the output window. Really handing when doing
multithreaded stuff. I used this loads when I was creating my Legion
project back in 2007. My how time flies. :)

[Colin Eberhardt]

Now that does sound nice ...

[Philipp Sumi]

Bill,

Thanks for the feedback! The more we get, the faster the framework can improve :)

We didn't want to rely on any "3rd-party" mechanism, especially because you can completely customize the whole resolution process in SLF. Furthermore, IIRC, Silverlight doesn't support Trace at all, so this is a no-go anyway as a framework foundation. You can, however, simple feed Trace output directly into SLF - the framework comes with a built-in TraceListener.

Regarding the hierarchical lookups you described - SLF supports this exact lookup pattern out of the box :)
I wasn't even sure anymore what would happen here, so I took one of the sample apps that show off the named loggers feature and just added these two lines at the end of the sample:

Trace.Listeners.Add(new SlfTraceListener());
Trace.Write("hello world", "red.BAR");


This lead to SLF writing "hello world" to SLF's configured logger "red". I love it when things work like that :)

[Bill Kempf]

I didn't realize that SL didn't have the System.Diagnostics stuff.
That's sad :(. That's enough of a reason to use your own DebugLogger
et. al. However, it still makes sense to include a TraceSourceLogger
(conditionally dependent on runtime). This isn't a "3rd-party"
mechanism. All of the tracing stuff is part of the BCL. The
Ukadc.Diagnostics stuff is layered on top and would be automatically
usable if SLF supported System.Diagnostics as a "logging framework".
The heirarchical naming for TraceSource isn't entirely simple to
implement, but the necessary code isn't all that complicated either.
Again, it should be trivial for me to implement all of this stuff
using SLF out of the box, but it seems like something that should be
"batteries included" to me.

The blog post talked about named loggers with inheritance, but didn't
make it clear how it worked, so my e-mail was overly descriptive on
this :). To be honest, I prefer to use the Type as the "name".

LoggingService.GetLogger(typeof(MyClass));

This uses the full name of the Type ("MyNamespace.MyClass"). This is
roughly how Log4J (and by extension, I believe, Log4Net) works. Worth
considering an overload in SLF for this usage.

[Bill Kempf]

Oh... another thought. If you used MEF, there wouldn't be a need to
configure what logging facade to plug-in to SLF. :)

[Bill Kempf]

Something else I just noticed. ILogger doesn't have a method for
determining whether or not anything would be logged for a given level.
Such a test can be very important to optimizing logging code (you
don't want to gather information for logging if it's not going to be
logged).

[Philipp Sumi]

Bill,

Keep that feedback coming :)

We have a simple TraceLogger built into SLF, which just forwards a string representation of the logged data to Trace. If you would think this could/should be improved, we're more than open to suggestions!

We already discussed GetLogger<T>() or GetLogger(Type) methods in LoggerService, but decided to keep the API as small as possible for 1.0. We didn't want to just copy all the functionality of existing logging frameworks (which are partially horribly bloated IMO), but rather wait for feedback. We heard you.

Regarding log filtering, we already opened an discussion for the topic on the project site. It basically comes down to the question whether we should leave that completely up to the underlying framework or provide it as a (complementary) part of SLF. I think both positions have their valid points: http://slf.codeplex.com/Thread/View.aspx?ThreadId=76857

Regarding MEF: It might actually be a simple but fancy little contribution to implement a factory resolver (LoggerService.FactoryResolver is the root of the logger resolution process) that works based on MEF. I'll keep that one in mind :)

Thanks again!

[Bill Kempf]

Yes, instead of logging to Trace, it should log to a specified TraceSource.

TraceSourceLogger logger = new TraceSourceLogger(new TraceSource("name"));
LoggingService.SetLogger(logger);

Trace is an API of dubious design beyond the simplicity of use by
developers. TraceSource is where the real power in System.Diagnostics
lies. :) Combine TraceSource with something like Ukadc.Diagnostics
(which basically just provides TraceListener's and other pluggable
components) and you get a "logging" framework nearly as powerful as
Log4Net and the others. Add some magic to give you heirarchical name
lookup and you have 99% of the functionality of these other
frameworks... all using built-in components. I think a lot of people
don't realize the potential of System.Diagnostics when they
automatically discount it as a logging framework. :)

On the filtering... I posted to the discussion on codeplex. I think
that most filtering should be left to the underlying implementations
plugged into SLF, but I think that trace level filtering is too
important (for optimizing code) to not be included. A facade that
doesn't allow me to determine if LogLevel.Debug messages would be
logged or not has abstracted away too much of the underlying logging
to be useful, IMHO. All logging services, including SystemDiagnostics,
include log level filtering and interrogation for a reason :).

[Paul Stovell]

+1.

For me the most powerful thing in System.Diagnostics is Trace.CorrelationManager. It allows you to set an activity ID on the client side and have WCF propagate it to the server, allowing you to overlay log entries. With the service trace viewer you can overlay client and server log files and see something like:

Order 123:
   Processing order   (Client.exe)
   Sending order       (Client.exe)
      Order received       (Server.exe)
      Error in order         (Server.exe)
   Error in order        (Client.exe)
Order 456:
   Processing order   (Client.exe)
   Sending order       (Client.exe)
      Order received       (Server.exe)
      Order placed         (Server.exe)
   Order processed.  (Client.exe)

Then when you load the WCF message traces, you can see the WCF messages interlaced between your application logs to inspect what was actually sent/received. It's a very powerful system (though you may have to write your own trace listener).

Correlation and logical operation hierarchies is something any log-wrapping API should definitely support.

Paul

--
Paul Stovell

[Philipp Sumi]

Ok, I've taken the Trace issue to the SLF discussion board, along with a first quick implementation sample:

http://slf.codeplex.com/Thread/View.aspx?ThreadId=76892

 

Paul: I need to look into the CorrelationManager. Unfortunately, I have to admit that so far, I'm drawing a blank here :/

[Bill Kempf]

Looks like a good start... though this doesn't give you heirarchical naming. :)

I could be wrong, but I don't think you need to cache the TraceSource,
as I believe TraceSource already does this internally (been a while,
but Reflector is your friend on this one).

I don't know why the TraceSource property includes a public setter? As
near as I can tell, you can never call it. Nor do I think you would
ever want to. However, I would consider a constructor that takes a
TraceSource.

[Paul Stovell]

Hi Philipp,

Something like this would be enough:

var logger = LoggerService.GetLogger...
using (logger.BeginActivity(Guid.NewGuid(), "Begin XYZ"))
{
    logger.Warn("hello");
}

The adapter for the logging framework can either return a dud IDisposable or make use of the correlation token in different ways. log4net might start a new file for that guid, while System.Diagnostics would use it to set the trace activity Id.

Paul

--
Paul Stovell