You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4net-dev@logging.apache.org by Vivek Sharma <Vi...@NIIT-tech.com> on 2007/12/05 13:04:13 UTC

Hello there

 

Hello,

 

We, at NIIT technologies are working for a very important client of ours
and are using log4net in a project whose description is as follows-

 

 

There is an ASP.NET website created for UI. This website is a client to
web services. The ASP.NET website uses log4net to log the events to the
SQL Server database. Log4net has been configured to collect 1000 entries
and then write them in a batch to the database.

 

The problem-

Occasionally we encounter thread contention problem in the web server
and then the site crashes since w3wp process gets killed and gets
created again due to the deadlocks. This causes all the current sessions
to be killed after going into hang for  along time. When we investigated
the problem we came across following stack trace-

 

<snip>

 

OS Thread Id: 0x1ca4 (50)

 

ESP       EIP     

 

1d42e200 7c8285ec [GCFrame: 1d42e200] 

 

1d42e338 7c8285ec [HelperMethodFrame: 1d42e338]

System.Threading.Monitor.Enter(System.Object)

 

1d42e38c 1b2e9601

log4net.Appender.AppenderSkeleton.DoAppend(log4net.Core.LoggingEvent)

 

1d42e3c0 1b2e94f1
log4net.Util.AppenderAttachedImpl.AppendLoopOnAppenders(log4net.Core.Log

gingEvent)

 

1d42e408 1b2e9210
log4net.Repository.Hierarchy.Logger.CallAppenders(log4net.Core.LoggingEv

ent)

 

1d42e440 1b2e9115
log4net.Repository.Hierarchy.Logger.ForcedLog(System.Type,

log4net.Core.Level, System.Object, System.Exception)

 

1d42e45c 1b2e908c log4net.Repository.Hierarchy.Logger.Log(System.Type,

log4net.Core.Level, System.Object, System.Exception)

 

1d42e490 1b2e9033 log4net.Core.LogImpl.Info(System.Object,

System.Exception)

 

1d42e4a0 1b2e8e34
Com.Emirates.Pss.Ibe.CommonHelper.IBELogger.LogInfo(System.String,

System.String)

 

1d42e4b8 1b2ec725 CacheData.LogCacheInfo(System.String)

 

1d42e4cc 1bd907ce CacheData.CachingResx(System.String)

 

1d42e514 1bc7fd94 ResxBind.IsIBEResxMasterExist(System.String)

 

1d42e53c 1bc7fadf ResxBind.GetResxData(System.String, System.String)

 

1d42e574 1bc7e64f SearchAvailability.Page_Load(System.Object,

System.EventArgs)

 

1d42e674 698a1928
System.Web.Util.CalliHelper.EventArgFunctionCaller(IntPtr,

System.Object, System.Object, System.EventArgs)

 

1d42e684 6891d73f
System.Web.Util.CalliEventHandlerDelegateProxy.Callback(System.Object,

System.EventArgs)

 

1d42e6c0 01d8aea5 [MulticastFrame: 1d42e6c0]
System.EventHandler.Invoke(System.Object, System.EventArgs)

 

1d42e6d4 687ca5a4 System.Web.UI.Control.OnLoad(System.EventArgs)

 

1d42e6e4 687ca5f0 System.Web.UI.Control.LoadRecursive()

 

1d42e6f8 687dbbf6 System.Web.UI.Page.ProcessRequestMain(Boolean,

Boolean)

 

1d42e8b0 687db521 System.Web.UI.Page.ProcessRequest(Boolean, Boolean)

 

1d42e8e0 687db487 System.Web.UI.Page.ProcessRequest()

 

1d42e918 687db3a7

System.Web.UI.Page.ProcessRequestWithNoAssert(System.Web.HttpContext)

 

1d42e920 687db33a

System.Web.UI.Page.ProcessRequest(System.Web.HttpContext)

 

1d42e934 1b896865

ASP.ibe_searchavailability_aspx.ProcessRequest(System.Web.HttpContext)

 

1d42e938 686888df
System.Web.HttpApplication+CallHandlerExecutionStep.System.Web.HttpAppli

cation.IExecutionStep.Execute()

 

1d42e96c 6865a071 System.Web.HttpApplication.ExecuteStep(IExecutionStep,

Boolean ByRef)

 

1d42e9ac 6865a39b

System.Web.HttpApplication.ResumeSteps(System.Exception)

 

1d42e9f4 6865912d
System.Web.HttpApplication.System.Web.IHttpAsyncHandler.BeginProcessRequ

