Search code examples
winforms.net-6.0nlogmicrosoft-extensions-logging

NLog RichTextBoxTarget throws System.NullReferenceException after adding new FileTarget programmatically


My team and I have a Windows Form application which I am converting from .NET Framework 4.6.2 to .NET 6. We are using NLog through Microsoft.Extensions.Logging to write to a log file and a RichTextBox on the main application form. (Package versions: NLog.Extensions.Logging 5.3.2/NLog.Windows.Forms 5.2.0)

<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" autoReload="true" throwExceptions="false" internalLogFile="${basedir}/LogFiles/InternalLog.txt" internalLogLevel="Info">
  <extensions>
    <add assembly="NLog.Windows.Forms"/>
  </extensions>
  <targets>
    <default-wrapper xsi:type="AsyncWrapper" timeToSleepBetweenBatches="500" />
    <target name="file" xsi:type="File" layout="${longdate}|${level}|${message}|${exception}" fileName="${basedir}/LogFiles/file.txt" archiveAboveSize="1048576" archiveEvery="Day" maxArchiveFiles="21" archiveFileName="${basedir}/LogFiles/Errorlog/file.{####}.txt" archiveNumbering="Sequence" encoding="utf-8"/>
    <target name="trace" xsi:type="Trace" layout="${longdate}|${level}|${message}|${exception}" />
    <target name="richTextBox" xsi:type="RichTextBox" layout="${message}${exception}" controlName="rtbStatus" formName="BaseForm" allowAccessoryFormCreation="false" messageRetention="All" maxLines="10000"/>
  </targets>
  <rules>
    <logger name="ErrorLog" minlevel="Info" writeTo="file,trace,richTextBox"/>
  </rules>
</nlog>

The form itself is used to configure and run an underlying service which receives messages from a number of other application. For each application that users configure communication with we are also creating a FileTarget programmatically in order to generate a simulation file which can be used for debugging. These additional targets are setup as follows:

public NLogSimFileLogger(string category, string name)
{
    try
    {
        this._TargetName                        = category + "-" + name;
        FileTarget target                       = new FileTarget();
        target.Layout                           = "${message}";
        target.ReplaceFileContentsOnEachWrite   = false;
        target.ArchiveAboveSize                 = 1048576;
        target.ArchiveEvery                     = FileArchivePeriod.Day;
        target.MaxArchiveFiles                  = 21;
        target.ArchiveFileName                  = "${basedir}/LogFiles/Sims/" + category + "/" + name + "{####}.txt";
        target.ArchiveNumbering                 = ArchiveNumberingMode.Sequence;
        target.FileName                         = "${basedir}/LogFiles/Sims/" + category + "/" + name + ".sim";
        target.KeepFileOpen                     = true;
        target.ConcurrentWrites                 = true;
        target.Name                             = this._TargetName;

        LogManager.Configuration.AddRule(LogLevel.Debug, LogLevel.Fatal, target, this._TargetName);
        LogManager.ReconfigExistingLoggers();

        this._Logger = LoggerFactory.Create(configure => configure.AddNLog(LogManager.Configuration)).CreateLogger(this._TargetName);
    }
    catch(Exception ex)
    {
        ...
    }
}

When creating the target however we are getting a System.NullReferenceException when trying to access the TargetRichTextBox from the SendTheMessageToRichTextBox method inside of NLog.Windows.Forms.RichTextBox.

