You've seen my posts from time to time about Microsoft's Enterprise Instrumentation Framework (EIF). We were using it at one of my clients for quite some time to log all of our errors to various places. But recently we started experiencing massive slowdowns that I was unable to rectify, but that seemed to be attributable to EIF initialization. Some of our unit tests went from taking 5 seconds to taking 50 seconds.
I probably would have worked longer to fix it, but at the same time we were facing some serious configuration issues with EIF as well. Specifically, we were trying to instrument our code to record a pair of start/stop log messages for each method, which we could turn on or off at runtime based on our need for diagnostic information. While EIF certainly supports this, its configuration mechanism requires that we then list the name of every method in the EIF config file. While possible, that was impractical.
So I decided to see what it would take to switch to log4net. As it turned out, it only took one day. I'd isolated most of the logging code already, so I just had to change things in one place. And at the end of it, I was much happier. Not only does log4net appear to do pretty much the same things as EIF, it appears to be faster (although the jury is still out), it appears to be easier to extend, and it is definitely easier to configure. The last point is an important one for us - log4net has a hierarchical configuration scheme, meaning we can set defaults at the root and have them propagate to all our logging statements, rather than having to set them explicitly, as we do with EIF.
I'm not saying EIF is bad, mind you. It could be that I was doing things wrong. I know that Microsoft is overhauling it, so maybe their next version will be better. log4net does have a head start, being a port of log4j, which has been around for a long time. But for now, log4net meets our needs better...your mileage may vary.
There's a decent article on theserverside.net that goes more in depth, but here are what I found to be the major differences:
- Ease of use. log4net felt easier to get started with. That might have been because I had already used EIF. The two are fairly similar.
- Typed vs. untyped. log4net is “untyped“ in the sense that you log strings. In EIF, you log typed objects. This turns out largely to be a philosophical distinction except for:
- Extensibility. Because log4net allows you to attach arbitrary name-value pairs to a logging thread (they call this MDCs), it's actually easier to extend. In EIF, the reliance on strongly-typed object hierarchies means I have to extend their schema. That turns out to be difficult for a variety of reasons.
- Manageability. Like I said, the fact that log4net lets you inherit log settings down a hierarchy of loggers makes it easier to manage a large application. EIF, by contrast is “flat“, and forces you to manage every log source independently.
Other than that, I found the two pieces of software to be very, very similar. Which means I'd generally choose log4net in the future.
We made the same decision around log4net. We did wrap it, however, via our own ILoggingService interface to CYA in case it's next version sucks. We're on (as everyone is) 1.20b8 but there are breaking changes coming as the project has moved to apache's management.
ReplyDeleteInteresting! Any idea on when that might be?
ReplyDeleteWe started on log4net about 18 months ago or so, but found a lot of reasons - mainly configuration and context for Serviced Components - to go with EIF. I agree with your comment about ease of logging text vs a tedious log event hierarchy, but at the time EIF brought a lot to the table for Serviced Components, and we made the decision to standardize on one or the other for simplicity.
ReplyDeleteYeah, I can totally see using EIF for serviced components, since it grabs so much useful (in that context) information by default.
ReplyDeleteDarn. You AGREED with me. Shucks, I thought I was gonna hear how log4net had made some great strides in this area and that I could switch back. ;)
ReplyDelete:)
ReplyDeletelog4net has the ability to capture contextual information in your logs. You can use the MDC and NDC in order to do this. Being a long time log4net user, I had only briefly considered the EIF, so I am not sure what features it offers for serviced components that log4net would not be able to provide. Could you elaborate?
ReplyDeleteJust that it will automatically - without you having to write any code - capture COM+ and windows security information. It's nothing you can't do n log4net with an MDC or an NDC, but it requires writing code.
ReplyDeletePerhaps someone has written a forwarding appender that takes care of this for you, though - I'm not aware of one.
I don't think there's anything one product can do that the other can't. It's just a question of "how hard is it".
Architecture: Craig Andrea drops EIF for log4net!
ReplyDeleteThanks for the link!
ReplyDeleteCraig, you have mentioned
ReplyDelete"Specifically, we were trying to instrument our code to record a pair of start/stop log messages for each method, which we could turn on or off at runtime based on our need for diagnostic information. While EIF certainly supports this"
Can u pls explain how to acheive this (turn on / off) trace at run time.
Thanks,
Gopi
It depends on how you set up your logging, but the broad answer is, "edit your log4net config file".
ReplyDeleteWe've set it up so that when we log a message, we set the logger to the full method name, like
Craig.Foo.Bar.SomeMethod
Because log4net recognizes dots as separators, this allows us to turn things on/off at the Craig level, the Craig.Foo level, the Craig.Foo.Bar level, etc.
Craig,
ReplyDeleteSorry, my question was, how to achieve this in EIF ? I don't wanna write .Raise() Event all over my production code.
In EIF, if i just place the fully qualified method name in the enterpriseinstrumentation.config can the event be raised ?
Thanks,
Gopi
Achieving this in EIF is a pain in the ass, which is one of the main reasons that we ditched it.
ReplyDeleteAs far as recording messages, both EIF and log4net require that you call Raise() or Log() for every message that you want to produce.
You can probably achieve this using an aspect weaver, custom compiler, or .NET remoting sink, but I don't know much about any of those approaches...and what I do know, I don't like.
Frankly, I think you should get bite the bullet and instrument your code. Encapsulate what you're doing in a helper method, and you can get the code down to one line, but it's still going to have to be in every method.
Real Ugly() and that is what I'm affraid off.
ReplyDeletewhy can't these guys simply read the config and see any entry for class.method() and raise an event ? After all they are flowing the context along ?
I have evaluated AOP, method interceptor etc. all but everything needs atleast an attribute to be placed on these methods, which makes the entire purpose useless !
BTW, I wonder how the ANTS Profiler or Intel VTUNE dynamically gets the method interception ?
Thanks anyhow for your inputs.
Gopi
I'm not sure how you expect the EIF guys to write something like this - how are they supposed to inject code into your method? How would you write it if you were them?
ReplyDeleteANTS and VTune use the .NET profiling API, which is one way to inject code, but it's really hard to do it this way. The profiler itself has to be unmanaged, and the parts of it you'd need to do method injection would need to be written in assembly, with the resultant high chance of major bugs.
One option is for you to do manipulation of your source files as part of the compilation process, injecting logging method calls. It's ugly, but you're trying to solve a hard problem.
I'm a bit surprised to hear that there are no AOP solutions that don't require method attribution.
I'm expecting (I may be wrong) just exactly like trace=true in aspx pages which turns the trace on.
ReplyDeleteI guess it is a compiler job. when u see an entry in the config file for a class.method() you just add a trace call to the start and end of the method. After all the compiler knows the workflow !
as u finally suggest, that is what i'm planning to do, injecting logging calls. but don't know how to start !
any pointers would be great.
Yes AOP is still not that mature ! either attribute or you have to derive from ContextBoundObject !
Thanks,
Gopi
There's a big difference between an ASP.NET page and any old method of some class. ASP.NET does a crapload of stuff before and after your page. Once the JITter runs, .NET does very little (nothing, in most cases) before/after your method, so your performance doesn't suck.
ReplyDeleteAs for how to instrument your source, I'd have a look at some of the profilers out there. At least one of them is a source code instrumenter. Otherwise you're going to have to write a C# parser, and that's a huge job.
Thanks Craig for all your excellent inputs.
ReplyDeleteduring the course (accidently) I found answer to my query on my Computer !
It is under ProgramFiles\Microsoft Visual Studio .NET 2003\SDK\v1.1\Tool Developers Guide\docs\Profiling.doc
There is also the samples folder which has C++ source code, of how to enable managed code profiling ! That's fantastic .
I'm in the process of compiling and testing the code (needs platform SDK) and I checked the next version (Whidbey) has much better support for Code/Memory Profiling.
If you have worked on this, pls give some comments.
Thanks,
Gopi
My main comment would be: don't do it. You're going to be experiencing a world of pain just so you don't have to type one extra line of code per method - not worth it. You can even easily write an FxCop rule that checks for the presence of that one line of code and run it during your builds. That way you can never forget to put it in.
ReplyDelete