The application pool for this site was getting disabled quite frequently and we found quite a few entries like the following in the event log:
Event Type: Error
Event Source: W3SVC
Event Category: None
Event ID: 1002
Date: 19/11/2008
Time: 15:20:23
User: N/A
Computer: <computername>
Description: Application pool ‘DefaultAppPool’ is being automatically disabled due to a series of failures in the process(es) serving that application pool
In this case the customer already had some debugging skills so when he called CSS he already had a few dumps available to analyze; they were some process shutdown dumps (taken on Kernel32!TerminateProcess), strangely we had no second chance dumps (maybe because of one of these reasons?) but they’ve been a good point to start from anyway.
First, let’s have a look at the exceptions:
0:000> !dumpheap -type Exception -stat
[...]
Statistics:
MT Count TotalSize Class Name
79333ed4 1 12 System.Text.DecoderExceptionFallback
79333e90 1 12 System.Text.EncoderExceptionFallback
79330d44 1 72 System.ExecutionEngineException
79330cb4 1 72 System.StackOverflowException
79330c24 1 72 System.OutOfMemoryException
7931ffd4 1 72 System.NullReferenceException
6610c7fc 1 84 System.Web.HttpUnhandledException
79330dd4 2 144 System.Threading.ThreadAbortException
79318afc 2 144 System.InvalidOperationException
7931740c 5 160 System.UnhandledExceptionEventHandler
Total 16 objects
Remember, a few special exceptions are loaded when the AppDomain is first created (see here) so let’s try to see if there is still something significant on the threads:
0:000> !threads
ThreadCount: 21
UnstartedThread: 0
BackgroundThread: 21
PendingThread: 0
DeadThread: 0
Hosted Runtime: no
PreEmptive GC Alloc Lock
ID OSID ThreadOBJ State GC Context Domain Count APT Exception
17 1 950 000f2580 1808220 Enabled 00000000:00000000 000eed48 0 MTA (Threadpool Worker)
27 2 1bfc 00100018 b220 Enabled 00000000:00000000 000eed48 0 MTA (Finalizer)
28 3 300 00117068 80a220 Enabled 00000000:00000000 000eed48 0 MTA (Threadpool Completion Port)
29 4 1cf4 0011a458 1220 Enabled 00000000:00000000 000eed48 0 Ukn
9 5 ec0 001702e0 220 Enabled 00000000:00000000 000eed48 0 Ukn
31 6 2414 00171f68 180b220 Enabled 00000000:00000000 000eed48 0 MTA (Threadpool Worker)
32 7 1f24 00172338 180b220 Enabled 00000000:00000000 000eed48 0 MTA (Threadpool Worker)
33 8 97c 001729e0 180b220 Enabled 00000000:00000000 000eed48 0 MTA (Threadpool Worker)
34 9 13bc 00173088 180b220 Enabled 00000000:00000000 000eed48 0 MTA (Threadpool Worker)
35 a 22f8 00173a50 180b220 Enabled 00000000:00000000 000eed48 0 MTA (Threadpool Worker)
36 b 1e60 00174540 180b220 Disabled 12445a64:124475b8 0011ab48 1 MTA (Threadpool Worker) System.StackOverflowException (1a0a00a4)
37 c 1c8c 00174cf8 180b220 Enabled 00000000:00000000 000eed48 0 MTA (Threadpool Worker)
15 d 1934 0017d040 880a220 Enabled 00000000:00000000 000eed48 0 MTA (Threadpool Completion Port)
7 e 2028 0017ece8 220 Enabled 00000000:00000000 000eed48 0 Ukn
8 f dbc 0016f280 220 Enabled 00000000:00000000 000eed48 0 Ukn
4 10 2298 05007008 220 Enabled 00000000:00000000 000eed48 0 Ukn
6 11 20c0 05004278 220 Enabled 00000000:00000000 000eed48 0 Ukn
3 12 c9c 05003b70 220 Enabled 00000000:00000000 000eed48 0 Ukn
5 13 1a84 04ff7a60 220 Enabled 00000000:00000000 000eed48 0 Ukn
2 14 253c 0d378ee0 220 Enabled 00000000:00000000 000eed48 0 Ukn
42 15 1760 0d38b3d8 220 Enabled 00000000:00000000 000eed48 0 Ukn
Dumping the managed stack for thread 36, the recursion is quite obvious:
0:036> !clrstack
OS Thread Id: 0x1e60 (36)
ESP EIP
04e94acc 77e42004 [FaultingExceptionFrame: 04e94acc]
04e95058 77e42004 [HelperMethodFrame: 04e95058]
04e950c4 65230cc1 System.Data.RBTree`1+TreePage[[System.__Canon, mscorlib]]..ctor(Int32)
04e950d4 65230abe System.Data.RBTree`1[[System.__Canon, mscorlib]].AllocPage(Int32)
04e950f8 652309fc System.Data.RBTree`1[[System.__Canon, mscorlib]].InitTree()
04e95108 65230961 System.Data.DataRowCollection..ctor(System.Data.DataTable)
04e95118 652307c2 System.Data.DataTable..ctor()
04e95134 65230535 System.Data.Common.DataTableMapping.GetDataTableBySchemaAction(System.Data.DataSet, System.Data.MissingSchemaAction)
04e95150 6523037c System.Data.ProviderBase.SchemaMapping..ctor(System.Data.Common.DataAdapter, System.Data.DataSet, System.Data.DataTable, System.Data.ProviderBase.DataReaderContainer, Boolean, System.Data.SchemaType, System.String, Boolean, System.Data.DataColumn, System.Object)
04e9519c 6522fbac System.Data.Common.DataAdapter.FillMappingInternal(System.Data.DataSet, System.Data.DataTable, System.String, System.Data.ProviderBase.DataReaderContainer, Int32, System.Data.DataColumn, System.Object)
04e951d0 6522fc1e System.Data.Common.DataAdapter.FillMapping(System.Data.DataSet, System.Data.DataTable, System.String, System.Data.ProviderBase.DataReaderContainer, Int32, System.Data.DataColumn, System.Object)
04e95218 6522f9e6 System.Data.Common.DataAdapter.FillFromReader(System.Data.DataSet, System.Data.DataTable, System.String, System.Data.ProviderBase.DataReaderContainer, Int32, Int32, System.Data.DataColumn, System.Object)
04e95270 6522f942 System.Data.Common.DataAdapter.Fill(System.Data.DataSet, System.String, System.Data.IDataReader, Int32, Int32)
04e952b4 65230105 System.Data.Common.DbDataAdapter.FillInternal(System.Data.DataSet, System.Data.DataTable[], Int32, Int32, System.String, System.Data.IDbCommand, System.Data.CommandBehavior)
04e9530c 65230010 System.Data.Common.DbDataAdapter.Fill(System.Data.DataSet, Int32, Int32, System.String, System.Data.IDbCommand, System.Data.CommandBehavior)
04e95350 6559401d System.Data.Common.DbDataAdapter.Fill(System.Data.DataSet, System.String)
04e95384 6678d11f System.Web.UI.WebControls.SqlDataSourceView.ExecuteSelect(System.Web.UI.DataSourceSelectArguments)
04e95424 6668f498 System.Web.UI.DataSourceView.Select(System.Web.UI.DataSourceSelectArguments, System.Web.UI.DataSourceViewSelectCallback)
04e95434 66792c0f System.Web.UI.WebControls.DataBoundControl.PerformSelect()
04e9544c 6679285e System.Web.UI.WebControls.BaseDataBoundControl.DataBind()
04e95458 667dcf35 System.Web.UI.WebControls.GridView.DataBind()
04e9545c 660e1ac3 System.Web.UI.WebControls.BaseDataBoundControl.EnsureDataBound()
04e95488 668ecdcd System.Web.UI.WebControls.BaseDataBoundControl.set_RequiresDataBinding(Boolean)
04e95498 667da23b System.Web.UI.WebControls.GridView.set_PageIndex(Int32)
04e954a8 0ad3e096 ASP.search_aspx.Gridview1_DataBound(System.Object, System.EventArgs)
04e959a8 667928ce System.Web.UI.WebControls.BaseDataBoundControl.OnDataBound(System.EventArgs)
04e959bc 66792b45 System.Web.UI.WebControls.DataBoundControl.OnDataSourceViewSelectCallback(System.Collections.IEnumerable)
04e959cc 6668f4a4 System.Web.UI.DataSourceView.Select(System.Web.UI.DataSourceSelectArguments, System.Web.UI.DataSourceViewSelectCallback)
04e959dc 66792c0f System.Web.UI.WebControls.DataBoundControl.PerformSelect()
04e959f4 6679285e System.Web.UI.WebControls.BaseDataBoundControl.DataBind()
04e95a00 667dcf35 System.Web.UI.WebControls.GridView.DataBind()
04e95a04 660e1ac3 System.Web.UI.WebControls.BaseDataBoundControl.EnsureDataBound()
04e95a30 668ecdcd System.Web.UI.WebControls.BaseDataBoundControl.set_RequiresDataBinding(Boolean)
04e95a40 667da23b System.Web.UI.WebControls.GridView.set_PageIndex(Int32)
04e95a50 0ad3e096 ASP.search_aspx.Gridview1_DataBound(System.Object, System.EventArgs)
04e95f50 667928ce System.Web.UI.WebControls.BaseDataBoundControl.OnDataBound(System.EventArgs)
04e95f64 66792b45 System.Web.UI.WebControls.DataBoundControl.OnDataSourceViewSelectCallback(System.Collections.IEnumerable)
04e95f74 6668f4a4 System.Web.UI.DataSourceView.Select(System.Web.UI.DataSourceSelectArguments, System.Web.UI.DataSourceViewSelectCallback)
04e95f84 66792c0f System.Web.UI.WebControls.DataBoundControl.PerformSelect()
04e95f9c 6679285e System.Web.UI.WebControls.BaseDataBoundControl.DataBind()
04e95fa8 667dcf35 System.Web.UI.WebControls.GridView.DataBind()
04e95fac 660e1ac3 System.Web.UI.WebControls.BaseDataBoundControl.EnsureDataBound()
04e95fd8 668ecdcd System.Web.UI.WebControls.BaseDataBoundControl.set_RequiresDataBinding(Boolean)
04e95fe8 667da23b System.Web.UI.WebControls.GridView.set_PageIndex(Int32)
04e95ff8 0ad3e096 ASP.search_aspx.Gridview1_DataBound(System.Object, System.EventArgs)
[...]04ebea70 0ad3e096 ASP.search_aspx.Gridview1_DataBound(System.Object, System.EventArgs)
04ebef70 667928ce System.Web.UI.WebControls.BaseDataBoundControl.OnDataBound(System.EventArgs)
04ebef84 66792b45 System.Web.UI.WebControls.DataBoundControl.OnDataSourceViewSelectCallback(System.Collections.IEnumerable)
04ebef94 6668f4a4 System.Web.UI.DataSourceView.Select(System.Web.UI.DataSourceSelectArguments, System.Web.UI.DataSourceViewSelectCallback)
04ebefa4 66792c0f System.Web.UI.WebControls.DataBoundControl.PerformSelect()
04ebefbc 6679285e System.Web.UI.WebControls.BaseDataBoundControl.DataBind()
04ebefc8 667dcf35 System.Web.UI.WebControls.GridView.DataBind()
04ebefcc 660e1ac3 System.Web.UI.WebControls.BaseDataBoundControl.EnsureDataBound()
04ebeff8 660e1a57 System.Web.UI.WebControls.BaseDataBoundControl.OnPreRender(System.EventArgs)
04ebf008 667e07da System.Web.UI.WebControls.GridView.OnPreRender(System.EventArgs)
04ebf030 660abc21 System.Web.UI.Control.PreRenderRecursiveInternal()
04ebf048 660abc7c System.Web.UI.Control.PreRenderRecursiveInternal()
04ebf060 660abc7c System.Web.UI.Control.PreRenderRecursiveInternal()
04ebf078 660abc7c System.Web.UI.Control.PreRenderRecursiveInternal()
04ebf090 660abc7c System.Web.UI.Control.PreRenderRecursiveInternal()
04ebf0a8 660a7c4b System.Web.UI.Page.ProcessRequestMain(Boolean, Boolean)
04ebf200 660a77a4 System.Web.UI.Page.ProcessRequest(Boolean, Boolean)
04ebf238 660a76d1 System.Web.UI.Page.ProcessRequest()
04ebf270 660a7666 System.Web.UI.Page.ProcessRequestWithNoAssert(System.Web.HttpContext)
04ebf27c 660a7642 System.Web.UI.Page.ProcessRequest(System.Web.HttpContext)
04ebf290 0ad37afe ASP.search_aspx.ProcessRequest(System.Web.HttpContext)
04ebf2a0 660adb16 System.Web.HttpApplication+CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
04ebf2d4 6608132c System.Web.HttpApplication.ExecuteStep(IExecutionStep, Boolean ByRef)
04ebf314 6608c5c3 System.Web.HttpApplication+ApplicationStepManager.ResumeSteps(System.Exception)
04ebf364 660808ac System.Web.HttpApplication.System.Web.IHttpAsyncHandler.BeginProcessRequest(System.Web.HttpContext, System.AsyncCallback, System.Object)
04ebf380 66083e1c System.Web.HttpRuntime.ProcessRequestInternal(System.Web.HttpWorkerRequest)
04ebf3b4 66083ac3 System.Web.HttpRuntime.ProcessRequestNoDemand(System.Web.HttpWorkerRequest)
04ebf3c4 66082c5c System.Web.Hosting.ISAPIRuntime.ProcessRequest(IntPtr, Int32)
04ebf5d8 79f68cde [ContextTransitionFrame: 04ebf5d8]
04ebf60c 79f68cde [GCFrame: 04ebf60c]
04ebf768 79f68cde [ComMethodFrame: 04ebf768]
The next step is to find out why the OnDataBound event is firing over and over; here is the source code for the faulting page (simplified to show only the relevant bits):
Sub Page_Load(ByVal Sender As Object, ByVal E As EventArgs)
Dim cmd As String = "select * from products"
If Not IsPostBack Then
' when there is a blank search, display all products
If SearchString = "" Then
SqlDataSource1.SelectCommand = cmd
GridView1.DataBind()
Else
' when there are keywords (not a blank search)
' some logic to change the sql query
GridView1.DataBind()
If GridView1.Rows.Count < 3 Then ' displays suggestions if results are less then 3
For i = 0 To Keywords.Count - 1
' some logic to change the sql query
GridView1.DataBind()
Next
For i = 0 To FoundNewKeywords.Count - 1
For s = 0 To Keywords.Count - 1
' some logic to change the sql query
GridView1.DataBind()
Next
For j = i To FoundNewKeywords.Count - 1
' some logic to change the sql query
GridView1.DataBind()
If j = FoundNewKeywords.Count - 1 And FoundNewKeywords.Count > 2 Then
For m = j - 1 To 1 Step -1
' some logic to change the sql query
GridView1.DataBind()
Next
If i < 1 Then
For m = 2 To j - 1
' some logic to change the sql query
GridView1.DataBind()
Next
End If
End If
Next
Next
End If
End If
End If
End Sub
Sub Gridview1_DataBound(ByVal sender As Object, ByVal e As EventArgs)
' Some custom logic here
End Sub
From a high level perspective the intention was to start with a “return everything” query and refine it step by step taking into account keywords specified by the user and add logic to suggest other records that might interest the user. From an operation standpoint calling DataBind() multiple times means the whole data binding logic is executed over and over, such as the custom DataBound event handler: that way, depending on what we’re doing, we could exhaust the stack space which is what was happening in this case.
The solution is simple: there is no need to call DataBind() many times, just call it once after we have refined our query.
Carlo
Quote of the day:
To avoid situations in which you might make mistakes may be the biggest mistake of all. – Peter McWilliams