Hi gentlemen,
I have a code that hangs up under debugger from time to time.
There are two threads stopped, one stopped in TraceAppender.Append,
another in AppenderSkeleton.DoAppend trying to acquire lock(this).
There are two active Appenders, TraceAppender (for VisualStudio
console) and RollingLogFileAppender.
Thread stacks:
thread 1:
[In a sleep, wait, or join]
System.Windows.Threading.DispatcherSynchronizationContext.Wait(System.IntPtr[]
waitHandles, bool waitAll, int millisecondsTimeout)
System.Threading.SynchronizationContext.InvokeWaitMethodHelper(System.Threading.SynchronizationContext
syncContext, System.IntPtr[] waitHandles, bool waitAll, int
millisecondsTimeout)
[Native to Managed Transition]
[Managed to Native Transition]
log4net.Appender.TraceAppender.Append(log4net.Core.LoggingEvent
loggingEvent = {log4net.Core.LoggingEvent}) C#
log4net.Appender.AppenderSkeleton.DoAppend(log4net.Core.LoggingEvent
loggingEvent = {log4net.Core.LoggingEvent}) C#
log4net.Util.AppenderAttachedImpl.AppendLoopOnAppenders(log4net.Core.LoggingEvent
loggingEvent = {log4net.Core.LoggingEvent}) C#
log4net.Repository.Hierarchy.Logger.CallAppenders(log4net.Core.LoggingEvent
loggingEvent = {log4net.Core.LoggingEvent}) C#
log4net.Repository.Hierarchy.Logger.ForcedLog(System.Type
callerStackBoundaryDeclaringType = {System.RuntimeType},
log4net.Core.Level level = {log4net.Core.Level}, object message =
"[SettingsManager] - Searches loaded", System.Exception exception =
null) C#
log4net.Repository.Hierarchy.Logger.Log(System.Type
callerStackBoundaryDeclaringType = {System.RuntimeType},
log4net.Core.Level level = {log4net.Core.Level}, object message =
"[SettingsManager] - Searches loaded", System.Exception exception =
null) C#
log4net.Core.LogImpl.Info(object message = "[SettingsManager] -
Searches loaded") C#
stopped in
override protected void Append(LoggingEvent loggingEvent)
{
//
// Write the string to the Trace system
//
...
System.Diagnostics.Trace.Write(RenderLoggingEvent(loggingEvent),
loggingEvent.LoggerName);
thread 2:
[Managed to Native Transition]
> log4net.Appender.AppenderSkeleton.DoAppend(log4net.Core.LoggingEvent
> loggingEvent = {log4net.Core.LoggingEvent}) C#
log4net.Util.AppenderAttachedImpl.AppendLoopOnAppenders(log4net.Core.LoggingEvent
loggingEvent = {log4net.Core.LoggingEvent}) C#
log4net.Repository.Hierarchy.Logger.CallAppenders(log4net.Core.LoggingEvent
loggingEvent = {log4net.Core.LoggingEvent}) C#
log4net.Repository.Hierarchy.Logger.ForcedLog(System.Type
callerStackBoundaryDeclaringType = {System.RuntimeType},
log4net.Core.Level level = {log4net.Core.Level}, object message =
"[TreeView] - duplicate artifact found! Parent Internet Explorer
Favorites:INTSPEI::P-Navigator::Favorites::InternetExplorer::Root;C:\\Users\\vic\\Favorites,
child
http---strategywiki.org-wiki-StarCraft_II:INTSPEI::P-Navigator::Page;http://strategywiki.org/wiki/StarCraft_II,
position 7", System.Exception exception = null) C#
log4net.Repository.Hierarchy.Logger.Log(System.Type
callerStackBoundaryDeclaringType = {System.RuntimeType},
log4net.Core.Level level = {log4net.Core.Level}, object message =
"[TreeView] - duplicate artifact found! Parent Internet Explorer
Favorites:INTSPEI::P-Navigator::Favorites::InternetExplorer::Root;C:\\Users\\vic\\Favorites,
child
http---strategywiki.org-wiki-StarCraft_II:INTSPEI::P-Navigator::Page;http://strategywiki.org/wiki/StarCraft_II,
position 7", System.Exception exception = null) C#
log4net.Core.LogImpl.Error(object message = "[TreeView] - duplicate
artifact found! Parent Internet Explorer
Favorites:INTSPEI::P-Navigator::Favorites::InternetExplorer::Root;C:\\Users\\vic\\Favorites,
child
http---strategywiki.org-wiki-StarCraft_II:INTSPEI::P-Navigator::Page;http://strategywiki.org/wiki/StarCraft_II,
position 7") C#
stopped at
public void DoAppend(LoggingEvent loggingEvent)
{
// This lock is absolutely critical for correct
formatting
// of the message in a multi-threaded environment.
Without
// this, the message may be broken up into elements from
// multiple thread contexts (like get the wrong thread
ID).
lock(this)
...
Config file:
<?xml version="1.0" encoding="utf-8" ?>
<log4net debug="false">
<appender name="LogFileAppender" type="log4net.Appender.FileAppender" >
<file value="P-Navigator-log.txt" />
<appendToFile value="true" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date [%thread] %-5level -
%message%newline" />
</layout>
</appender>
<appender name="TraceAppender" type="log4net.Appender.TraceAppender" >
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%-5level: %message%newline" />
</layout>
</appender>
<appender name="RollingLogFileAppender"
type="log4net.Appender.RollingFileAppender">
<file value="P-Navigator-log.txt" />
<appendToFile value="true" />
<maxSizeRollBackups value="100" />
<maximumFileSize value="5MB" />
<rollingStyle value="Size" />
<staticLogFileName value="true" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date [%thread] %-5level - %message%newline" />
</layout>
</appender>
<root>
<level value="INFO" />
<appender-ref ref="RollingLogFileAppender" />
<appender-ref ref="TraceAppender" />
<!--appender-ref ref="HttpTraceAppender" /-->
<!-- <appender-ref ref="RollingLogFileAppender" /> -->
</root>
</log4net>
Thank you.
