Why is log4net creating two separate log files when using RollingFileAppender?

Question

I'm trying to get the log4net RollingFileAdapter working so that my logfiles are rolling over by date. However I'm finding that even when I copy the example code, I'm not getting the behaviour I expect. Instead of getting a single file of today's date and time, it splits the log messages between two different files. One file is called just "log" and the second one obeys the config and will be called 'log20130830-1115.txt'.

If I use <log4net debug="true"> in my config file, I see the folling in the Trace output:

log4net: Initial roll over to [c:\inetpub\wwwroot\QuartzTest\ScheduleTest\bin\Debug\log20130830-1115.txt]
log4net: Moving [c:\inetpub\wwwroot\QuartzTest\ScheduleTest\bin\Debug\log] -> [c:\inetpub\wwwroot\QuartzTest\ScheduleTest\bin\Debug\log20130830-1115.txt]

Notice line two... Why does it create a file called "log" in the first place? And why doesn't it seem to do the move it talks about? The entries in 'log' are always timestamped AFTER any of the entries in the correctly named file, even though that file appears first.

What's happening here? Have I messed up the config or is there a bug in the log4net RollingFileAppender?

Here is my config:

<log4net debug="true">
    <appender name="TraceAppender" type="log4net.Appender.TraceAppender">
        <layout type="log4net.Layout.PatternLayout">
            <conversionPattern value="[log4net] %d [%t] %-5p %l - %m%n" />
        </layout>
    </appender>

    <appender name="RollingLogFileAppender" type="log4net.Appender.RollingFileAppender">
        <file value="log" />
        <appendToFile value="true" />
        <rollingStyle value="Date" />
        <datePattern value="yyyyMMdd-HHmm'.txt'" />
        <layout type="log4net.Layout.PatternLayout">
            <conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline" />
        </layout>
    </appender>

    <root>
        <level value="INFO" />
        <appender-ref ref="TraceAppender" />
        <appender-ref ref="RollingLogFileAppender" />
    </root>
</log4net>

Answer 1

You're rolling on date, which means that whenever the datePattern you've specified changes, log4net will roll the log file. You've specified a date pattern that changes each minute, so you should expect a new log rolloff each minute.

These rolloffs will be named using the date pattern you've specified. However the active log file will be named "log" and renamed during rolloff. That is, with your config log4net will always write to the file named "log" and copy it off once the datePattern value changes.

If I understand you correctly then you want your active log file to be named using the date pattern in your config. Try this:

 <appender name="RollingFileDateAppender" type="log4net.Appender.RollingFileAppender">
  <file value="log.txt" />
  <appendToFile value="true" />
  <preserveLogFileNameExtension value="true" />
  <staticLogFileName value="false" />

  <rollingStyle value="Date" />
  <datePattern value="yyyyMMdd-HHmm" />

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

The staticLogFileName setting controls the name of the "active" log file; when it's false, log4net will use the datePattern to name the active log file. Note this means no roll-off copy needs to be done, a new log file (with the appropriate name) will be created instead. Setting preserveLogFileNameExtension to true forces log4net to use the .txt file extension when creating the file; normally it would just append the date pattern to the end of the file name, resulting in a file extension like .txt20130830-0819 which is pretty useless.