开发者

Application_BeginRequest not being fired in stressed environment

开发者 https://www.devze.com 2023-01-30 09:06 出处:网络
We are obesrving strange problems when performing sress test of our applciation. We use Application_BeginRequest and Application_EndRequest to log the beginning and end of the web request, together, w

We are obesrving strange problems when performing sress test of our applciation. We use Application_BeginRequest and Application_EndRequest to log the beginning and end of the web request, together, with the thread id.

However, from our logs, we see that Application_Begin_REquest is not being fired:

We use the following code to do the logging in global.asax.cs:

protected void Application_BeginRequest(object sender, EventArgs e)
{
  string url = "";
  if (HttpContext.Current != null)  // this should alway be true
    url = HttpContext.Current.Request.Url.ToString();

  Dbg.WriteLine(String.Format("Request: {0} {1}", HttpContext.Current.Request.ServerVariables["REMOTE_ADDR"], url));

  // integration calls measurement
  HttpContext.Current.Items.Add("wcfElapsed", new TimeSpan());

}

protected void Application_EndRequest(Object sender, EventArgs e)
{
  string url = "";
  if (HttpContext.Current != null)  // this should alway be true
    url = HttpContext.Current.Request.Url.ToString();

  Dbg.WriteLine(String.Format("End request: {0} {1}", HttpContext.Current.Request.ServerVariables["REMOTE_ADDR"], url));
}

This is our log file. Urls are omitted The 00013 column is thread id.

  14.12.10 21:41:25.042 00013 00000            Request: 172.23.26.41 
  14.12.10 21:41:25.068 00013 00000            End request: 172.23.26.41 
  14.12.10 21:41:25.212 00013 00000            Request: 172.23.26.41 
  14.12.10 21:41:25.223 00013 00000            End request: 172.23.26.41 
  14.12.10 21:41:30.974 00013 00000            End request: 172.23.26.88 

You can see that there are two "End request" in the last two lines, but there is no (Begin) Reque开发者_JAVA技巧st for the last log line.

Our Dbg.WriteLine uses System.Diagnostics trace listeners to ouput data to the file.

Environment: Windows Server 2008 R2, ASP.NET 3.5

This only happens when performin stress test. CPU utilization is around 60%, there are max 10 concurent requests executing.

Any ideas, what could be wrong?

UPDATE: I have found out that some other also did have similar problems (althoug in different configuration: http://forums.iis.net/t/1154954.aspx) Matej

UPDATE#2: This night be related to fact, that Thread.GetHashCode() which is used to print out the thread identifier in our log fies could change. See ASP.NET - Thread.GetHashCode() changes


I think it could be down to debugging to file, not being able to handle all these events. Writing to file has its limitations.

I suggest using default debug trace which you can see in DebugView.


It's probably not that the BeginRequest is not firing so much as there may be an unhandled unexception that is causing System.Diagnostics to crash without terminating the request.

The best way I could recommend to find the problem would be to install IIS Debug Diagnostics and run a crash or hang report. You won't like it much because the thing gathers tons and tons of data, but if there is some sort of thread crash/hang it will definitely catch it.

Edit:
While implementing a backup logging event directly to a custom Event Log in the system event log, we found that under heavy stress the requests for permission to access the log were causing latency (our guess was that after a certain number of requests the active directory connector was unable to respond in a timely fashion) and ultimately exceptions. This appeared to run on a separate thread which we could see dumping. W3wp.exe continued to function and the page fulfilled its response duties, but we found that of 3 events that should have been logged, the events getting logged were inconsistent. We also found that the event log itself would become busy and throw an exception. We found this one because from time to time this exception presented itself to the user interface instead of vanishing with the others. Our end solution was to use a local account to provide permission to the library to reduce the requests on the domain policy. This even cleared up the event log being busy symptom. At that point we were so happy it was gone we did not pursue it further.

0

精彩评论

暂无评论...
验证码 换一张
取 消

关注公众号