Fully featured low overhead profiler for Java EE and Java SE platforms.
Ultimate profiling and monitoring solution for Gradle, Maven, Ant, JUnit and TestNG.
Easy to use performance and memory profiler for .NET framework.

Profiler EAP Build 332 o XP SP2 - Memory Snapshot Problem

Moderators: Vladimir Kondratyev, Anton Katilin

Profiler EAP Build 332 o XP SP2 - Memory Snapshot Problem

Postby Rigbyd » Wed Dec 19, 2007 4:02 pm

I am attempting to capture a memory snapshot of a ASP.Net (2.0) application and having issues, specifically:

- The application stops in the middle of the capture progress bar and fails to advance.

- The asp.net worker process (aspnet_wp.exe) sits at a constant 100% utilization (of a single CPU core).

- The application is still responsive (clicking exit, maximize, etc performed the appropriate action).

- Application has been in this state for 20 minutes with no change.


Screenshots:

Image

Image

Image

Image

Images hosted on Flickr
Rigbyd
 
Posts: 11
Joined: Wed Dec 19, 2007 3:33 pm

Postby Rigbyd » Wed Dec 19, 2007 4:05 pm

As of the time of this post, application had been running for 45 minutes with no change. ASP.Net worker process is still at 100% utilization even after exiting the program.
Rigbyd
 
Posts: 11
Joined: Wed Dec 19, 2007 3:33 pm

Postby Rigbyd » Wed Dec 19, 2007 4:08 pm

Restarting Yourkit while the aspnet worker process is still at 100% utilization results in Yourkit hanging at the splash screen until the asp.net worker process is killed.
Rigbyd
 
Posts: 11
Joined: Wed Dec 19, 2007 3:33 pm

Postby Vladimir Kondratyev » Wed Dec 19, 2007 4:44 pm

Please send us all log files from %USER_HOME%\.ynp\logs directory.

Also please provide full stack when ASP.NET consumes 100% CPU?

Thank you in advance.

Best regards,
Vladimir Kondratyev
YourKit, LLC
http://www.yourkit.com
"Don't get lost in data, get information!"
Vladimir Kondratyev
 
Posts: 1444
Joined: Tue Aug 10, 2004 7:52 pm
Location: Düsseldorf, Germany

Postby Rigbyd » Wed Dec 19, 2007 5:16 pm

Image
Image


Contents of 0.log (Cleared logs and ran application):

2007-12-19 11:28:45.811 INFO com.yourkit.Main0 : ---------------------------------------------------------------------
2007-12-19 11:28:45.811 INFO com.yourkit.Main0 : Starting YourKit Profiler 3.0 EAP build 332 for .NET build #332; built on Tue Dec 18 21:28:00 EST 2007
2007-12-19 11:28:45.811 INFO com.yourkit.Main0 : number of args: 0
2007-12-19 11:38:32.801 INFO com.yourkit.ui.bn$a :
com.yourkit.runtime.PresentableException: There's no application running at localhost with profiler agent configured to listen on port 10002
at com.yourkit.api.ControllerImpl.a(a:5)
at com.yourkit.api.ControllerImpl.a(a:259)
at com.yourkit.api.ControllerImpl.getStatus(a:252)
at com.yourkit.api.ControllerImpl.cacheStatuses(a:94)
at com.yourkit.ui.bn$a$1.run(a:23)
at com.yourkit.api.ControllerImpl$22.perform(a:15)
at com.yourkit.api.ControllerImpl.a(a:274)
at com.yourkit.api.ControllerImpl.runBatch(a:120)
at com.yourkit.ui.bn$a.run(a:24)
2007-12-19 11:38:38.360 INFO com.yourkit.ui.bn$a :
com.yourkit.runtime.PresentableException: There's no application running at localhost with profiler agent configured to listen on port 10002
at com.yourkit.api.ControllerImpl.a(a:5)
at com.yourkit.api.ControllerImpl.a(a:259)
at com.yourkit.api.ControllerImpl.runBatch(a:120)
at com.yourkit.ui.bn$a.run(a:24)




Note: "com.yourkit.runtime.PresentableException" occurs at the point where I kill the aspnet worker process while YourKit is still running.

Great application by the way, I meant to say it in the first post. ;-)

Thanks!
Rigbyd
 
Posts: 11
Joined: Wed Dec 19, 2007 3:33 pm

Postby Vladimir Kondratyev » Wed Dec 19, 2007 5:28 pm

Perhaps, do you have ".ynp\log" directory in some other location? For example, C:\WINDOWS\system32\config\systemprofile\.ynp\log

There should be log file of application being profiled.

Best regards,
Vladimir Kondratyev
YourKit, LLC
http://www.yourkit.com
"Don't get lost in data, get information!"
Vladimir Kondratyev
 
Posts: 1444
Joined: Tue Aug 10, 2004 7:52 pm
Location: Düsseldorf, Germany

Postby Rigbyd » Wed Dec 19, 2007 7:41 pm

3876.log in C:\WINDOWS\system32\config\systemprofile\.ynp\log:

[YourKit Profiler 3.0 EAP build 332 for .NET]
OS: Windows XP 5.1
CLR: v2.0.50727
'C:\WINDOWS\Microsoft.NET\Framework\v2.0.50727\aspnet_wp.exe' started 19.12.2007 at 13:56
Snapshot is saved to C:\WINDOWS\system32\config\systemprofile\Snapshots\aspnet_wp.exe-2007-12-19(6).snapshot

