« Reverse Engineering To Learn .NET Better | Main | How to Encode Audio... »

June 17, 2004

Logging? Think Twice...

This is an experiment in the somewhat obvious, but to see how big of problem it can be, let's take a much closer look at a very common and basic feature of most software, logging. When performing smaller functions or operations consider the verbosity and quantity when it comes to logging information. The example below performs some 10,000 Math operations and logs the each result to the log file. As you can see the amount of time between the start and finish is greater than 12 seconds.

06_08 11:53:12.6875 2152  INFO === Log Start ===
06_08 11:53:12.6875 2152  INFO     Test 2.71828182845905
06_08 11:53:12.7031 2152  INFO     Test INDEX=0
... Performing Work AND Logging ...
06_08 11:53:24.6250 2152  INFO     Test Infinity
06_08 11:53:24.6250 2152  INFO     Test INDEX=8750
06_08 11:53:24.6250 2152  INFO === Log End ===

When performing the exact same 10,000 Math operations and only writing the first result, to record a start time, the result of course is dramatically different. The time difference is slighly more than 250ms.

06_08 11:53:43.8437  376  INFO === Log Start ===
06_08 11:53:43.8437  376  INFO     Test 2.71828182845905
06_08 11:53:43.8437  376  INFO     Test INDEX=0
... Performing Work AND *NO* Logging ...
06_08 11:53:43.8750  376  INFO === Log End ===

The moral of the story is log only what you need to. Logging IO can actually be quite expensive. These tests were performed with .NET 1.1 Framework.


Posted by 0xFF3300 at June 17, 2004 11:56 AM

Trackback Pings

TrackBack URL for this entry:
http://www.dudeforce.net/cgi-bin/mt-tb.cgi/79

Listed below are links to weblogs that reference Logging? Think Twice...:

Comments

Just happenned to run across your website, when I was googling something.

Just wondering would it be better to log, and put everything in memory and then do a write only once, after the application finishes.

Is that better?

Posted by: Rav at July 28, 2004 01:34 PM

Rav,

Filling then flushing the log works, but the issue you will come across is when an error occurs, and the log never gets flushed. I guess it really depends on how your Exception handling in the application is set up.

- Julian

Posted by: Julian at July 29, 2004 12:43 PM

His mind is like a steel trap: full of mice.
-- Foghorn Leghorn
prozac online If a camel is a horse designed by a committee, then a consensus forecast is a
camel's behind.
-- Edgar R. Fiedler
prozac

Posted by: Sarah King at September 6, 2004 02:21 AM

Post a comment

Thanks for signing in, . Now you can comment. (sign out)

(If you haven't left a comment here before, you may need to be approved by the site owner before your comment will appear. Until then, it won't appear on the entry. Thanks for waiting.)


Remember me?