Logging to an individual log file for each individ

Question

I have a service application that on startup reads an XML file and starts a thread for each entry in the XML file. Each thread creates an instance of a worker class which requires a logger to log any output to a thread specific log file.

In the services app.config I have the log4net configuration settings set to use an XML appender and the file is specified as a PatternString as shown below:

<appender name="XmlAppender" type="log4net.Appender.FileAppender">
  <file type="log4net.Util.PatternString" value="D:\Temp\Logs\%property{LogName}.log" />
  <immediateFlush value="true"/>
  <appendToFile value="true" />
  <layout type="log4net.Layout.SimpleLayout" />
</appender>

In a thread locked method for each instance of the worker class created I get the logger using the log4net.LogManager.GetLogger("MyLogger") method and then I set the current threads PatternStrings LogName property using ThreadContext.Properties["LogName"] = "Log name prefix".

All of the files are created but when the logger is called it just logs all message to one seemingly random file.

I have searched about for quite a while trying to find a solution or some answers to what I am doing wrong but I have had no luck.

Does anyone have any idea why this is happening?

Answer 1

Adam's answer has worked pretty well for me, but there is one this I would like to add. If there is a possibility of your logFileName being reused in your application, you will need to check to make sure the repository does not already exist.

string repoName = String.Format("{0}Repository", logFileName);

// Check for existing repository
ILoggerRepository[] allRepos = LogManager.GetAllRepositories();
ILoggerRepository repo = allRepos.Where(x => x.Name == repoName).FirstOrDefault();

// If repository does not exist, create one, set the logfile name, and configure it
if (repo == null)
{
    repo = LogManager.CreateRepository(repoName);
    ThreadContext.Properties[KEY_LOG_FILE] = logFileName;
    log4net.Config.XmlConfigurator.Configure(repo);
}

// Set logger
ILog logger = LogManager.GetLogger(repoName, logName);

Answer 2

I think I have worked out the issue. The steps follow:

• Create an an individual ILoggerRepository object (loggerRepository in this example) on each thread.
• Set the ThreadContexts property for the log file name.
• Use the XmlConfiguratior to configure the repository.
• Use the LogManager to Get the named logger (in the XML configuration file) using the named LoggerRepository for that thread.

In return I get a new configured logger pointing to the respective file for that thread.

The XML configuration is the same as it was originally and shown here for completeness:

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
  <configSections>    
    <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net"/>
  </configSections>
  <log4net>
    <logger name="ProductionLogger">
      <appender-ref ref="XmlAppender"/>      
      <level value="ALL"/>
    </logger>
    <appender name="XmlAppender" type="log4net.Appender.FileAppender">
      <file type="log4net.Util.PatternString" value="D:\Temp\Logs\%property{LogName}.log" />
      <immediateFlush value="true"/>
      <appendToFile value="true" />
      <layout type="log4net.Layout.SimpleLayout" />
    </appender>
  </log4net>
</configuration>

The code to create the loggers is below. Each time this code is run it is run in its own thread.

ILoggerRepository loggerRepository = LogManager.CreateRepository(logFileName + "Repository");
ThreadContext.Properties["LogName"] = logFileName;
log4net.Config.XmlConfigurator.Configure(loggerRepository);
ILog logger = LogManager.GetLogger(logFileName + "Repository", "ProductionLogger");

This seems to work with no issues so far. I will be moving forward with this solution for the moment but I will update this post if I find out anything else.

Answer 3

@Adam's solution helped me. For posterity here's simple code that creates 5 Tasks (using threads from the threadpool), where in each task each thread writes to a separate log file (and then sleeps for 1 second), five times.

.NET Framework 4.7.2
.NET Console Application

AssemblyInfo.cs

using System.Reflection;
using System.Runtime.CompilerServices;
using System.Runtime.InteropServices;

// General Information about an assembly is controlled through the following
// set of attributes. Change these attribute values to modify the information
// associated with an assembly.
[assembly: AssemblyTitle("LogfilePerThread")]
[assembly: AssemblyDescription("")]
[assembly: AssemblyConfiguration("")]
[assembly: AssemblyCompany("Microsoft")]
[assembly: AssemblyProduct("LogfilePerThread")]
[assembly: AssemblyCopyright("Copyright © Microsoft 2020")]
[assembly: AssemblyTrademark("")]
[assembly: AssemblyCulture("")]

// Setting ComVisible to false makes the types in this assembly not visible
// to COM components.  If you need to access a type in this assembly from
// COM, set the ComVisible attribute to true on that type.
[assembly: ComVisible(false)]

// The following GUID is for the ID of the typelib if this project is exposed to COM
[assembly: Guid("d3ec8b29-e701-424e-80d4-473e9fbb5572")]

// Version information for an assembly consists of the following four values:
//
//      Major Version
//      Minor Version
//      Build Number
//      Revision
//
// You can specify all the values or you can default the Build and Revision Numbers
// by using the '*' as shown below:
// [assembly: AssemblyVersion("1.0.*")]
[assembly: AssemblyVersion("1.0.0.0")]
[assembly: AssemblyFileVersion("1.0.0.0")]

