Why is the date appended twice on filenames when using Log4Net?

Question

I was trying to add the date to my log file name and I was able to make it work by following the few suggestions I've found in stackoverflow. Everything works fine but for some reason, the first file always has the date appended twice. For example, instead of log.2009-02-23.log, I get log.2009-02-23.log.2009-02-23.log. I found it so weird and fyi, this is a very simple code. It's not like I have it running in a multi-threaded environment.

My log4net config:

<log4net>
<appender name="MyLog" type="log4net.Appender.RollingFileAppender">
    <file value="../../Logs/Mylog"/>
    <staticLogFileName value="false" />
    <appendToFile value="true"/>
    <rollingStyle value="Date"/>
    <datePattern value=".yyyy-MM-dd.lo\g" />
    <lockingModel type="log4net.Appender.FileAppender+MinimalLock" />
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%d{DATE} [%t] %-5p %c - %m%n"/>
    </layout>
</appender>
<root>
    <level value="INFO"/>
    <appender-ref ref="MyLog"/>
</root>
</log4net>

Any ideas why?

Edit: I want to add the information about the environment I'm testing this in.
- asp.net
- .net framework 2.0
- windows server 2003 64-bit service pack 2
- log4net 1.2.10

Answer 1

try <datePattern value=".yyyy-MM-dd.lo\g" /> I don't understand what the \g is for.

Answer 2

As olle pointed out. your problem is related to the '\g', which your log4net is interpreting as another dateformat. Try deleting the ".yyyy-MM-dd.lo\g" and replacing it with "yyyy-MM-dd"

The ".log" doesn't belong in the dateformat

Answer 3

I use the following:

<param name="DatePattern" value="yyyy.MM.dd.\l\o\g"/>

With this I get filenames like: 2009.02.23.log

Answer 4

It's a permission problem. At least that's what's happening to me.

I'm new in using Log4Net so I didn't know that it has internal logging but I found it so I tried turning internal logging on. I wasn't very sure what it's saying but here's what it looks like to me it's doing: 1. Append the date to the file name. 2. Try to access the file to write to it (failed). 3. Append the date to the file name again. 4. Successfully access the file (which has the weird file name now)

Before I know this, I was google-ing for the solution to this problem with keywords like what I have as a title on this stackoverflow question. There wasn't that much information out there. I found maybe one guy who said it happens to some people but never really explained why nor the solution. With this new information (+the internal error message from Log4Net), I was looking at different threads from the search engines. With that I found hints that it might be a permission problem.

It seems that the writing application doesn't have sufficient permission to the logs folder. The default identity of the application is usually NETWORK_SERVICE. After I give more permission (I gave it full control but i don't know what is the minimum to make it work) to the folder, it works just fine.

If anyone can explain this better than me, please feel free to edit.

Answer 5

This happens if there is a problem accessing the log file when you initialize the log system. It can happen if you initialize the log system twice, if you run your program while another copy is running and writing to the log file, or if you are editing the log file in a text editor. Basically anything that causes a write lock on the log file when log4net init runs.

Check your code for duplicate calls to log4net init - perhaps you are initializing in a constructor instead of in a singleton's static constructor or global init, for example.

This can also happen if you are running in a 'web garden' configuration and don't include the PID in the filename, because each different web server process tries to write to the same file. If using web gardens and writing to files, add the pid to the filename pattern so each server process gets its own file.

Answer 6

I run into the same problem. For me, it was a combination of using RollingFileAppender for my test logs, and running my NUnit tests with ReSharper.

It turns out that ReSharper uses two processes to run the tests:

which creates a race condition on the log file.

Now, if we change the log file name to include the process id:

<appender name="MyLog" type="log4net.Appender.RollingFileAppender">
  <file type="log4net.Util.PatternString" value="MyLog.pid.%processid" />
  <appendToFile value="true" />
  <rollingStyle value="Composite" />
  <maxSizeRollBackups value="10" />
  <maximumFileSize value="10MB" />
  <staticLogFileName value="false"/>
  <datePattern value="_yyyy-MM-dd'.log'"/>
  <layout type="log4net.Layout.PatternLayout">
    <conversionPattern value="%d{HH:mm:ss.fff} [%15.15t] %-5p '%40.40c' - %m%n" />
  </layout>
</appender>

the problem is solved. Each file gets its own, unique name:

MyLog.pid.5440_2010-10-13.log
MyLog.pid.1496_2010-10-13.log

Note the use of PatternString for 'type'.

Hope that helps.