2

I set up logging with log4net a while back and just didn't think of a particular scenario.

At present I have a global config file. There is a RollingFileAppender and an AdonetAppender.

When only one instance of the program is running on the database then all is fine. Sometimes, two slightly different instances may be run on the same database. The appenders log the messages from both instances, but often (in the communal code) it is not possible to tell from which instance the message originated. Of course, I could add the instance name to the message or whatever, but it seems like a last resort.

My brain is like a fog. I think the solution should be rather simple, but I just can't think what would be best.

Could I create another appender, and "switch" during runtime which appender is being used based on the instance name?

Here is the config file:

<?xml version="1.0" encoding="utf-8" ?>
<log4net debug="true">

  <appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">
    <lockingModel type="log4net.Appender.FileAppender+MinimalLock" />
    <file value="D:\Medupi logs\CalcEngineLog.txt"/>
    <appendToFile value="true"/>
    <rollingStyle value="Size"/>
    <maxSizeRollBackups value="2"/>
    <maximumFileSize value="4MB"/>
    <staticLogFileName value="true"/>
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%date [%thread] %level %logger %location - %message%newline%exception"/>
    </layout>
    <filter type="log4net.Filter.LevelRangeFilter">
      <levelMin value="DEBUG"/>
      <levelMax value="FATAL"/>
    </filter>
    <filter type="log4net.Filter.DenyAllFilter" />
  </appender>  

  <appender name="AdoNetAppender" type="log4net.Appender.AdoNetAppender">
   <!-- <threshold value="Warn" /> -->
    <bufferSize value="1" />
    <connectionType value="System.Data.SqlClient.SqlConnection, System.Data, Version=1.0.3300.0, Culture=neutral, PublicKeyToken=b77a5c561934e089" />
    <connectionString value="" />
    <commandText value="INSERT INTO [Calculation Engine Log] ([Date],[Thread],[Level],[Logger],[Location],[Message],[Exception]) VALUES (@log_date, @thread, @log_level, @logger, @location, @message, @exception)" />
    <parameter>
      <parameterName value="@log_date" />
      <dbType value="DateTime" />
      <layout type="log4net.Layout.RawTimeStampLayout" />
    </parameter>
    <parameter>
      <parameterName value="@thread" />
      <dbType value="String" />
      <size value="255" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%thread" />
      </layout>
    </parameter>
    <parameter>
      <parameterName value="@log_level" />
      <dbType value="String" />
      <size value="50" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%level" />
      </layout>
    </parameter>
    <parameter>
      <parameterName value="@logger" />
      <dbType value="String" />
      <size value="255" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%logger" />
      </layout>
    </parameter>
    <parameter>
      <parameterName value="@location" />
      <dbType value="String" />
      <size value="255" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%location" />
      </layout>
    </parameter>
    <parameter>
      <parameterName value="@message" />
      <dbType value="String" />
      <size value="4000" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%message" />
      </layout>
    </parameter>
    <parameter>
      <parameterName value="@exception" />
      <dbType value="String" />
      <size value="2000" />
      <layout type="log4net.Layout.ExceptionLayout" />
    </parameter>
  </appender>  

  <root>
    <level value="Debug"/>
    <appender-ref ref="AdoNetAppender"/>
    <appender-ref ref="RollingFileAppender"/> 
    <appender-ref ref="DebugAppender"/>
  </root>

</log4net>

This is how it is configured in the start-up project:

private static readonly log4net.ILog log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);  


static void Main()
    {
        if (!log4net.LogManager.GetRepository().Configured)
        {
            log4net.Config.XmlConfigurator.ConfigureAndWatch(new FileInfo("C:\\Program Files\\Symplexity\\bin\\Log4NetSettingsGlobal.xml"));
        }
        ...
    }

Additional information

In production, a Windows Service is started and this checks a config file for which instances must be run on a cluster.

The individual instances each have a separate process:

foreach (var cluster in clusters) 
        {
        ProcessStartInfo startInfo = new ProcessStartInfo
            {
                CreateNoWindow = true,
                FileName = processFileName,

                WindowStyle = ProcessWindowStyle.Hidden,
                Arguments = string.Format("\"{0}\" \"{1}\"", cluster.Name, _ConfigPath)
            };

            _ClusterProcesses.Add(Process.Start(startInfo));               
        }

I assume I could add the appIdentifier (as per comments) to the Arguments of the startInfo?

