Yet another "ASP.NET slow first-load" thread -- but different!

Hi all,

I've been doing a lot of reading and research into this, and I don't
believe I'm running into "first load" slowness problems -- something's
slow about loading an initial ASP.NET 2.0 app on my server. Details:

1) There's *NO* activity, *NO* CPU usage, while I wait for the page to
first load. w3wp sits at 6 meg of ram, 0% usage, and the browser
spins for a while. 15-30 seconds later, w3wp starts doing stuff,
jumps to 18-20 meg of ram, and the page loads

2) The application in question is a simple "hello world" -- there's
virtually nothing to compile.

3) Precompiled applications suffer just as much as uncompiled apps

4) iisstate (I wish it could debug asp.net 2.0!) always stops at:

ModLoad: 79e70000 7a3d6000 c:\WINDOWS\Microsoft.NET\Framework
\v2.0.50727\mscorwks.dll

and then finally continues at:

ModLoad: 7c8d0000 7d0d4000 C:\WINDOWS\system32\shell32.dll

5) SI's procmon shows these two actions surrounding the "pause"

7160 1:34:26.8929034 AM w3wp.exe 992 RegCloseKey HKLM\System
\CurrentControlSet\Control\ComputerName SUCCESS

14836 1:34:48.0260661 AM w3wp.exe 992 RegOpenKey HKLM\SYSTEM
\CurrentControlSet\Services\ASP.NET_2.0.50727\Names REPARSE

(note the 22 second pause in activity)

6) Recompiling the application (e.g. changing the code and reloading
the page) is very fast -- it's only when w3wp first starts up (yes, I
know I can mostly avoid this, but I don't accept that "solution"
because this looks like something's actually broken)

