63
votes

I have a program that makes many log4net calls to the "myprogram" loggers. It also calls other code that makes log4net calls to other loggers. I want to capture all logs higher than INFO for "myprogram" and all logs higher than WARN for everything else. This way, I get the work-in-progress messages specific to the task I'm working on, but am still notified of potentially bad things happening in the supporting code. I want this sent to both Console and a log file.

I have the following log4net config:

<log4net>
    <root>
        <level value="WARN" />
        <appender-ref ref="Console" />
        <appender-ref ref="LogFile" />
    </root>
    <logger name="myprogram">
        <level value="INFO" />
        <appender-ref ref="Console" />
        <appender-ref ref="LogFile" />
    </logger>
    <appender name="Console" type="log4net.Appender.ConsoleAppender">
        <layout type="log4net.Layout.PatternLayout">
            <conversionPattern value="%message%newline" />
        </layout>
        <threshold value="INFO" />
    </appender>
    <appender name="LogFile" type="log4net.Appender.RollingFileAppender">
        <layout type="log4net.Layout.PatternLayout">
            <conversionPattern value="- %utcdate %level %logger %ndc %thread %message%newline" />
        </layout>
        <appendToFile value="false" />
        <staticLogFileName value="true" />
        <rollingStyle value="Once" />
        <file value="mylogfile" />
        <immediateFlush value="true" />
        <threshold value="INFO" />
        <lockingModel type="log4net.Appender.FileAppender+MinimalLock" />
    </appender>
</log4net>

This makes perfect sense to me: log >WARN for everything and >INFO for the specific "myprogram" logger.

The problem is that I'm getting INFO messages logged twice on both Console and LogFile. This only happens if I have both the <root> and <logger> elements filled though; if I remove either one, then the remaining one works as I expect.

I could understand if I was getting double-logging of WARN entries (since myprogram matches both "root" and "myprogram"), but it's happening at INFO even though ROOT is (presumably) set to WARN.

Am I doing something wrong here, or is this a log4net bug/ambiguity?

2

2 Answers

80
votes

You are getting duplicated because you are telling it to log messages twice. I wouldn't recommend using additivity here since you might experience some side effects, simply remove unnecessary configuration:

<root>
    <level value="WARN" />
    <appender-ref ref="Console" />
    <appender-ref ref="LogFile" />
</root>
<logger name="myprogram">
    <level value="INFO" />
</logger>

You don't need to indicate the appender-ref in the logger myprogram since it will inherit them from the root logger; if you specify them again it will log twice.

71
votes

Try with this change, setting additivity to false.

<root>
    <level value="WARN" />
    <appender-ref ref="Console" />
    <appender-ref ref="LogFile" />
</root>
<logger name="myprogram" additivity="false">
    <level value="INFO" />
    <appender-ref ref="Console" />
    <appender-ref ref="LogFile" />
</logger>