Igavshne
  • 699
  • 7
  • 33
  • 1
    Since you need *some* kind of discriminating information, how about the process id (something like https://stackoverflow.com/q/1812880/5265292) but added to the log message instead of some filename? – grek40 Jul 19 '18 at 21:25

1 Answers1

2

Start by identifying the 2 application instances.
The easiest way to do so is to start each application instance with a unique commandline argument.
Start the first instance via eg. a .cmd file as MyApplication.exe instance1 and the second one as MyApplication.exe instance2.
Read this argument value from the args parameter of method Main.

static void Main(String[] args)
{
    String appIdentifier = args[0];
    // ...
}

Now you have multiple options.

Option 1: a shared Log4net configuration for both instances

Assign the appIdentifier to a Log4net context property.
The scope to use depends on your scenario, see the Log4net documentation.

log4net.GlobalContext.Properties["appIdentifier"] = appIdentifier;

RollingFileAppender

Include this context property in the layout of the RollingFileAppender via %property{appIdentifier}. Each logged line will now contain the appropriate appIdentifier value 'instance1' or 'instance2'.

<layout type="log4net.Layout.PatternLayout">
    <conversionPattern value="... %property{appIdentifier}  ..."/>
</layout>    

AdoNetAppender

First make sure that the table you are logging to contains a column to store the appIdentifier value, eg. column appIdentifier VARCHAR(25).

Extend the configuration of the AdoNetAppender with an extra parameter to match the appIdentifier property.

<parameter>
    <parameterName value="@appIdentifier"/>
    <dbType value="String" />
    <size value="25" />
    <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%property{appIdentifier}" />
    </layout>
</parameter>

Extend the SQL INSERT statement with the corresponding column name and parameter.

INSERT INTO [Calculation Engine Log] ([Date],[Thread],[Level],[Logger],[Location],[Message],[Exception],[appIdentifier]) 
VALUES (@log_date, @thread, @log_level, @logger, @location, @message, @exception, @appIdentifier)

Option 2: a separate Log4net configuration file for each instance

This is not a pretty as option 1 ... but still an option.

Make a separate xml configuration file for each instance by matching the file name with the appIdentifier commandline argument.

log4net.Config.XmlConfigurator.ConfigureAndWatch(new FileInfo("C:\\Program Files\\Symplexity\\bin\\" + appIdentifier + '.xml'));

RollingFileAppender

Configure a separate output file path for each instance.

For instance 1

<appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">
    ...
    <file value="D:\Medupi logs\Instance1.txt"/>    
    ...
 </appender>

For instance 2

<file value="D:\Medupi logs\Instance2.txt"/>     

AdoNetAppender

See option 1 about how to set up a column to store the appIdentifier.
Include a constant value as identifier in the SQL INSERT statement.

INSERT INTO [Calculation Engine Log] ([Date],[Thread],[Level],[Logger],[Location],[Message],[Exception],[appIdentifier]) 
VALUES (@log_date, @thread, @log_level, @logger, @location, @message, @exception, 'Instance1')

Do the same in the xml configuration file for instance2 with value 'Instance2'.


Option 3: a single named logger

If you are only using a single ILog instance throughout your application, retrieve it by name using the value of the appIdentifier.

The %logger marker of the RollingFileAppender and @logger marker of the AdoNetAppender will contain the value 'Instance1' or 'Instance2' respectively.

I am not a fan of using a single logger, but I often see it being practiced this way.

private static log4net.ILog log;

static void Main(String args)
{
    String appIdentifier = args[0];

    if (!log4net.LogManager.GetRepository().Configured)
    {
        log4net.Config.XmlConfigurator.ConfigureAndWatch(new FileInfo("C:\\Program Files\\Symplexity\\bin\\Log4NetSettingsGlobal.xml"));

        log = log4net.LogManager.GetLogger(appIdentifier); 
    }
    // ...
}

Option 4: a parametrized file name for the RollingFileAppender

This is an alternative option for the RollingFileAppender only, combine it with one of the options above for the AdoNetAppender.

Set the Log4net context property as explained in option 1.
It is possible to include such Log4net context properties in the path to the output file of the RollingFileAppender.

Doing so will generate a file 'Instance1.log' or 'Instance2.log' respectively.
(Instead of varying the file name, you can also apply this to the (sub)folder name.)

Not sharing the same output file between multipe application instances running concurrently might be a good idea if you are having or are concerned about locking and/or performance issues.

<appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">
    ...
    <file type="log4net.Util.PatternString" value="D:\Medupi logs\%property{appIdentifier}.log" /> 
    ...
 </appender> 
pfx
  • 20,323
  • 43
  • 37
  • 57
  • Thank you for all the options. I've started with option 1 and might have a look at 3 or 4 as well. The application is started by a Windows Service, and the different instances are only determined later and respective processes are started for each. So at first I set the appIdentifier to "Communal" and then when the instances are determined I set it to "Calc" or "TA" and it works inside the rest of the class. But then, when it uses another assembly, the appIdentifier turns to "(null)". How can I retain the correct appIdentifier for each instance? – Igavshne Jul 21 '18 at 15:21
  • This info is new and might affect which option to go for. So a service starts an .exe application? Do you pass an appIdentifier to it as commandline arg? Each instance needs to keep its own one. Maybe better to add this info with some code of where and how the service sets and passes the appid to a newly started application. – pfx Jul 21 '18 at 15:47
  • I've updated the post. Let me know if you need more detail. – Igavshne Jul 24 '18 at 20:31
  • You should indeed pass an `appId` via the `ProcessStartInfo Arguments` to the newly started `.exe` application. Within this application, you also have to configure `Log4net` as the code in your question shows, and also include the code of one of the options in this answer; eg. reading `appId` from `String[] args`. Your windows service and this newly started application are separate processes. You can run your `.exe` application from commandline to check whether logging works. – pfx Jul 24 '18 at 20:41
  • I've checked that it does run from the "start-up" project that can be used in the place of the Windows Service for debugging purposes. Still struggling to get it working from the Windows Service though. – Igavshne Jul 25 '18 at 18:34
  • Sorry, I do not completely understand. Do you struggle with passing the `appId` argument from the windows service to the newly started `.exe` application? – pfx Jul 25 '18 at 18:39
  • Yes, something like that, but it is working now (from the Windows Service). There are multiple start-up scenarios, so I need to check each of them. Your answer was excellent! You deserve the bounty. If there is still some problem, I will continue asking in the comments. Thank you! – Igavshne Jul 26 '18 at 10:01