logging-log4net-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Victor Sergienko" <singa...@gmail.com>
Subject I believe I found a deadlock
Date Tue, 17 Jun 2008 15:35:49 GMT
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.

Mime
View raw message