Coworkers and I tracked down an issue today that has us baffled. If anyone can provide any insight, we'd love to hear it.
In a windows forms project (VS 2005 and 2008 at least) if you create a new timer and callback object with local variables, and an instance of an NLog Logger has been defined, eventually the callback stops being activated.
In other words, the timer will start up, and activate the callback on its interval for a certain number of iterations (varies by which machine you use, doesn't seem to matter what time interval the timer has set) and then the callback stops being called. On my machine it runs about 6 or 7 iterations, others it runs 5, others it runs 12.
This happens whether the callback method is calling a logger method or not, however if you comment out the logger instance entirely, the timer and callback work properly indefinitely.
If, however, you define the references to the timer and callback as member variables rather than local, everything seems to play nicely.
What we can't figure out is why NLog is making this happen, particularly when all you have to do is DEFINE a logger, not even use it.
Here is the code that FAILS:
using System;
using System.Windows.Forms;
using NLog;
namespace WindowsFormsApplication6
{
public partial class Form1 : Form
{
private Logger Log = LogManager.GetLogger( "" );
private int iCount = 0;
public Form1()
{
<nabble_a href="WindowsFormsApplication6.zip">WindowsFormsApplication6.zip</nabble_a><nabble_a href="NLog.config">NLog.config</nabble_a> InitializeComponent();
System.Threading.TimerCallback tcb = new System.Threading.TimerCallback(callback);
System.Threading.Timer t = new System.Threading.Timer(tcb, null, 0, 10);
}
private void callback( object o )
{
++iCount;
Log.Trace( "iCount {0}", iCount ); // Fails with or without this line
Console.WriteLine( "iCount {0}", iCount );
}
}
}
This code works, because NLog has been removed entirely:
using System;
using System.Windows.Forms;
using NLog;
namespace WindowsFormsApplication6
{
public partial class Form1 : Form
{
private int iCount = 0;
public Form1()
{
InitializeComponent();
System.Threading.TimerCallback tcb = new System.Threading.TimerCallback(callback);
System.Threading.Timer t = new System.Threading.Timer(tcb, null, 0, 1);
}
private void callback( object o )
{
++iCount;
Console.WriteLine( "iCount {0}", iCount );
}
}
}
And this code is the final solution that works WITH NLog because the variables are members rather than local to the construtor method:
using System;
using System.Windows.Forms;
using NLog;
namespace WindowsFormsApplication6
{
public partial class Form1 : Form
{
private Logger Log = LogManager.GetLogger( "" );
private int iCount = 0;
System.Threading.TimerCallback tcb = null;
System.Threading.Timer t = null;
public Form1()
{
InitializeComponent();
tcb = new System.Threading.TimerCallback(callback);
t = new System.Threading.Timer(tcb, null, 0, 1);
}
private void callback( object o )
{
++iCount;
Log.Trace( "iCount {0}", iCount );
Console.WriteLine( "iCount {0}", iCount );
}
}
}
Here is the NLog.config file we are using (we've played around with different config settings to no avail, and nlog is not producing an internal error log):
<?xml version="1.0" ?>
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
internalLogFile="${basedir}/logs/nlogInternal.txt"
internalLogLevel="Warn" >
<targets async="false">
<target name="file"
xsi:type="File"
fileName="${basedir}/MyLog.log"
layout="${longdate}: ${message}"
keepFileOpen="false"
encoding="iso-8859-2" />
</targets>
<rules>
<logger name="*" minlevel="Trace" writeTo="file" />
</rules>
</nlog>
If anyone can provide some insight into WHY this is happening, we would appreciate it. I tried to attached a zip file with the actual project, but that doesn't seem to be working properly....
Thanks,
Corin