est(System.Web.HttpContext, System.AsyncCallback, System.Object)

 

1d42ea10 6865e0bd
System.Web.HttpRuntime.ProcessRequestInternal(System.Web.HttpWorkerReque

st)

 

1d42ea44 6865dd72
System.Web.HttpRuntime.ProcessRequestNoDemand(System.Web.HttpWorkerReque

st)

 

1d42ea50 6865c447 System.Web.Hosting.ISAPIRuntime.ProcessRequest(IntPtr,

Int32)

 

1d42ec00 79f1ef33 [ContextTransitionFrame: 1d42ec00] 

 

1d42ec50 79f1ef33 [GCFrame: 1d42ec50] 

 

1d42eda8 79f1ef33 [ComMethodFrame: 1d42eda8]

 

</snip>

 

 

This shows that DoAppend method submits the object containing it to the
System monitor.

We downloaded he code and realized that it has been done for making the
collection of LogEntries thread safe. However, logging 1000 entries
takes time and next request tries to log new entries. This results in
thread contention and deadlock for a long time. 

 

We look forward to getting your valuable inputs on this issue. How can
we best optimize the settings etc to reduce this contention window and
minimize the number of hits to the database.

 

 

 

Regards

Vivek Sharma

vivek.sharma@niit-tech.com

NIIT Technologies

A-44 Mohan Cooperative,

Mathura Road,

New Delhi -110041.

 

 

 

 

 

 

 

 

 

 

 

 

----------------------------------------------------------------------
DISCLAIMER

This email and any files transmitted with it are confidential and are solely for the use of the individual or entity to which it is addressed. Any use, distribution, copying or disclosure by any other person is strictly prohibited. If you receive this transmission in error, please notify the sender by reply email and then destroy the message. Opinions, conclusions and other information in this message that do not relate to official business of the company shall be understood to be neither given nor endorsed by NIIT Ltd. or NIIT Technologies Ltd. Any information contained in this email, when addressed to Clients is subject to the terms and conditions in governing client contract.


RE: Hello there

Posted by Vivek Sharma <Vi...@NIIT-tech.com>.
 

Hello,

 

We, at NIIT technologies are working for a very important client of ours
and are using log4net in a project whose description is as follows-

 

 

There is an ASP.NET website created for UI. This website is a client to
web services. The ASP.NET website uses log4net to log the events to the
SQL Server database. Log4net has been configured to collect 1000 entries
and then write them in a batch to the database.

 

The problem-

Occasionally we encounter thread contention problem in the web server
and then the site crashes since w3wp process gets killed and gets
created again due to the deadlocks. This causes all the current sessions
to be killed after going into hang for  along time. When we investigated
the problem we came across following stack trace-

 

<snip>

 

OS Thread Id: 0x1ca4 (50)

 

ESP       EIP     

 

1d42e200 7c8285ec [GCFrame: 1d42e200] 

 

1d42e338 7c8285ec [HelperMethodFrame: 1d42e338]

System.Threading.Monitor.Enter(System.Object)

 

1d42e38c 1b2e9601

log4net.Appender.AppenderSkeleton.DoAppend(log4net.Core.LoggingEvent)

 

1d42e3c0 1b2e94f1
log4net.Util.AppenderAttachedImpl.AppendLoopOnAppenders(log4net.Core.Log

gingEvent)

 

1d42e408 1b2e9210
log4net.Repository.Hierarchy.Logger.CallAppenders(log4net.Core.LoggingEv

ent)

 

1d42e440 1b2e9115
log4net.Repository.Hierarchy.Logger.ForcedLog(System.Type,

log4net.Core.Level, System.Object, System.Exception)

 

1d42e45c 1b2e908c log4net.Repository.Hierarchy.Logger.Log(System.Type,

log4net.Core.Level, System.Object, System.Exception)

 

1d42e490 1b2e9033 log4net.Core.LogImpl.Info(System.Object,

System.Exception)

 

1d42e4a0 1b2e8e34
Com.Emirates.Pss.Ibe.CommonHelper.IBELogger.LogInfo(System.String,

System.String)

 

1d42e4b8 1b2ec725 CacheData.LogCacheInfo(System.String)

 

1d42e4cc 1bd907ce CacheData.CachingResx(System.String)

 

1d42e514 1bc7fd94 ResxBind.IsIBEResxMasterExist(System.String)

 

1d42e53c 1bc7fadf ResxBind.GetResxData(System.String, System.String)

 

1d42e574 1bc7e64f SearchAvailability.Page_Load(System.Object,

System.EventArgs)

 

