Why is logging to a log4net.ILog appending to multiple logs?

Question

I'm developing a plugin for a third-party application, and for each 'run' of this plugin I want an exclusive log file.

I've built the following class.

public class LogFileRepository
{
    private readonly Common.Configuration.Settings _configSettings;
    private const string InstanceName = "AutomationPlugin.Logging";
    private readonly ILoggerRepository _repository;


    public LogFileRepository (Common.Configuration.Settings configSettings)
    {
        _configSettings = configSettings;

        var repositoryName = $"{InstanceName}.Repository";
        _repository = LoggerManager.CreateRepository(repositoryName);
    }


    public ILog GetLog(string name)
    {
        var logger = LogManager.Exists(_repository.Name, name);
        if (logger != null)
        {
            return logger;
        }

        var filter = new LevelMatchFilter {LevelToMatch = Level.All};
        filter.ActivateOptions();
        var appender = new RollingFileAppender
                       {
                           AppendToFile = false,
                           DatePattern = "yyyy-MM-dd",
                           File = String.Format(_configSettings.Paths.LogFileTemplate, name),
                           ImmediateFlush = true,
                           Layout = new PatternLayout("%n%date{ABSOLUTE} | %-7p | %m"),
                           LockingModel = new FileAppender.MinimalLock(),
                           MaxSizeRollBackups = 1,
                           Name = $"{InstanceName}.{name}.Appender",
                           PreserveLogFileNameExtension = false,
                           RollingStyle = RollingFileAppender.RollingMode.Once
                       };
        appender.AddFilter(filter);
        appender.ActivateOptions();

        BasicConfigurator.Configure(_repository, appender);

        return LogManager.GetLogger(_repository.Name, name);
    }
}

What I intended this function to do is for the GetLog method to return a log file (with the specified name) if the LogManager already has one; if there isn't an existing log file then it should instantiate and return it.

This does happen. On the first run of the plugin a log file is created and written to; on a second run of the plugin a new log file is created and written to, but all messages are also written to the first log file. And on a third run all messages are written to the two existing log files as well as the new third log file.

Why? Is there something in the RollingFileAppender that I've seemingly misunderstood/misconfigured? I want an exclusive log file for each name parameter.

Does this get your job done: https://stackoverflow.com/a/18750639/982149 ? — Fildor, Sep 05 '18 at 12:07
@Fildor - Yes, the `_repository` is a private member variable on the class, and the code consuming this class is a singleton which instantiates the host class of `_repository` in its constructor. So there's one instance of the host class and therefore the same instance of `_repository`. Also, the name of the log is definitely different - otherwise I'd never see that second file being created. — awj, Sep 05 '18 at 13:07

score 2 · Accepted Answer · answered Sep 07 '18 at 14:07

Assuming you've created _repository using LogManager.CreateRepository(), this actually creates a Hierarchy, and when you configure this with your new appender via BasicConfigurator.Configure(_repository, appender); this adds the appender to the Hierarchy's Root appender collection.

All loggers then created from the repository are child loggers of the "Root" and are configured to be "additive" in that they append to all appenders defined directly against them, and any of their parent loggers, all the way up to the Root. In your case the loggers themselves have no appenders of their own, so are just picking up appenders from the Root, which in your case contains all the appenders. As a result all messages get logged to every file.

What you want to do is to attach the appender to its specific logger, and disable additivity so that it doesn't then log to appenders higher in the hierarchy. There doesn't appear to be a "nice" way to do this, but the following worked in my testing:

...
appender.AddFilter(filter);
appender.ActivateOptions();

// Add the appender directly to the logger and prevent it picking up parent appenders
if (LoggerManager.GetLogger(_repository.Name, name) is Logger loggerImpl)
{
    loggerImpl.Additivity = false;
    loggerImpl.AddAppender(appender);
}

BasicConfigurator.Configure(_repository, appender);
return LogManager.GetLogger(_repository.Name, name);

Why is logging to a log4net.ILog appending to multiple logs?

1 Answers1