Log4net dynamic separate log does not work?

Question

I have a config file as follow:

<configuration>
<configSections>
    <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />        
</configSections>
<appSettings> 
    <add key="log4net.Config" value="log4net.config"/>
</appSettings>
<log4net>
    <appender name="appenderA" type="log4net.Appender.RollingFileAppender">
        <file type="log4net.Util.PatternString" value="logs\\%property{LogName}" />
        <param name="AppendToFile" value="true" />
        <param name="RollingStyle" value="Composite" />
        <lockingModel type="log4net.Appender.FileAppender+MinimalLock" />
        <maxSizeRollBackups value="3" />
        <maximumFileSize value="5KB" />     
        <staticLogFileName value="true" />
        <layout type="log4net.Layout.PatternLayout">
            <conversionPattern value="%d [%t] %-5p %c [%logger] = %m%n" />
        </layout>
    </appender>
    <logger name="ConsoleApplication1.testCls">
        <level value="INFO" />          
    </logger>   
    <root>
        <level value="ALL" />
        <appender-ref ref="appenderA" />
    </root>
</log4net>
</configuration>

Then I have a function will return log4net.ILog

Public Function func(cls As Object) As log4net.ILog
    Dim clsName As String = cls.ToString()
    Dim rollAppen As New RollingFileAppender()

    log4net.ThreadContext.Properties("LogName") = clsName.ToLower() & ".log"
    log4net.Config.XmlConfigurator.Configure(New System.IO.FileInfo("Log4Net.config"))
    Dim logg As ILog = LogManager.GetLogger(clsName)
    Dim l As log4net.Repository.Hierarchy.Logger = DirectCast(logg.Logger, log4net.Repository.Hierarchy.Logger)
    If l.Level Is Nothing Then
        l.Level = l.Hierarchy.LevelMap("INFO")
    End If
    Return logg
End Function

Now I test the function func

    Dim tCls As testCls = New testCls()
    Dim cls As LogTest2 = New LogTest2()
    Dim l4n As log4net.ILog
    Dim l4n2 As log4net.ILog

    l4n = cls.func(tCls.GetType().ToString())
    l4n2 = cls.func(cls.GetType().ToString())

    l4n.Debug("... Here is a debug log -2.")
    l4n.Info("... and an Info log.")
    l4n.Warn("... and a warning 1.")
    l4n.Debug("... Here is a debug log -1.")
    l4n.Warn("... and a warning 2.")
    l4n.Warn("... and a warning 3.")
    l4n2.Warn("l4n2 cls and a warning -1.")
    l4n.Warn("... and a warning 4.")
    l4n.Warn("... and a warning 5.")
    Console.Write(" ... ... ... ")
    l4n.Warn("... and a warning 6.")
    l4n.Debug("... Here is a debug log 1.")
    l4n.Warn("... and a warning 7.")
    l4n2.Debug("l4n2 cls Here is a debug log.")
    l4n2.Info("l4n2 cls and an Info log.")
    l4n.Fatal("... and a fatal aaa.")
    l4n2.Fatal("l4n2 and a fatal .")
    l4n.Debug("... Here is a debug log 2.")
    l4n.Warn("... and a warning 8.")
    l4n.Error("... and an error.")
    l4n.Debug("... Here is a debug log 3.")
    l4n.Fatal("... and a fatal bbb.")
    l4n.Debug("... Here is a debug log 4.")
    l4n2.Debug("l4n2 cls Here is a debug log.")
    l4n2.Info("l4n2 cls and an Info log.")
    l4n2.Warn("l4n2 cls and a warning.")
    l4n2.Error("l4n2 cls and an error.")
    l4n2.Fatal("l4n2 cls and a fatal .")

There are 2 log files named consoleapplication1.testcls.log and consoleapplication1.logtest2.log generated. But....

it is only consoleapplication1.logtest2.log have log content and all the log content save into consoleapplication1.logtest2.log. Another log consoleapplication1.testcls.log generated but no content in it.

consoleapplication1.testcls.log
====no content====

consoleapplication1.logtest2.log
2013-06-13 11:00:33,390 [11724] INFO   = ... and an Info log.
2013-06-13 11:00:36,408 [11724] WARN   = ... and a warning 1.
2013-06-13 11:00:36,411 [11724] WARN   = ... and a warning 2.
2013-06-13 11:00:36,413 [11724] WARN   = ... and a warning 3.
2013-06-13 11:00:36,414 [11724] WARN   = l4n2 cls and a warning -1.
2013-06-13 11:00:36,416 [11724] WARN   = ... and a warning 4.
2013-06-13 11:00:36,418 [11724] WARN   = ... and a warning 5.
2013-06-13 11:00:39,421 [11724] WARN   = ... and a warning 6.
2013-06-13 11:00:39,424 [11724] WARN   = ... and a warning 7.
2013-06-13 11:00:39,426 [11724] INFO   = l4n2 cls and an Info log.
2013-06-13 11:00:39,429 [11724] FATAL  = ... and a fatal aaa.
2013-06-13 11:00:39,431 [11724] FATAL  = l4n2 and a fatal .
2013-06-13 11:00:39,433 [11724] WARN   = ... and a warning 8.
2013-06-13 11:00:39,435 [11724] ERROR  = ... and an error.
2013-06-13 11:00:39,437 [11724] FATAL  = ... and a fatal bbb.
2013-06-13 11:00:39,439 [11724] INFO   = l4n2 cls and an Info log.
2013-06-13 11:00:39,441 [11724] WARN   = l4n2 cls and a warning.
2013-06-13 11:00:39,443 [11724] ERROR  = l4n2 cls and an error.
2013-06-13 11:00:39,444 [11724] FATAL  = l4n2 cls and a fatal .

Do you know what is wrong with my code? I've been struggling with this for two days already.

Answer 1

The appender configured in your config file is the only instance of RollingLogFileAppender - you just have two objects pointing to it. Therefore you are overwriting the settings for l4n when you call func() to set l4n2. To prove this theory, you should be able to switch the lines:

l4n = cls.func(tCls.GetType().ToString())
l4n2 = cls.func(cls.GetType().ToString())

to

l4n2 = cls.func(cls.GetType().ToString())
l4n = cls.func(tCls.GetType().ToString())

and all of your log output should go into the consoleapplication1.testcls.log rather than the consoleapplication1.logtest2.log where all of your output is currently going.

The fix is to either programmatically generate a new log4net appender for each class (as they do in the answer to this question) or just put two instances of RollingLogFileAppender into your config file: one for each class that you want to log for.