I've tried watching 'net traffic for classic DNS timeouts, checking my
hostnames, DNS, etc ... I've attached a remote debugger (VS2005) to
w3wp, initiated a break while it was spinning, and all that showed me
was a HUGE stack inside mscorwks.dll -- one method (I failed to note
which one, I can check again if it's helpful) was 90% of that list!
(recursion?)

I can't figure this one out. I'd appreciate any pointers! Thanks so
much!

-=| Ben

Re: Yet another "ASP.NET slow first-load" thread -- but different!

Please capture and disclose the "huge" stack in mscorwks.dll. That is
important information, with symbols loaded and resolved properly so
that the stack makes sense -- otherwise, the stack is just a big
jumble of memory addresses or non-useful offsets, and that is not
useful.

If you think the issue is within that DLL, then the discussion is not
with ASP.Net nor IIS but rather CLR itself.


//David
http://w3-4u.blogspot.com
http://blogs.msdn.com/David.Wang
//



On Sep 13, 10:40 pm, cine...@gmail.com wrote:
> Hi all,
>
> I've been doing a lot of reading and research into this, and I don't
> believe I'm running into "first load" slowness problems -- something's
> slow about loading an initial ASP.NET 2.0 app on my server. Details:
>
> 1) There's *NO* activity, *NO* CPU usage, while I wait for the page to
> first load. w3wp sits at 6 meg of ram, 0% usage, and the browser
> spins for a while. 15-30 seconds later, w3wp starts doing stuff,
> jumps to 18-20 meg of ram, and the page loads
>
> 2) The application in question is a simple "hello world" -- there's
> virtually nothing to compile.
>
> 3) Precompiled applications suffer just as much as uncompiled apps
>
> 4) iisstate (I wish it could debug asp.net 2.0!) always stops at:
>
> ModLoad: 79e70000 7a3d6000 c:\WINDOWS\Microsoft.NET\Framework
> \v2.0.50727\mscorwks.dll
>
> and then finally continues at:
>
> ModLoad: 7c8d0000 7d0d4000 C:\WINDOWS\system32\shell32.dll
>
> 5) SI's procmon shows these two actions surrounding the "pause"
>
> 7160 1:34:26.8929034 AM w3wp.exe 992 RegCloseKey HKLM\System
> \CurrentControlSet\Control\ComputerName SUCCESS
>
> 14836 1:34:48.0260661 AM w3wp.exe 992 RegOpenKey HKLM\SYSTEM
> \CurrentControlSet\Services\ASP.NET_2.0.50727\Names REPARSE
>
> (note the 22 second pause in activity)
>
> 6) Recompiling the application (e.g. changing the code and reloading
> the page) is very fast -- it's only when w3wp first starts up (yes, I
> know I can mostly avoid this, but I don't accept that "solution"
> because this looks like something's actually broken)
>
> I've tried watching 'net traffic for classic DNS timeouts, checking my
> hostnames, DNS, etc ... I've attached a remote debugger (VS2005) to
> w3wp, initiated a break while it was spinning, and all that showed me
> was a HUGE stack inside mscorwks.dll -- one method (I failed to note
> which one, I can check again if it's helpful) was 90% of that list!
> (recursion?)
>
> I can't figure this one out. I'd appreciate any pointers! Thanks so
> much!
>
> -=| Ben

Re: Yet another "ASP.NET slow first-load" thread -- but different!

I experience the same on my webhost provider when accessing monsters such as
the Community Server and Dot Net Nuke. Both are resource hugs that
apparently cache their pages and if not requested within a period of time
then next time the poor visitor pays the penalty of a long wait.

In my experience it can take as long at 15-20 seconds to first show the page
which is totally unacceptable. By then the visitor is already gone to
greener pastures.

However for my regular ASP.NET sites (developed by me) I do not see this
behaviour. I typically precompile them (ASP.NET 2.0) and might have a bit of
extra delay the first time but never 15-30 seconds. I wonder if we are
talking about the same problem?

wrote in message
news:1189748453.793306.319430@57g2000hsv.googlegroups.com...
> Hi all,
>
> I've been doing a lot of reading and research into this, and I don't
> believe I'm running into "first load" slowness problems -- something's
> slow about loading an initial ASP.NET 2.0 app on my server. Details:
>
> 1) There's *NO* activity, *NO* CPU usage, while I wait for the page to
> first load. w3wp sits at 6 meg of ram, 0% usage, and the browser
> spins for a while. 15-30 seconds later, w3wp starts doing stuff,
> jumps to 18-20 meg of ram, and the page loads
>
> 2) The application in question is a simple "hello world" -- there's
> virtually nothing to compile.
>
> 3) Precompiled applications suffer just as much as uncompiled apps
>
> 4) iisstate (I wish it could debug asp.net 2.0!) always stops at:
>
> ModLoad: 79e70000 7a3d6000 c:\WINDOWS\Microsoft.NET\Framework
> \v2.0.50727\mscorwks.dll
>
> and then finally continues at:
>
> ModLoad: 7c8d0000 7d0d4000 C:\WINDOWS\system32\shell32.dll
>
> 5) SI's procmon shows these two actions surrounding the "pause"
>
> 7160 1:34:26.8929034 AM w3wp.exe 992 RegCloseKey HKLM\System
> \CurrentControlSet\Control\ComputerName SUCCESS
>
> 14836 1:34:48.0260661 AM w3wp.exe 992 RegOpenKey HKLM\SYSTEM
> \CurrentControlSet\Services\ASP.NET_2.0.50727\Names REPARSE
>
> (note the 22 second pause in activity)
>
> 6) Recompiling the application (e.g. changing the code and reloading
> the page) is very fast -- it's only when w3wp first starts up (yes, I
> know I can mostly avoid this, but I don't accept that "solution"
> because this looks like something's actually broken)
>
> I've tried watching 'net traffic for classic DNS timeouts, checking my
> hostnames, DNS, etc ... I've attached a remote debugger (VS2005) to
> w3wp, initiated a break while it was spinning, and all that showed me
> was a HUGE stack inside mscorwks.dll -- one method (I failed to note
> which one, I can check again if it's helpful) was 90% of that list!
> (recursion?)
>
> I can't figure this one out. I'd appreciate any pointers! Thanks so
> much!
>
> -=| Ben
>

Re: Yet another "ASP.NET slow first-load" thread -- but different!

A stack trace is a simple and conclusive way to determine this. You
simply observe what code is running that takes that much time as well
as what it is doing.

This sort of debugging is pretty universally applicable to any
software. If you want it in a more "friendly" form, it usually takes
proprietary effort on the part of the software/developer to achieve
the friendly results.

For example, IIS7 supports a simple monitoring tool for all requests
running on it, so you can easily configure it to flag down request
that take > X seconds and do a detailed stack trace of that request,
which makes determining this sort of issue easy. Of course, this only
works for IIS requests and not anything else. However, there are
integrated ETW traces on IIS7 which allow integrated view of the
entire request, from IIS through ASP/ASP.Net, DCOM, SQL, etc.

Unfortunately, none of those advancements apply to what we are
discussing here, and you'll have to move to IIS7 to get it.


//David
http://w3-4u.blogspot.com
http://blogs.msdn.com/David.Wang
//





On Sep 14, 12:12 am, "~~~ .NET Ed ~~~"
wrote:
> I experience the same on my webhost provider when accessing monsters such as
> the Community Server and Dot Net Nuke. Both are resource hugs that
> apparently cache their pages and if not requested within a period of time
> then next time the poor visitor pays the penalty of a long wait.
>
> In my experience it can take as long at 15-20 seconds to first show the page
> which is totally unacceptable. By then the visitor is already gone to
> greener pastures.
>
> However for my regular ASP.NET sites (developed by me) I do not see this
> behaviour. I typically precompile them (ASP.NET 2.0) and might have a bit of
> extra delay the first time but never 15-30 seconds. I wonder if we are
> talking about the same problem?
>
> wrote in message
>
> news:1189748453.793306.319430@57g2000hsv.googlegroups.com...
>
>
>
> > Hi all,
>
> > I've been doing a lot of reading and research into this, and I don't
> > believe I'm running into "first load" slowness problems -- something's
> > slow about loading an initial ASP.NET 2.0 app on my server. Details:
>
> > 1) There's *NO* activity, *NO* CPU usage, while I wait for the page to
> > first load. w3wp sits at 6 meg of ram, 0% usage, and the browser
> > spins for a while. 15-30 seconds later, w3wp starts doing stuff,
> > jumps to 18-20 meg of ram, and the page loads
>
> > 2) The application in question is a simple "hello world" -- there's
> > virtually nothing to compile.
>
> > 3) Precompiled applications suffer just as much as uncompiled apps
>
> > 4) iisstate (I wish it could debug asp.net 2.0!) always stops at:
>
> > ModLoad: 79e70000 7a3d6000 c:\WINDOWS\Microsoft.NET\Framework
> > \v2.0.50727\mscorwks.dll
>
> > and then finally continues at:
>
> > ModLoad: 7c8d0000 7d0d4000 C:\WINDOWS\system32\shell32.dll
>
> > 5) SI's procmon shows these two actions surrounding the "pause"
>
> > 7160 1:34:26.8929034 AM w3wp.exe 992 RegCloseKey HKLM\System
> > \CurrentControlSet\Control\ComputerName SUCCESS
>
> > 14836 1:34:48.0260661 AM w3wp.exe 992 RegOpenKey HKLM\SYSTEM
> > \CurrentControlSet\Services\ASP.NET_2.0.50727\Names REPARSE
>
> > (note the 22 second pause in activity)
>
> > 6) Recompiling the application (e.g. changing the code and reloading
> > the page) is very fast -- it's only when w3wp first starts up (yes, I
> > know I can mostly avoid this, but I don't accept that "solution"
> > because this looks like something's actually broken)
>
> > I've tried watching 'net traffic for classic DNS timeouts, checking my
> > hostnames, DNS, etc ... I've attached a remote debugger (VS2005) to
> > w3wp, initiated a break while it was spinning, and all that showed me
> > was a HUGE stack inside mscorwks.dll -- one method (I failed to note
> > which one, I can check again if it's helpful) was 90% of that list!
> > (recursion?)
>
> > I can't figure this one out. I'd appreciate any pointers! Thanks so
> > much!
>
> > -=| Ben- Hide quoted text -
>
> - Show quoted text -

Re: Yet another "ASP.NET slow first-load" thread -- but different!

On Sep 14, 2:47 am, "Egbert Nierop \(MVP for IIS\)"
wrote:
> schreef in berichtnews:1189748453.793306.319430@57g2000hsv.googlegroups .com...
>
> > Hi all,
>
> > 5) SI's procmon shows these two actions surrounding the "pause"
>
> > 7160 1:34:26.8929034 AM w3wp.exe 992 RegCloseKey HKLM\System
> > \CurrentControlSet\Control\ComputerName SUCCESS
>
> Hi,
>
> ComputerName is used for several API's including those who all accept the computer name for network operations.
> I would suggest you start netmon, which is available throught the support directory CD from your W2K3 cd.
>
> I believe this 22 seconds, is a broadcast, it is trying to figure 'things' (I guess) between the domain controler and your server.
>
> Regards
>
> --
> ASP Session Managerhttp://www.nieropwebconsult.nl/asp_session_manager.ht m