Program.cs

using System;
using System.Threading;
using System.Threading.Tasks;
using log4net;
using log4net.Repository;

namespace LogfilePerThread
{
    class Program
    {
        static void Main(string[] args)
        {
            int nWorkers = 5; // 5 workers, 5 log files
            Task[] Workers = new Task[nWorkers];
            for (int i = 0; i < nWorkers; i++)
            {
                int i1 = i;
                Workers[i] = new Task(() => Work(i1));
                Workers[i].Start();
            }

            Task.WaitAll(Workers);
            Console.WriteLine("Main executed.");
        }

        public static void Work(int workerID)
        {
            // Make sure the directory where logfiles are written exists
            string logfileName = $"Worker{workerID}_TaskLog"; // Logfile extension & path specified in App.config
            ILoggerRepository repository = LogManager.CreateRepository($"{logfileName}Repository");
            ThreadContext.Properties["WorkerLoggerProperty"] = logfileName;
            log4net.Config.XmlConfigurator.Configure(repository);
            ILog log = LogManager.GetLogger($"{logfileName}Repository", "WorkerLogger"); // Use this logger object in thread

            // Do work: Log & Sleep
            for (int i = 0; i < 5; i++)
            {
                log.Info($"Logging from WorkerID={workerID} - Msg {i}");
                Thread.Sleep(1000);
            }
        }
    }
}

App.config

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
  <configSections>
    <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
  </configSections>

  <startup>
    <supportedRuntime version="v4.0" sku=".NETFramework,Version=v4.7.2" />
  </startup>

  <log4net>

    <logger name="WorkerLogger">
      <level value="DEBUG" />
      <appender-ref ref="RollingFile" />
    </logger>

    <appender name="RollingFile" type="log4net.Appender.RollingFileAppender">
      <file type="log4net.Util.PatternString" value="C:\logs\%property{WorkerLoggerProperty}.log" />
      <appendToFile value="true" />
      <immediateFlush value="true"/>
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%5level, %thread] %message%newline" />
      </layout>
    </appender>

  </log4net>

</configuration>

C:\logs\Worker0_TaskLog.log

2020-01-14 21:59:46,696 [ INFO, 3] Logging from WorkerID=0 - Msg 0
2020-01-14 21:59:47,714 [ INFO, 3] Logging from WorkerID=0 - Msg 1
2020-01-14 21:59:48,714 [ INFO, 3] Logging from WorkerID=0 - Msg 2
2020-01-14 21:59:49,714 [ INFO, 3] Logging from WorkerID=0 - Msg 3
2020-01-14 21:59:50,714 [ INFO, 3] Logging from WorkerID=0 - Msg 4

C:\logs\Worker1_TaskLog.log

2020-01-14 21:59:46,696 [ INFO, 4] Logging from WorkerID=1 - Msg 0
2020-01-14 21:59:47,714 [ INFO, 4] Logging from WorkerID=1 - Msg 1
2020-01-14 21:59:48,714 [ INFO, 4] Logging from WorkerID=1 - Msg 2
2020-01-14 21:59:49,714 [ INFO, 4] Logging from WorkerID=1 - Msg 3
2020-01-14 21:59:50,714 [ INFO, 4] Logging from WorkerID=1 - Msg 4

C:\logs\Worker2_TaskLog.log

2020-01-14 21:59:46,697 [ INFO, 5] Logging from WorkerID=2 - Msg 0
2020-01-14 21:59:47,713 [ INFO, 5] Logging from WorkerID=2 - Msg 1
2020-01-14 21:59:48,713 [ INFO, 5] Logging from WorkerID=2 - Msg 2
2020-01-14 21:59:49,713 [ INFO, 5] Logging from WorkerID=2 - Msg 3
2020-01-14 21:59:50,713 [ INFO, 5] Logging from WorkerID=2 - Msg 4

C:\logs\Worker3_TaskLog.log

2020-01-14 21:59:46,696 [ INFO, 6] Logging from WorkerID=3 - Msg 0
2020-01-14 21:59:47,714 [ INFO, 6] Logging from WorkerID=3 - Msg 1
2020-01-14 21:59:48,714 [ INFO, 6] Logging from WorkerID=3 - Msg 2
2020-01-14 21:59:49,714 [ INFO, 6] Logging from WorkerID=3 - Msg 3
2020-01-14 21:59:50,714 [ INFO, 6] Logging from WorkerID=3 - Msg 4

C:\logs\Worker4_TaskLog.log

2020-01-14 21:59:47,580 [ INFO, 7] Logging from WorkerID=4 - Msg 0
2020-01-14 21:59:48,580 [ INFO, 7] Logging from WorkerID=4 - Msg 1
2020-01-14 21:59:49,580 [ INFO, 7] Logging from WorkerID=4 - Msg 2
2020-01-14 21:59:50,580 [ INFO, 7] Logging from WorkerID=4 - Msg 3
2020-01-14 21:59:51,580 [ INFO, 7] Logging from WorkerID=4 - Msg 4