log4net not working in dll

Question

I'm currently having issues with getting log4net to work within a particular dll. I'm currently using log4net in other dlls being called by my test app and logging is working fine within those dlls and also within my test app. It's this one particular dll that I'm having trouble with. Here is snippet of code from the dll I'm having trouble with.

//This is from ABC.dll
public class SessionFactory
{
    protected static ISessionFactory sessionFactory;
    private static readonly ILog log = LogManager.GetLogger(typeof(SessionFactory));

    private static void Init()
    {
        try
        {
            //Read the configuration from hibernate.xml.cfg or app.config
            Configuration normalConfig = new Configuration().Configure();
            ConfigureNhibernateValidator(normalConfig);

            log.Debug("Initializing session factory");

            sessionFactory = Fluently.Configure(normalConfig)
              .Mappings(m =>
                  m.FluentMappings
                  .AddFromAssemblyOf<OrderHeaderMap>()
                  .Conventions.AddFromAssemblyOf<PascalCaseColumnNameConvention>())
               .ProxyFactoryFactory("NHibernate.ByteCode.LinFu.ProxyFactoryFactory, NHibernate.ByteCode.LinFu")
              .BuildSessionFactory();

            log.Debug("Finished initializing the session factory");
        }
        catch(Exception ex)
        {
            //Code not shown
        }
    }
}

In my test app I am calling:

log4net.Config.XmlConfigurator.Configure();

Here is my log4net configuration in my App.config file:

<configuration>
  <configSections>
    <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net"/>
  </configSections>
  <log4net>
    <!-- ALL|DEBUG|INFO|WARN|ERROR|FATAL|OFF -->
    <root>
      <level value="DEBUG"/>
      <appender-ref ref="SpeedTest"/>
    </root>

    <!-- This is a default logger that nhibernate uses to push out all the SQL statements to-->
    <logger name="NHibernate.SQL" additivity="false">
      <level value="DEBUG"/>
      <appender-ref ref="NHibernateConsoleLog"/>
      <appender-ref ref="NHibernateFileLog"/>
    </logger>

    <!-- This is a default logger that nhibernate uses to push out all the debugging type information to-->
    <logger name="NHibernate" additivity="false">
      <level value="DEBUG"/>
      <appender-ref ref="NHibernateFileLog"/>
    </logger>

    <appender name="NHibernateConsoleLog" type="log4net.Appender.TraceAppender">
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline"/>
      </layout>
    </appender>

    <appender name="NHibernateFileLog" type="log4net.Appender.RollingFileAppender">
      <file value="Logs/nhibernate.txt" />
      <appendToFile value="true" />
      <rollingStyle value="Size" />
      <maxSizeRollBackups value="10" />
      <maximumFileSize value="10MB" />
      <staticLogFileName value="true" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%d{HH:mm:ss.fff} [%t] %-5p %c - %m%n"  />
      </layout>
    </appender>

    <appender name="SpeedTest" type="log4net.Appender.RollingFileAppender">
      <file value="Logs/SpeedTest.txt" />
      <appendToFile value="true" />
      <rollingStyle value="Size" />
      <maxSizeRollBackups value="10" />
      <maximumFileSize value="10MB" />
      <staticLogFileName value="true" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%d{HH:mm:ss.fff} [%t] %-5p %c - %m%n"  />
      </layout>
    </appender>
  </log4net>

</configuration>

Again logging is working fine within my test application using the SpeedTest appender but the logging within the above snippet of code is not working. I set breakpoints above on when it initializes the logger and it seems to hit it. I can post the log4net debug output if necessary but I didn't really see much. Just let me know if you need it and I will post.

Any suggestions as to why logging is not being recorded in the above snippet of code?

Answer 1

It seems that this issue was stemming from me changing the directory to all my external dependencies (log4net being one of them) awhile back in TFS. All I did was drop all my references in my visual studio project and re-add them from my new dependencies folder and everything worked as expected after this. Thanks for all those that helped here.

Answer 2

My suspicion would be that it isn't reading the configuration from the configuration file when you call configure.

If you add the following lines to your application, what do you see (either on the console, or in IDE output window, or by stepping through in the debugger):

var log4netConfig = ConfigurationManager.GetSection("log4net");
var log4netConfigIsNull = log4netConfig == null;
Console.WriteLine(log4netConfigIsNull);

Does it look like the configuration is actually available from the configuration file?

[Edit: in response to your comment]

If you now add another line of debug code to your app:

Console.WriteLine(log.IsDebugEnabled);

what output do you get? Does the logger think it is configured for debug logging? (I'm particularly interested in the behaviour of this in, or after, SessionFactory.Init).

Answer 3

The immediate thought would be that your logging code isn't getting hit, possibly due to an exception being thrown prior to your first log4net call. Can you put a log entry into a finally block, just to test that the logger works?