Form hanging when RichTextBox target nonstop logging

[AlexisChung]

NLog version: (e.g. 4.6.8)

Platform: .Net 4.0

Current NLog config (xml or C#, if relevant)

<?xml version="1.0" encoding="utf-8" ?>
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
      xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
      autoReload="true">

  <targets async="true">
    <target name="TraceTarget" xsi:type="File"
            layout="${level:uppercase=true:padding=-5} ${date:format=yyyy\-MM\-dd\ HH\:mm\:ss\.fff} - ${message}"
            fileName="${basedir}/Log/${date:yyyyMMdd}_Trace.txt"
            maxarchivefiles="1"
            />
  </targets>

  <rules>
    <logger ruleName="Trace" name="Trace" minlevel="Debug" writeTo="TraceTarget" />
  </rules>
</nlog>

code

 RichTextBoxTarget _target = new RichTextBoxTarget
            {
                Name = targetName,
                Layout = "[${level:uppercase=true:padding=-5}]" +
                          "${date:format=yyyy\\-MM\\-dd\\ HH\\:mm\\:ss\\.fff} " +
                          "${message} " +
                          "${exception:innerFormat=tostring:maxInnerExceptionLevel=10:separator=,:format=tostring}",
                ControlName = richTextBoxName,
                FormName = formName,
                AutoScroll = true,
                MaxLines = Convert.ToInt32(CommonFunction.ReadSetting("RichTextBoxMaxLines")),
                UseDefaultRowColoringRules = true,
                CreatedForm = false,
                AllowAccessoryFormCreation = false,
            };

• What is the current result? I use RichTextBox target and when nonstop logging, the Form(WPF) will hanging (ex. i can't drag move the Form or i can't click any control on the Form), but the text of controls are working perfectly.
• What is the expected result? I would expect when nonstop logging, UI controls can be working.
• Did you checked the Internal log? Yes
• Please post full exception details (message, stacktrace, inner exceptions) None
• Are there any workarounds? No
• Is there a version in which it did work? Don't think so
• Can you help us by writing an unit test? Sorry, I don't know how to writing an unit test

[AlexisChung]

Hi all, i found the problem, in RichTextBoxTarget.cs

textbox.BeginInvoke(new DelSendTheMessageToRichTextBox(SendTheMessageToRichTextBox), logMessage, rule, logEvent);

i changed BeginInvoke--->Invoke. and it work perfectly.

[304NotModified]

Isn't the whole thing much slower with Invoke?

[snakefoot]

Sounds like Control.Invoke becomes a throttle, where the writing waits for the GUI to keep up:

• Control.Invoke: Executes on the UI thread, but calling thread waits for completion before continuing.
• Control.BeginInvoke: Executes on the UI thread, and calling thread doesn't wait for completion.

Maybe this change avoids filling up the window message-pump. But I think it should be optional. Think bulk insert would probably also help.

[mas-co]

This is the first time I used the NLog.Windows.Forms in a project and I ran into the same problem with the RichTextBox thread hanging when I barraged the logger.

Can anyone direct me toward a guide to manually compile NLog.Windows.Forms and manually add it to a solution with multiple projects (I am using .NET 4.7.2)? I was going to check the suggestion by AlexisChung).

Using NLog 4.6.8 with NLog.Windows.Forms 4.3.0

Below is a test I made to blast the logger. I am assuming that the RichTextBox target is supposed to be wrapped by an async wrapper like the regular NLog.Targets targets. (Both wrapped and unwrapped hang the UI).

using System;
using System.Collections.Generic;
using System.ComponentModel;
using System.Data;
using System.Drawing;
using System.Linq;
using System.Text;
using System.Threading.Tasks;
using System.Windows.Forms;

namespace WindowsFormsApp1
{
    public partial class Form1 : Form
    {
        static readonly NLog.Logger logger = NLog.LogManager.GetCurrentClassLogger();

        public Form1()
        {
            InitializeComponent();
        }

        private void Form1_Load(object sender, EventArgs e)
        {
            var config = NLog.LogManager.Configuration;
            if(config == null) { config = new NLog.Config.LoggingConfiguration();}

            var rtbTarget = new NLog.Windows.Forms.RichTextBoxTarget()
            {
                Name = "rtbTarget",
                FormName = this.Name,
                ControlName = rtbLogger.Name
            };

            var rtbTargetWrapper = new NLog.Targets.Wrappers.AsyncTargetWrapper()
            {
                Name = "rtbTargetWrapper",
                WrappedTarget = rtbTarget
            };

            NLog.Config.SimpleConfigurator.ConfigureForTargetLogging(rtbTargetWrapper, NLog.LogLevel.Trace);

            logger.Trace("Logger started.");
            KillTheWabbit(1000);
        }

        private void KillTheWabbit(int count)
        {
            for (int i = 0; i < count; i++)
            {
                logger.Trace("Kill the wabbit: {i}", i);
            }
        }
    }
}

[mas-co]

Isn't the whole thing much slower with Invoke?

Yes, but the form doesn't hang. I ran 3 cases with 10000 iterations:

1. Original the RichTextBox target: base time (140335 ms) (form "hangs")
2. Invoke Only RichTextBox target: 31% more time (184428 ms) (form is responsive)
3. Original RichTextBox target with BufferingWrapper 30% more time (182938 ms) (form "hangs")

[mpleis]

Saturating log events to the RichTextBox is consuming all the bandwidth and leaving other 'Main Thread' UI tasks waiting to get it's share.