NLog / NLog.Windows.Forms

NLog targets specific for Windows.Forms
BSD 3-Clause "New" or "Revised" License
44 stars 26 forks source link

RuntimeCallableWrapper error, when run other sta /com thread #33

Closed gitlsl closed 5 years ago

gitlsl commented 8 years ago

I create a sta thread(because I use COM interface), after the thread over, it will throw a exception 'RuntimeCallableWrapper'.

when I comment the target to rtb , no Exception throw ,so there may a mistake in 'NLog.Windows.Forms' !

304NotModified commented 8 years ago

Could you please post the full error, including stacktrace?

gitlsl commented 8 years ago

@304NotModified I am sorry, there are no stacktrace , only show a dialog like below

Transition into COM context 0x465608 for this RuntimeCallableWrapper failed with the following error: System call failed. (Exception from HRESULT: 0x80010100 (RPC_E_SYS_CALL_FAILED)). This is typically because the COM context 0x465608 where this RuntimeCallableWrapper was created has been disconnected or it is busy doing something else. Releasing the interfaces from the current COM context (COM context 0x465498). This may cause corruption or data loss. To avoid this problem, please ensure that all COM contexts/apartments/threads stay alive and are available for context transition, until the application is completely done with the RuntimeCallableWrappers that represents COM components that live inside them

just like this link click me

mikhail-barg commented 8 years ago

Well, I feel like it would be a problem to find the culpit without an actual code that reproduces the issue.

@gitlsl Could you please provide some minimal code sample that could be used to investigate the problem?

gitlsl commented 8 years ago

@mikhail-barg here is code when loop 99 is ok , loop 9999 will throw 'RuntimeCallableWrapper'

private async void start_Click(object sender, EventArgs e)
 {
        Thread t = new Thread(() =>
        {
            ILog log = LogManager.GetLogger("test");
            for (int i = 0; i < 9999; i++)
            {
                log.Info("test" + i);
            }
        });
        t.SetApartmentState( ApartmentState.STA);//actually no matter sta or mta
        t.Start();

        return;
}
<target xsi:type="RichTextBox" 
            name="rtb" 
            layout="${date:format=MM-dd HH\:mm\:ss}|${uppercase:${level}}|${message}"
            controlName="richTextBox1" 
            formName="Form_Main"
            useDefaultRowColoringRules ="true" maxLines="2000" autoScroll="true"/>

and Although I set rtb target async (in his parent) , but GUI will feign death when log fastly

mikhail-barg commented 7 years ago

OK, I finally was able to find time to have a look at this issue. As far as I understand the problem source, it's just overflowing the windows messaging queue. Here's the most similar problem with regard to RichTextBoxes, and solution proposed it to avoid calling textBox.ScrollToCaret();.

I've tried disaling the following block in the SendTheMessageToRichTextBox

            if (AutoScroll)
            {
                textBox.Select(textBox.TextLength, 0);
                textBox.ScrollToCaret();
            }

And with this, I was able to pump around 6000 log messages to the setup in the TestApplication. Trying to pump more mesages causes The CLR has been unable to transition from COM context […] for 60 seconds issue.

Wrapping the target in AsyncWrapper with Block overflow action allowed me to pump at least 50 000 messages through single RTB target with textBox.ScrollToCaret() disabled. But when textBox.ScrollToCaret() is enabled, AsyncWrapper indeed does not help as gitlsl wrote.

But it does help to use AsyncWrapper with Discard overflow action. Using

<target xsi:type="AsyncWrapper"
          name="async"
          overflowAction="Discard"
          queueLimit="50"
          timeToSleepBetweenBatches="50"
          batchSize="50">
          <target xsi:type="RichTextBox" ... />
</target>

allowed me to pump 50 000 messages in a cycle, without getting any exceptions. So this could be a workaround for such cases.

Another workaround could be to add some Thread.Sleep() call to break tight loop, but it appeared that it should be rather huge:

                    if (i % 50 == 0)
                    {
                        Thread.Sleep(1000);
                    }

Still I'm not sure what we should do regarding this problem from the library side.

It seems that using textBox.ScrollToCaret() degrades performance of the RTB significantly, but I haven't found any other reasonable way to scroll WinForms' RTB control. So we could do some batching on the target side, so we would issue ScrollToCaret() call only after some decent number of logging messages processed or some timeout expired, but this really looks like an overkill.

On the other hand, in my apps we are doing really lots of logging to RTB targets from multiple treads and don't have such issues. So it could be juts beause of explitictly running logging in a tight loop.

@304NotModified what do you think?

304NotModified commented 7 years ago

ScrollToCaret() call only after some decent number of logging messages processed or some timeout expired, but this really looks like an overkill.

Maybe we could make this configurable? That would be easier than creating discarding async stuff I guess. (only if this will fix the issue)

mikhail-barg commented 7 years ago

Well, removing ScrollToCaret() does not solve the issue completely (because sending lots of messages in a tight loop still causes the exception even without ScrollToCaret(), but it happens much later). So generally it's possible to overcome the problem with discarding AsyncWrapper with small limits, as I described above.

304NotModified commented 7 years ago

Well, removing ScrollToCaret() does not solve the issue completely

OK, that IMO it's unneeded to make this configurable

Another option is to catch the exception, and write a log to the internal log? and continue (maybe discard)

304NotModified commented 7 years ago

I think I can close this one, isn't it?

mikhail-barg commented 7 years ago

I've got no new ideas on this since last time.

304NotModified commented 5 years ago

Closing this due to inactivity. Please let us know if this still an issue and please provide the requested info - thanks!