application_start firing unexpectedly asp.net

Question

I am looking at an asp.net application that makes calls to a database within the application start inside global.asax. These calls takes around 3 seconds (depends on SQL cache plan) to run. I have noticed that the application runs slowly when I first redeploy. I put this down to the calls to the database whilst the application started. However after a few minutes the application again takes time to load.

To find out what was going, I have written to a log file (see below). From this file you can see that application start fires multipe times when multiple requests hits the application for the first time. It then appears that the application_start is fired in a random fashion (anything from 2-10 mins).

From my understanding of how application_starts works it should only get triggered when the applicaton FIRST starts, however it appears to be fired from multiple clients randomly! According to MSDN "The Application_Start event is fired the first time when an application starts."

Can anyone help me work out what is going on? I am using IIS6 and .net 2.0. Is it an application pool setting I am missing.

Many thanks Rippo

[12/02/2009 16:16:58] 91.84.25.241 - Application started, Sub MyRules started
[12/02/2009 16:17:06] 65.55.51.34 - Application started, Sub MyRules started
[12/02/2009 16:17:07] 91.84.25.241 - Application started, Sub MyRules completed
[12/02/2009 16:17:10] 65.55.51.34 - Application started, Sub MyRules completed
[12/02/2009 16:17:26] 212.115.51.229 - Application started, Sub MyRules started
[12/02/2009 16:17:30] 212.115.51.229 - Application started, Sub MyRules completed
[12/02/2009 16:17:30] 212.115.51.229 - Application started, Sub MyRules started
[12/02/2009 16:17:33] 212.115.51.229 - Application started, Sub MyRules completed
[12/02/2009 16:17:33] 212.115.51.229 - Application started, Sub MyRules started
[12/02/2009 16:17:36] 212.115.51.229 - Application started, Sub MyRules completed
[12/02/2009 16:17:36] 212.115.51.229 - Application started, Sub MyRules started
[12/02/2009 16:17:39] 212.115.51.229 - Application started, Sub MyRules completed
[12/02/2009 16:17:42] 212.115.51.229 - Application started, Sub MyRules started
[12/02/2009 16:17:48] 212.115.51.229 - Application started, Sub MyRules completed
[12/02/2009 16:17:48] 212.115.51.229 - Application started, Sub MyRules started
[12/02/2009 16:17:52] 212.115.51.229 - Application started, Sub MyRules completed
[12/02/2009 16:17:52] 212.115.51.229 - Application started, Sub MyRules started
[12/02/2009 16:17:54] 212.115.51.229 - Application started, Sub MyRules completed
[12/02/2009 16:18:27] 91.84.25.241 - Application started, Sub MyRules started
[12/02/2009 16:18:31] 91.84.25.241 - Application started, Sub MyRules completed
[12/02/2009 16:18:31] 212.115.51.229 - Application started, Sub MyRules started
[12/02/2009 16:18:33] 212.115.51.229 - Application started, Sub MyRules completed
[12/02/2009 16:29:26] 167.230.38.115 - Application started, Sub MyRules started
[12/02/2009 16:29:28] 167.230.38.115 - Application started, Sub MyRules completed
[12/02/2009 16:29:34] 82.110.42.84 - Application started, Sub MyRules started
[12/02/2009 16:29:37] 82.110.42.84 - Application started, Sub MyRules completed
[12/02/2009 16:29:38] 82.110.42.84 - Application started, Sub MyRules started
[12/02/2009 16:29:41] 82.110.42.84 - Application started, Sub MyRules completed
[12/02/2009 16:32:53] 99.142.1.97 - Application started, Sub MyRules started
[12/02/2009 16:32:57] 99.142.1.97 - Application started, Sub MyRules completed
[12/02/2009 16:32:57] 99.142.1.97 - Application started, Sub MyRules started
[12/02/2009 16:33:01] 99.142.1.97 - Application started, Sub MyRules completed
[12/02/2009 16:33:01] 99.142.1.97 - Application started, Sub MyRules started
[12/02/2009 16:33:06] 99.142.1.97 - Application started, Sub MyRules completed
[12/02/2009 16:33:06] 99.142.1.97 - Application started, Sub MyRules started
[12/02/2009 16:33:10] 99.142.1.97 - Application started, Sub MyRules completed
[12/02/2009 16:33:11] 99.142.1.97 - Application started, Sub MyRules started
[12/02/2009 16:33:16] 99.142.1.97 - Application started, Sub MyRules completed
[12/02/2009 16:36:15] 65.55.51.34 - Application started, Sub MyRules started
[12/02/2009 16:36:17] 65.55.51.34 - Application started, Sub MyRules completed
[12/02/2009 16:41:37] 119.123.226.156 - Application started, Sub MyRules started
[12/02/2009 16:41:37] 62.49.121.122 - Application started, Sub MyRules started
[12/02/2009 16:41:40] 62.49.121.122 - Application started, Sub MyRules completed
[12/02/2009 16:41:40] 119.123.226.156 - Application started, Sub MyRules completed
[12/02/2009 16:41:41] 62.49.121.122 - Application started, Sub MyRules started
[12/02/2009 16:41:44] 62.49.121.122 - Application started, Sub MyRules completed
[12/02/2009 16:45:17] 84.70.249.242 - Application started, Sub MyRules started
[12/02/2009 16:45:19] 84.70.249.242 - Application started, Sub MyRules completed
[12/02/2009 16:47:03] 80.41.121.68 - Application started, Sub MyRules started
[12/02/2009 16:47:05] 80.41.121.68 - Application started, Sub MyRules completed
[12/02/2009 16:47:29] 81.179.26.249 - Application started, Sub MyRules started
[12/02/2009 16:47:31] 81.179.26.249 - Application started, Sub MyRules completed
[12/02/2009 16:47:59] 81.136.179.170 - Application started, Sub MyRules started
[12/02/2009 16:47:59] 81.136.179.170 - Application started, Sub MyRules started
[12/02/2009 16:48:02] 81.136.179.170 - Application started, Sub MyRules completed
[12/02/2009 16:48:02] 81.136.179.170 - Application started, Sub MyRules started
[12/02/2009 16:48:02] 81.136.179.170 - Application started, Sub MyRules completed
[12/02/2009 16:48:02] 81.136.179.170 - Application started, Sub MyRules started
[12/02/2009 16:48:04] 81.136.179.170 - Application started, Sub MyRules completed
[12/02/2009 16:48:04] 81.136.179.170 - Application started, Sub MyRules completed
[12/02/2009 16:52:35] 69.34.161.80 - Application started, Sub MyRules started
[12/02/2009 16:52:35] 69.34.161.80 - Application started, Sub MyRules started
[12/02/2009 16:52:35] 69.34.161.80 - Application started, Sub MyRules started
[12/02/2009 16:52:38] 69.34.161.80 - Application started, Sub MyRules completed
[12/02/2009 16:52:38] 69.34.161.80 - Application started, Sub MyRules started
[12/02/2009 16:52:39] 69.34.161.80 - Application started, Sub MyRules completed
[12/02/2009 16:52:39] 69.34.161.80 - Application started, Sub MyRules completed
[12/02/2009 16:52:40] 69.34.161.80 - Application started, Sub MyRules completed