I think you hit the nail on the head here! I tried this on a server
that's not part of a domain and it didn't experience this pause. I'll
research this more and report my findings here ...

Thanks!

-=| Ben

Re: Yet another "ASP.NET slow first-load" thread -- but different!

> I think you hit the nail on the head here! I tried this on a server
> that's not part of a domain and it didn't experience this pause. I'll
> research this more and report my findings here ...

If I interrupt w3wp.exe while after having it load .NET for the first
time (as it 'hangs'), this is always the stack:

ntdll.dll!_KiFastSystemCallRet@0()
ntdll.dll!_NtWaitForSingleObject@12() + 0xc bytes
kernel32.dll!_WaitForSingleObjectEx@12() + 0x88 bytes
kernel32.dll!_WaitForSingleObject@8() + 0x12 bytes
w3dt.dll!WP_CONTEXT::RunMainThreadLoop() + 0x10 bytes
w3dt.dll!UlAtqStartListen() + 0x2d bytes
w3core.dll!W3_SERVER::StartListen() + 0xbd bytes
w3core.dll!UlW3Start() + 0x26e bytes
w3wp.exe!_wmain() + 0x22a bytes
w3wp.exe!_wmainCRTStartup() + 0x12b bytes
kernel32.dll!_BaseProcessStart@4() + 0x23 bytes

Wireshark (Ethereal successor) shows my server talking to my DC -- DCE
RPC / EPMAP stuff, LSA (LsarLookupNames4 request) -- the latter takes
30 seconds to receive a response. Unfortunately it's encrypted so I
don't know what's going on. However, I know that this is used to
resolve a name to a SID -- so this is currently my area of focus
(since this is related to the server being attached to a domain). I
don't see any unresolved SIDs in my Local Security Settings or on
various directories' NTFS permissions... Neither IIS nor the worker
pool are configured to log into a domain account, and anonymous access
is via a local account as well.
I don't have access to the domain controller (which is a busy server
anyway) or I'd try tracing the request from there.

I haven't been able to reproduce the "huge stack" in mscorwks.dll --
and that may have been a bogus stack (?) since I didn't have any
symbols configured at that time. So I'm not yet sure if this is a CLR
issue or an IIS issue yet, but I welcome insight/direction.

.... still digging -- I need to go to bed (by about 3.5 hours ago)!

-=| Ben