Login or Sign Up to become a member!
LessThanDot Sit Logo

LessThanDot

Desktop Developer

Less Than Dot is a community of passionate IT professionals and enthusiasts dedicated to sharing technical knowledge, experience, and assistance. Inside you will find reference materials, interesting technical discussions, and expert tips and commentary. Once you register for an account you will have immediate access to the forums and all past articles and commentaries.

LTD Social Sitings

Lessthandot twitter Lessthandot Linkedin Lessthandot friendfeed Lessthandot facebook Lessthandot rss

Note: Watch for social icons on posts by your favorite authors to follow their postings on these and other social sites.

Your profile

Search

XML Feeds

Google Ads

« Me and NHProf: the beginningHow to make your VMware VM crash »
comments
Rate Post:
submit to reddit Digg!FacebookDotnetkicks

Today I noticed that my integration tests with nhibernate were runnning very slow on the build server. Very slow meaning 1 hour to run while they run for 6 minutes on my dev machine all 840 of them. Something was different.

I am using Finalbuilder 5.5 on my build machine and that uses the nunit console to do the dirty work for it.

So I tried running it in the nuint gui tool and there too it was slow.
So I clicked a bit on the tabs, one never knows when one might get lucky and low and behold I was lucky. The Log tab of the GUi builder was getting lots of work.
I know my readers (all 3 of you) prefer pictures over words so here is a picture.

Apparently nunit 2.4.6 has a config somewhere that says log4net should use debug level logging. Which slows down nhibernate like never before.

So I copy pasted my regular log4net nhibernate appender and other config things into the app.config of the test project

  1. <configSections>
  2.       <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler,log4net" />
  3.     </configSections>
  4.  
  5.   <!-- This section contains the log4net configuration settings -->
  6.   <log4net debug="false">
  7.  
  8.        <appender name="rollingFile" type="log4net.Appender.RollingFileAppender,log4net" >
  9.  
  10.       <param name="File" value="nHibernate.log" />
  11.       <param name="AppendToFile" value="true" />
  12.       <param name="RollingStyle" value="Date" />
  13.       <param name="DatePattern" value="yyyy.MM.dd" />
  14.       <param name="StaticLogFileName" value="true" />
  15.       <param name="maxSizeRollBackups" value="10" />
  16.          
  17.       <layout type="log4net.Layout.PatternLayout,log4net">
  18.         <param name="ConversionPattern" value="%d [%t] %-5p %c - %m%n" />
  19.       </layout>
  20.     </appender>
  21.  
  22.     <!-- Setup the root category, add the appenders and set the default priority -->
  23.  
  24.     <root>
  25.       <level value="Info"/>
  26.       <appender-ref ref="rollingFile"/>
  27.     </root>
  28.  
  29.     <logger name="NHibernate">
  30.       <level value="Warn" />
  31.       <appender-ref ref="rollingFile"/>
  32.     </logger>
  33.  
  34.     <logger name="NHibernate.Loader.Loader">
  35.       <level value="Warn" />
  36.       <appender-ref ref="rollingFile"/>
  37.     </logger>
  38.  
  39.   </log4net>

and added this to the first test, just to check if it was faster.

  1. log4net.Config.XmlConfigurator.Configure()

And now my integration tests are back to their normal slow self.

I think this problem will not occur in nunit 2.5 and above since they now use a different logger then log4net.

About the Author

User bio imageChristiaan is a forensic technician who programs on the side, although my function description says that I do IT-things for 90% of the time . I'm an avid VB.NET fan and I use lots of the ALT.Net techniques, like unit-testing, nhibernate, logging, IoC, ...
Social SitingsTwitterLinkedInHomePageLTD RSS Feed
1910 views
submit to reddit Digg!FacebookDotnetkicks

Comments and Feedback

5 comments

Comment from: Alex Ullrich [Member] Email
*****
>>>I know my readers (all 3 of you) prefer pictures over words so here is a picture.

We do, and the bigger the better. I got all excited when I had to maximize my browser to see it. But you tricked us by having words in the picture ;)

I could definitely see this becoming an issue, I will have to check the version of NUnit I'm using (I think it's 2.5).
06/05/09 @ 08:32
Comment from: chrissie1 [Member] Email
It should be a bit smaller now.
06/05/09 @ 12:38
Comment from: Alex Ullrich [Member] Email
And now, as a bonus I can't read it ;) No more of those confusing words to hurt my widdle brain!
06/05/09 @ 15:16
Comment from: kermit [Member] Email
Have you tried NLog (http://www.nlog-project.org/)?

I got frustrated with Log4Net and found it very time consuming to setup per project, also the overhead seemed a bit high if I only wanted it for simple tasks.

NLog is more streamlined imo and well polished, takes minutes to setup and would work well in the above scenario plus has a small footprint so great for doing work like logging errors or simply acting as a log file writer (logs are actually inteligible english).

Like you I found Log4Net slow when I wanted to use it in a situation where I wanted to log lots of data over and over, where NLog really worked great (spewed out WMI data for my system monitor app without a fuss until I remembered I forgot to tell it to roll the log file).

Gets an 8 out of 10 from me.
06/05/09 @ 17:47
Comment from: Nutshell [Visitor] Email
Unlike you - I am having problems getting my Log4Net logging to work using NUnit 2.4.8 and above (including NUnit 2.5)

If I use NUnit 2.4.1 - it works fine -
If I change to use NUnit 2.5 - all my logging stops

Anyone know what might be the issues with that?
03/06/09 @ 16:12

Leave a comment


Your email address will not be revealed on this site.

Your URL will be displayed.
(Line breaks become <br />)
(Name, email & website)
(Allow users to contact you through a message form (your email will not be revealed.)