yusuf · Answer 1 · 2013-12-05T11:30:01.637

16

Check in what cases an App restarts. Recently we were writing some log entries to bin folder and exactly the same thing was happening and we didn't understand the reason. Then finally realized that making any modifications to bin folder was causing the app restart.

edited Dec 05 '13 at 11:30

answered Feb 12 '09 at 18:32

yusuf

3,596
5
34
39

I was doing just this and wrestling with my web app for the last few hours. Thanks for the answer here, even though it wasn't exactly what was happening with regard to this question! – Peter Meyer May 24 '10 at 20:03
+1 - I was dumping a generated SQL file there and had no idea why the application was restarting. I would up vote 1000 more times if I could. – TheCloudlessSky Jan 08 '11 at 19:23
Thank you for saving the long trip ! – kalki May 07 '13 at 13:13

score 2 · Answer 2 · answered Nov 24 '10 at 19:12

2

I had a problem with the Application_Start getting called multiple times, and it turns out it was because I had multiple instances set up. Stupid mistake, but I wanted to note it.

answered Nov 24 '10 at 19:12

Jason Young

3,683
4
32
39

score 2 · Answer 3 · answered Feb 12 '09 at 17:17

2

Check the event log, something is causing the app pool to recycle.

answered Feb 12 '09 at 17:17

AnthonyWJones

187,081
35
232
306

In my case, there is nothing in the app or system logs explaining why application_start is called more than once. It's a normal asp.net webapi 2 app in a docker container; it starts two w3wp.exe process, and each of them both run application_start successfully from beginning to end, twice. There is one WAS log indicating a settings change triggered a pool recycle, but this message preceeds the run of both processes. While it may explain the presense of the 2nd process, it does not explain why both process each call application_start (and run it to completion) twice. – Triynko Jan 27 '22 at 07:03

score 1 · Answer 4 · answered Aug 31 '12 at 22:13

I don't know why, but I saw the same thing in my logs. Is it possibly because it takes too long and you have multiple requests coming in at the same time? Anyway, just to be safe, I'm adding this code:

public class MvcApplication : HttpApplication
{
    private static volatile bool hasRegisteredBgTasks = false;
    private static object registeredBgTasksLock = new object();

    protected void Application_Start()
    {
        lock (registeredBgTasksLock)
        {
            if (hasRegisteredBgTasks)
            {
                return;
            }
            // Actual start up code.
            hasRegisteredBgTasks = true;
        }
    }

    // Other Application methods...
}

Another possibility in my case was using web deploy to the live site. I could have been half deployed, a user hits it, starts the app, then more files come in and restarts again. — Michael Kennedy, Aug 31 '12 at 22:49

Rippo · Accepted Answer · 2023-03-06T15:13:41.177

0

It turned out to be a leaky dll...

As a edit in 2023 to try and stop bad comments here is my comment in this post.

If memory serves me right it was a 3rd party rewrite dll that had a bug in it and was throwing errors whilst setting up the rewrites which caused the webapp to recycle continuously

edited Mar 06 '23 at 15:13

answered Jul 11 '09 at 17:18

Rippo

22,117
14
78
117

After 5 years it has a major leak now... seriously though, if memory serves me right it was a 3rd party rewrite dll that had a bug in it and was throwing errors which caused app to recycle continuously... can't remember details – Rippo Mar 08 '14 at 13:16
buggy third party dll that is! =) – Andrew Savinykh Mar 09 '14 at 07:56
just been downvoted with no comment 7 yrs after given this answer. @stackoverflow is a harsh place :) – Rippo Sep 11 '17 at 11:39
2

I downvoted you because this is a vague useless answer that helps no one. – Sep 11 '17 at 18:19
2

Yes I read the second comment. Still a useless stupid answer that doesn't help anybody. – Sep 12 '17 at 14:31
wow thanks for your support! Comments like yours doesn't really help anyone either. Sorry I upset you so much. – Rippo Sep 13 '17 at 07:41
1

You asked a question. I'm sorry the answer isn't what you wanted. – Sep 13 '17 at 13:33
well imo the comment isn't stupid and can help other people. but hey ho... As for answer I wanted I didn't expect flames that's all. Enjoy your day – Rippo Sep 13 '17 at 15:36

application_start firing unexpectedly asp.net

5 Answers5