Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

One ASP.NET app (accidentally) in multiple app domains or frequent app recycing

I'm debugging an ASP.NET application which is seemingly randomly losing the content of some static fields. I did some simple custom logging (because even log4net was flaky), and found out that the application is being loaded into two app domains. Here is a snippet from the log:

6/27/2011 9:01:01 PM /LM/W3SVC/1/ROOT/MyApp-1-129537072581658334: log message 1
6/27/2011 9:01:01 PM /LM/W3SVC/1/ROOT/MyApp-1-129537072581658334: log message 2
6/27/2011 9:01:01 PM /LM/W3SVC/1/ROOT/MyApp-1-129537072581658334: log message 3
6/27/2011 9:01:01 PM /LM/W3SVC/1/ROOT/MyApp-1-129537072581658334: log message 4
6/27/2011 9:01:02 PM /LM/W3SVC/1/ROOT/MyApp-4-129537072620628334: log message 5 <-
6/27/2011 9:01:02 PM /LM/W3SVC/1/ROOT/MyApp-4-129537072620628334: log message 6
6/27/2011 9:04:50 PM /LM/W3SVC/1/ROOT/MyApp-1-129537074647228334: log message 7
6/27/2011 9:04:50 PM /LM/W3SVC/1/ROOT/MyApp-1-129537074647228334: log message 8

The item after the time/date is the current app domain name.

The application is just a regular ASP.NET (not MVC) application handling some AJAX request and passing them to a bunch of ASP.NET libraries. The only unusual thing is that one of the libraries uses a bit of reflection to lookup some classes which then instantiates and runs them on separate threads. But it does not do anything explicitly with app domains.

By the way, the highlighted row from the log file comes from the ASP.NET app itself (i.e. not from one of those separate thread) from an ASPX handler.

Am I interpreting the log correctly? If so, what can cause an application to be loaded and served from multiple app domains?

Edit: This question is essentially related to this one: ASP.NET Application state vs a Static object. However, based on what I've seen today, it does not seem possible to rely on static fields. I could move everything to the Application object, but I guess a synchronization would be a bit cumbersome. I'm more and more convinced the application does something non-standard.

Edit 2: I did a little bit more investigation, and it seems that there is always a 1-1 relation between application and app domains (which is something I would expect). So I think that what I'm seeing is recycling.

Edit 3: After some more experiments and poking around, I enabled IIS health monitoring (based on http://blogs.msdn.com/b/tess/archive/2006/08/02/asp-net-case-study-lost-session-variables-and-appdomain-recycles.aspx), and found out that the application is started twice in a quick succession. It's actuall quite puzzling. Here are the log events:

Event code: 1003 
Event message: Application compilation is starting. 
Event time: 6/28/2011 8:34:31 AM 
Event time (UTC): 6/28/2011 3:34:31 PM 
Event ID: d42336b18c264516a4ba5aa1e62df276 
Event sequence: 1 
Event occurrence: 1 
Event detail code: 0 

Application information: 
    Application domain: /LM/W3SVC/1/ROOT/MyApp-1-129537488697736549 
    Trust level: Full 
    Application Virtual Path: /MyApp 
    Application Path: [snip]\MyApp\ 
    Machine name: US-SEA-R9759B2 

Process information: 
    Process ID: 7624 
    Process name: w3wp.exe 
    Account name: IIS APPPOOL\DefaultAppPool 

----

Event code: 1001 
Event message: Application is starting. 
Event time: 6/28/2011 8:34:33 AM 
Event time (UTC): 6/28/2011 3:34:33 PM 
Event ID: f7fbecb1ba1a4a24833016cec47458c6 
Event sequence: 1 
Event occurrence: 1 
Event detail code: 0 

Application information: 
    Application domain: /LM/W3SVC/1/ROOT-2-129537488729428362 
    Trust level: Full 
    Application Virtual Path: / 
    Application Path: [snip]\RootApp\ 
    Machine name: US-SEA-R9759B2 

Process information: 
    Process ID: 7624 
    Process name: w3wp.exe 
    Account name: IIS APPPOOL\DefaultAppPool 

----

Event code: 1001 
Event message: Application is starting. 
Event time: 6/28/2011 8:34:40 AM 
Event time (UTC): 6/28/2011 3:34:40 PM 
Event ID: 07a3dc31e8804caca1ddc3b2101962e3 
Event sequence: 1 
Event occurrence: 1 
Event detail code: 0 

Application information: 
    Application domain: /LM/W3SVC/1/ROOT-3-129537488807712839 
    Trust level: Full 
    Application Virtual Path: / 
    Application Path: [snip]\RootApp\ 
    Machine name: US-SEA-R9759B2 

Process information: 
    Process ID: 7624 
    Process name: w3wp.exe 
    Account name: IIS APPPOOL\DefaultAppPool 

----

Event code: 1001 
Event message: Application is starting. 
Event time: 6/28/2011 8:34:40 AM 
Event time (UTC): 6/28/2011 3:34:40 PM 
Event ID: db304b519a084fa797fbcfe66fbb0b48 
Event sequence: 1 
Event occurrence: 1 
Event detail code: 0 

Application information: 
    Application domain: /LM/W3SVC/1/ROOT/MyApp-4-129537488808502885 
    Trust level: Full 
    Application Virtual Path: /MyApp 
    Application Path: [snip]\MyApp\ 
    Machine name: US-SEA-R9759B2 

Process information: 
    Process ID: 7624 
    Process name: w3wp.exe 
    Account name: IIS APPPOOL\DefaultAppPool 

The MyApp application sits in another application (the RootApp). What I would expect would be two log messages: MyApp starting and RootApp starting.

like image 996
Jan Zich Avatar asked Jun 28 '11 04:06

Jan Zich


2 Answers

Did you accidentally set the number of worker processes in the AppPool Properties (Performance Tab) to 2?

In those properties, there could also be a setting that let's your AppPool recycle far too often, based on number or requests or any of those recycling settings

like image 78
Niels Ziegler Avatar answered Oct 14 '22 10:10

Niels Ziegler


If I had to guess there is something on your site that is changing web.config files, dlls, aspx, asmx or some other file. Whenever those files get changed a new instance of the web application gets started and any new requests get served from that new web application while the old requests get served from the existing application. Once all of the old requests complete the old application is shut down. This is good for deployments as it doesn't break peoples existing sessions but it means you shouldn't have anything that is automatically changing web.config files on every request or things like that.

This page describes in much better detail how this works http://technet.microsoft.com/en-us/library/cc759560(WS.10).aspx

like image 38
Paul Mendoza Avatar answered Oct 14 '22 11:10

Paul Mendoza