How do I eliminate duplicate logging in log4net?

Question

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?

score 83 · Accepted Answer · edited Oct 01 '13 at 12:15

83

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.

edited Oct 01 '13 at 12:15

Philipp M

1,877
7
27
38

answered Mar 19 '09 at 11:47

This worked well for me when I encountered the same problem. This avoids the additivity issue as well – Jeffrey Cameron Feb 25 '10 at 20:15
1

@Jeffrey are you aware of what the issues with using additivity are? I have not been successful in finding anything documented that Google knows about. – Tinister Sep 07 '10 at 15:07
@Tinister the additivity issue is having to set additivity=false (as in the question above) otherwise your output will be duplicated. – Jeffrey Cameron Sep 08 '10 at 15:08
1

@Jeffrey Yes but from I can tell, using "additivity=false" is also an acceptable solution to the OP's problem. Jam, in his or her answer, mentions that using additivty can produce "side-effects"; however, Jam's account seems to be deleted or something so I assume he will not available to respond. Your first comment seems to indicate you're also aware of these "side-effect" issues so I thought I'd ask. – Tinister Sep 08 '10 at 19:25
1

programmatically you can do this as follows: ((log4net.Repository.Hierarchy.Logger)log.Logger).Additivity = false; – FrankyHollywood Mar 14 '14 at 14:39

score 72 · Answer 2 · edited Oct 01 '13 at 12:20

72

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>

edited Oct 01 '13 at 12:20

Philipp M

1,877
7
27
38

answered Mar 16 '09 at 17:08

Eddie

53,828
22
125
145

2

This is a good way to ensure all messages logged against the 'myprogram' log does not bubble up to the root logger. – Llyle Feb 25 '11 at 11:00
Works for me; I want all log entries from a particular class to go to a different appender than the other classes. – David Keaveny Aug 05 '11 at 05:51
@jaminator: That's a difficult question to answer in the space of a comment, and I'm not entirely sure what you're asking. Are you asking why you might configure something like that? – Eddie Nov 11 '14 at 06:12

How do I eliminate duplicate logging in log4net?

2 Answers2

Linked