1d42e674 698a1928
System.Web.Util.CalliHelper.EventArgFunctionCaller(IntPtr,

System.Object, System.Object, System.EventArgs)

 

1d42e684 6891d73f
System.Web.Util.CalliEventHandlerDelegateProxy.Callback(System.Object,

System.EventArgs)

 

1d42e6c0 01d8aea5 [MulticastFrame: 1d42e6c0]
System.EventHandler.Invoke(System.Object, System.EventArgs)

 

1d42e6d4 687ca5a4 System.Web.UI.Control.OnLoad(System.EventArgs)

 

1d42e6e4 687ca5f0 System.Web.UI.Control.LoadRecursive()

 

1d42e6f8 687dbbf6 System.Web.UI.Page.ProcessRequestMain(Boolean,

Boolean)

 

1d42e8b0 687db521 System.Web.UI.Page.ProcessRequest(Boolean, Boolean)

 

1d42e8e0 687db487 System.Web.UI.Page.ProcessRequest()

 

1d42e918 687db3a7

System.Web.UI.Page.ProcessRequestWithNoAssert(System.Web.HttpContext)

 

1d42e920 687db33a

System.Web.UI.Page.ProcessRequest(System.Web.HttpContext)

 

1d42e934 1b896865

ASP.ibe_searchavailability_aspx.ProcessRequest(System.Web.HttpContext)

 

1d42e938 686888df
System.Web.HttpApplication+CallHandlerExecutionStep.System.Web.HttpAppli

cation.IExecutionStep.Execute()

 

1d42e96c 6865a071 System.Web.HttpApplication.ExecuteStep(IExecutionStep,

Boolean ByRef)

 

1d42e9ac 6865a39b

System.Web.HttpApplication.ResumeSteps(System.Exception)

 

1d42e9f4 6865912d
System.Web.HttpApplication.System.Web.IHttpAsyncHandler.BeginProcessRequ

est(System.Web.HttpContext, System.AsyncCallback, System.Object)

 

1d42ea10 6865e0bd
System.Web.HttpRuntime.ProcessRequestInternal(System.Web.HttpWorkerReque

st)

 

1d42ea44 6865dd72
System.Web.HttpRuntime.ProcessRequestNoDemand(System.Web.HttpWorkerReque

st)

 

1d42ea50 6865c447 System.Web.Hosting.ISAPIRuntime.ProcessRequest(IntPtr,

Int32)

 

1d42ec00 79f1ef33 [ContextTransitionFrame: 1d42ec00] 

 

1d42ec50 79f1ef33 [GCFrame: 1d42ec50] 

 

1d42eda8 79f1ef33 [ComMethodFrame: 1d42eda8]

 

</snip>

 

 

This shows that DoAppend method submits the object containing it to the
System monitor.

We downloaded he code and realized that it has been done for making the
collection of LogEntries thread safe. However, logging 1000 entries
takes time and next request tries to log new entries. This results in
thread contention and deadlock for a long time. 

 

We look forward to getting your valuable inputs on this issue. How can
we best optimize the settings etc to reduce this contention window and
minimize the number of hits to the database.

 

 

 

Regards

Vivek Sharma

vivek.sharma@niit-tech.com

NIIT Technologies

A-44 Mohan Cooperative,

Mathura Road,

New Delhi -110041.

 

 

 

 

 

 

 

 

 

 

 

 

----------------------------------------------------------------------
DISCLAIMER

This email and any files transmitted with it are confidential and are
solely for the use of the individual or entity to which it is addressed.
Any use, distribution, copying or disclosure by any other person is
strictly prohibited. If you receive this transmission in error, please
notify the sender by reply email and then destroy the message. Opinions,
conclusions and other information in this message that do not relate to
official business of the company shall be understood to be neither given
nor endorsed by NIIT Ltd. or NIIT Technologies Ltd. Any information
contained in this email, when addressed to Clients is subject to the
terms and conditions in governing client contract.

----------------------------------------------------------------------
DISCLAIMER

This email and any files transmitted with it are confidential and are solely for the use of the individual or entity to which it is addressed. Any use, distribution, copying or disclosure by any other person is strictly prohibited. If you receive this transmission in error, please notify the sender by reply email and then destroy the message. Opinions, conclusions and other information in this message that do not relate to official business of the company shall be understood to be neither given nor endorsed by NIIT Ltd. or NIIT Technologies Ltd. Any information contained in this email, when addressed to Clients is subject to the terms and conditions in governing client contract.