System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation.
 ---> System.NullReferenceException: Object reference not set to an instance of an object.
   at NLog.Windows.Forms.RichTextBoxTarget.SendTheMessageToRichTextBox(String logMessage, RichTextBoxRowColoringRule rule, LogEventInfo logEvent)
   --- End of inner exception stack trace ---
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Span`1& arguments, Signature sig, Boolean constructor, Boolean wrapExceptions)
   at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)
   at System.Delegate.DynamicInvokeImpl(Object[] args)
   at System.Delegate.DynamicInvoke(Object[] args)
   at System.Windows.Forms.Control.InvokeMarshaledCallbackDo(ThreadMethodEntry tme)
   at System.Windows.Forms.Control.InvokeMarshaledCallbackHelper(Object obj)
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
--- End of stack trace from previous location ---
   at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Windows.Forms.Control.InvokeMarshaledCallback(ThreadMethodEntry tme)
   at System.Windows.Forms.Control.InvokeMarshaledCallbacks()
   at System.Windows.Forms.Control.WndProc(Message& m)
   at System.Windows.Forms.TextBoxBase.WndProc(Message& m)
   at System.Windows.Forms.RichTextBox.WndProc(Message& m)
   at System.Windows.Forms.Control.ControlNativeWindow.OnMessage(Message& m)
   at System.Windows.Forms.Control.ControlNativeWindow.WndProc(Message& m)
   at System.Windows.Forms.NativeWindow.Callback(IntPtr hWnd, WM msg, IntPtr wparam, IntPtr lparam)
   at Interop.User32.DispatchMessageW(MSG& msg)
   at System.Windows.Forms.Application.ComponentManager.Interop.Mso.IMsoComponentManager.FPushMessageLoop(UIntPtr dwComponentID, msoloop uReason, Void* pvLoopData)
   at System.Windows.Forms.Application.ThreadContext.RunMessageLoopInner(msoloop reason, ApplicationContext context)
   at System.Windows.Forms.Application.ThreadContext.RunMessageLoop(msoloop reason, ApplicationContext context)
   at System.Windows.Forms.Application.Run(Form mainForm)
   at MyLibrary.SingleInstance..ctor(Form mainForm, SingleInstanceTypes type) in C:\SandBox\Libraries\UI\Lear.UI\SingleInstance.cs:line 104
   at MyApp.Program.Main(String[] args) in C:\Sandbox\LPS3Services\Projects\MessageRouter\LPS.MessageRouter.Monitor\Program.cs:line 38

Below is the interal log that is generate.

2023-07-28 11:56:40.0448 Info Message Template Auto Format enabled
2023-07-28 11:56:40.0564 Info Loading assembly name: NLog.Windows.Forms
2023-07-28 11:56:40.0767 Info NLog.Windows.Forms, Version=5.0.0.0, Culture=neutral, PublicKeyToken=5120e14c03d0593c. File version: 5.2.0.532. Product version: 5.2.0+2d57aed1aadb6fc0d0ffaa67674ba6ad00baf4cd. GlobalAssemblyCache: False
2023-07-28 11:56:40.1461 Info Registered target NLog.Targets.Wrappers.AsyncTargetWrapper(Name=file)
2023-07-28 11:56:40.1461 Info Registered target NLog.Targets.Wrappers.AsyncTargetWrapper(Name=trace)
2023-07-28 11:56:40.1461 Error Forbidden usage of RetentionStrategy (All) when MaxLines is not set
2023-07-28 11:56:40.1461 Info Registered target NLog.Targets.Wrappers.AsyncTargetWrapper(Name=richTextBox)
2023-07-28 11:56:40.1849 Info Validating config: TargetNames=file, trace, richTextBox, ConfigItems=30, FilePath=.\MyApp\bin\Debug\net6.0-windows\NLog.config
2023-07-28 11:56:40.2046 Info Form BaseForm not found, waiting for ReInitializeAllTextboxes.
2023-07-28 11:56:40.2113 Info Configuration initialized.
2023-07-28 11:56:40.2113 Info NLog, Version=5.0.0.0, Culture=neutral, PublicKeyToken=5120e14c03d0593c. File version: 5.2.2.1914. Product version: 5.2.2+51cc02a2dd780a9a01eb6747de52071d78e2f506. GlobalAssemblyCache: False
2023-07-28 11:56:40.5062 Info Executing ReInitializeAllTextboxes for Form MyApp.MainForm, Text: MainForm
2023-07-28 11:56:40.5062 Info Attaching target richTextBox_wrapped to textbox BaseForm.rtbStatus
2023-07-28 11:56:42.6583 Info Registered target NLog.Targets.FileTarget(Name=OPC-TagLog)
2023-07-28 11:56:42.6583 Info Validating config: TargetNames=file, trace, richTextBox, OPC-TagLog, ConfigItems=38, FilePath=.\MyApp\bin\Debug\net6.0-windows\NLog.config
2023-07-28 11:56:42.6583 Info Closing old configuration.
2023-07-28 11:56:42.7235 Info Validating config: TargetNames=file, trace, richTextBox, OPC-TagLog, ConfigItems=38, FilePath=.\MyApp\bin\Debug\net6.0-windows\NLog.config
2023-07-28 11:56:42.7235 Info Attaching target richTextBox_wrapped to textbox BaseForm.rtbStatus
2023-07-28 11:56:42.8612 Info Registered target NLog.Targets.FileTarget(Name=AS400-AS400 Resolution Connection Data Source0)
2023-07-28 11:56:42.8612 Info Validating config: Targets=5, ConfigItems=46, FilePath=.\MyApp\bin\Debug\net6.0-windows\NLog.config
2023-07-28 11:56:42.8612 Info Closing old configuration.
2023-07-28 11:56:42.8889 Info Validating config: Targets=5, ConfigItems=46, FilePath=.\MyApp\bin\Debug\net6.0-windows\NLog.config
2023-07-28 11:56:42.8889 Info Attaching target richTextBox_wrapped to textbox BaseForm.rtbStatus

We think that something is going wrong with another thread trying to write to NLog while the RichTextBoxTarget is being reinitialized after creating the new target.

We tried using LogManager.SuspendLogging around the creation of the new FileTarget however we still get the same error. We also removed the LogManager.ReconfigExistingLoggers line after creating the new logger but this also created the same error.

This seems to be specific to .NET 6 as prior to the upgrade we did not have this issue.


Solution

  • Updating to NLog.Windows.Forms v5.2.1 seems to have fixed the issue.