4

I'm currently getting into PerfView for performance analysis for my (C#) apps. But typically those apps use a lot of database calls. So I asked myself questions like: - How much time is spent in Repositories? - (How much time is spent waiting for SQL Queries to return?) -> I don't know if this is even possible to discover with PerfView

But from my traces I get barely any useful results. In the "Any Stacks" View it tells me (when I use grouping on my Repository) that 1,5 seconds are spent in my Repsoitory (the whole call is about 45 seconds). And i know this is not really true, because the repositories calls the database A LOT.

Is it just that CPU metric is not captured when waiting for SQL Queries to complete because CPU has nothing to do in this period of time and therefore my times are just including data transformation times etc in the repository?

Thanks for any help!

EDIT:

What i missed is turning on thread times option to get times of blocked code (which is what's happening during database calls i suppose). I got all the stacks now, just have filter out the uninteresting things. But i don't seem to get anywhere.

What's especially interesting for me when using "Thread Time" is the BLOCKED_TIME. But with it the times are off i think. When you look at the screenshot, it tells me that CPU_TIME is 28,384. Which is milliseconds (afaik), but BLOCKED_TIME is 2,314,732, which can't be milliseconds. So percentage for CPU_TIME is very low with 1.2% but 28 out of 70 seconds are still a lot. So the Inclusive Percentage time is comparing apples and oranges here. Can somebody explain?

PerfView "Thread Time Stacks" View after about 70 seconds analysis of a WCF service call

cmart
  • 991
  • 3
  • 11
  • 19
  • you have to create your own EventSource and raise your own event at start and stop of all actions. Now capture those events and here you can calculate the duration. – magicandre1981 Feb 25 '15 at 16:17
  • This should not be necessary. I'm not doing anything uncommon. Also i've updated my question with some new insights. – cmart Feb 25 '15 at 20:16
  • no, you have to do it this way. – magicandre1981 Feb 26 '15 at 06:01
  • That is exactly what i need and it is possible this way: http://blogs.msdn.com/b/vancem/archive/2012/11/26/wall-clock-time-analysis-using-perfview.aspx – cmart Feb 26 '15 at 08:33

1 Answers1

5

So, i succeeded.

What I missed (and Vance Morrison was explaining it in his video tutorial actually) is: When doing a wall clock time analysis with perfview, you get accumulated time from all the threads that have been "waiting around" in what is called "BLOCKED_TIME". Which means for a 70 seconds time, alone the finalizer thread adds 70 seconds to this "BLOCKED_TIME" because it was sitting there not doing anything (at least almost anything in my case).

So when doing wall clock time analysis it is important to filter out what you're interested in. For example search for the thread that was taking the most CPU-time and just include this one in your analysis and go further down the stack to find pieces of your code that are expensive (and also might lead to DB or Service Calls). As soon as you a analysis from the point of view of a method you are really getting the times that were spent in this method and the accumulated "BLOCK_TIME" is out of the picture.

What I found most useful is searching for methods in my own code that "seemed time consuming", i switched to the callers view for this method. Which shed some light from where it's called and in the callees view what is responsible for the consuming time further down the stack (a DB call in a repository or service calls for getting some data).

Little bit hard to explain, but as soon as i had understand really the basics of wall clock time analysis, it all made sense at some point.

I recommend this video tutorial: http://channel9.msdn.com/Series/PerfView-Tutorial

Again, great and very powerful tool!

cmart
  • 991
  • 3
  • 11
  • 19