I managed to successfully do one memory capture by doing it shortly after launching the asp.net application and not enabling system profiling in yourkit first. Upon the second attempt at performing a memory capture, the deadlock happened again (still did not have profiling enabled).
Rigbyd
 
Posts: 11
Joined: Wed Dec 19, 2007 3:33 pm

Postby Rigbyd » Wed Dec 19, 2007 7:47 pm

One of the older logs (3160.log) was 700k in size.

It contained:

Code: Select all
[YourKit Profiler 3.0 EAP build 332 for .NET]
   OS: Windows XP 5.1
   CLR: v2.0.50727
   'C:\WINDOWS\Microsoft.NET\Framework\v2.0.50727\aspnet_wp.exe' started 19.12.2007 at 10:37
CPU profiling is started
[processThread] ExceptionAddress = 63E76C0B
[processThread] ExceptionCode = -1073741819
[processThread] ExceptionFlags = 0
[processThread] ExceptionRecord = 00000000
[processThread] NumberParameters = 2
[processThread] ExceptionInformation[0] = 0

[processThread] ExceptionInformation[1] = 0

C [mscordbc.dll+0x6c0b]
C [yjpagent.dll+0x4cb2e]
C [yjpagent.dll+0x4d5fb]
C [yjpagent.dll+0x729a]
C [yjpagent.dll+0x7371]
C [yjpagent.dll+0x7467]
C [yjpagent.dll+0x74b3]
[processThread] ExceptionAddress = 63E76C0B
[processThread] ExceptionCode = -1073741819
[processThread] ExceptionFlags = 0
[processThread] ExceptionRecord = 00000000
[processThread] NumberParameters = 2
[processThread] ExceptionInformation[0] = 0

[processThread] ExceptionInformation[1] = 0




And after that,

Code: Select all
[C [mscordbc.dll+0x6c0b]
C [yjpagent.dll+0x4cb2e]
C [yjpagent.dll+0x4d5fb]
C [yjpagent.dll+0x729a]
C [yjpagent.dll+0x7371]
C [yjpagent.dll+0x7467]
C [yjpagent.dll+0x74b3]
[processThread] ExceptionAddress = 63E76C0B
[processThread] ExceptionCode = -1073741819
[processThread] ExceptionFlags = 0
[processThread] ExceptionRecord = 00000000
[processThread] NumberParameters = 2
[processThread] ExceptionInformation[0] = 0

[processThread] ExceptionInformation[1] = 0


was just repeated over and over again until the end of the file.
Rigbyd
 
Posts: 11
Joined: Wed Dec 19, 2007 3:33 pm

Postby Rigbyd » Wed Dec 19, 2007 8:04 pm

I've got it stuck at 100% right now and have left it there attempting to capture. I've been watching the log files, but nothing seems to be being entered in the log files that contains information about the deadlock.

Is there anything else besides logs that I can look at to get you additional information?
Rigbyd
 
Posts: 11
Joined: Wed Dec 19, 2007 3:33 pm

Postby Rigbyd » Wed Dec 19, 2007 8:59 pm

I've downloaded windbg and windows symbols.

Asp.Net worker process threads:
Image

Here's a stack trace of the "mscorwks.dll!SVR::gc_heap::gc_thread_stub" thread (The thread causing 100% CPU Utilization) in the asp.net worker process with symbols loaded:

Code: Select all
ntoskrnl.exe!ZwCompleteConnectPort+0x9
mscorwks.dll!SVR::gc_heap::gc_thread_function+0x287
mscorwks.dll!SVR::gc_heap::gc_thread_stub+0x92
kernel32.dll!BaseThreadStart+0x37
Rigbyd
 
Posts: 11
Joined: Wed Dec 19, 2007 3:33 pm

Postby Anton Katilin » Thu Dec 20, 2007 10:27 am

Thank you very much for this information. I hope that it will help us to locate and fix the problem. We're working on this now.

Technically, it seems that the slowdown was caused by catching and logging an exception that occurred very many times.
Anton Katilin
 
Posts: 5576
Joined: Wed Aug 11, 2004 8:37 am

Postby Rigbyd » Thu Dec 20, 2007 2:31 pm

Happy to help. Let me know if you need any more info.
Rigbyd
 
Posts: 11
Joined: Wed Dec 19, 2007 3:33 pm

Postby Anton Katilin » Thu Dec 20, 2007 4:50 pm

Hello,

Thank you very much for your help.

Could you please try build 334: http://www.yourkit.com/dotnet/eap/

Does it solve the problem on your system?

If it doesn't, could you please:
1. Delete all logs.
2. Reproduce the problem with 334.
3. Send full logs at support@yourkit.com

Best regards,
Anton
Anton Katilin
 
Posts: 5576
Joined: Wed Aug 11, 2004 8:37 am

Postby Rigbyd » Thu Dec 20, 2007 5:14 pm

I am able to replicate this problem in the new build (334) and have sent an email to the support address containing the log files and process/thread information.

Is there anything else further I can do?

Thanks.
Rigbyd
 
Posts: 11
Joined: Wed Dec 19, 2007 3:33 pm

Postby Anton Katilin » Fri Dec 21, 2007 1:30 pm

Hi,

I've sent you an email with instructions.

Thank you very much for your help.

Best regards,
Anton
Anton Katilin
 
Posts: 5576
Joined: Wed Aug 11, 2004 8:37 am

Next

Return to .NET Profiler

Who is online

Users browsing this forum: No registered users and 2 guests