iis worker process time elapsed very long

Question

I monitor the iis work process find few request time elapsed very long,

i dump the w3wp.exe using windbg not found deadlock.

what worng with this：

-------------------update------------------------------

when I run the !runaway command in windbg, the got result below, but it seems ok. the longest time for threads within 14 seconds.

0:000> !runaway
 User Mode Time
  Thread       Time
  10:cc0       0 days 0:00:14.765
  11:3178      0 days 0:00:14.718
  13:288c      0 days 0:00:14.359
  12:11d4      0 days 0:00:14.203
  44:216c      0 days 0:00:09.781
  47:ac0       0 days 0:00:08.125
  50:3388      0 days 0:00:06.546
  31:21c4      0 days 0:00:06.484
  53:2a68      0 days 0:00:05.687
  21:e48       0 days 0:00:05.515
  51:2c78      0 days 0:00:05.281
  73:fd0       0 days 0:00:04.968
  52:2824      0 days 0:00:04.703
  77:26e0      0 days 0:00:04.437
  76:1bbc      0 days 0:00:04.343
  78:2fa4      0 days 0:00:04.250
  69:c6c       0 days 0:00:04.218
  68:dd0       0 days 0:00:04.078
  70:220c      0 days 0:00:04.015
  72:a2c       0 days 0:00:04.000
  74:15b0      0 days 0:00:03.875
  71:2984      0 days 0:00:03.781
  75:3784      0 days 0:00:03.640
  62:e3c       0 days 0:00:03.546
  65:1da0      0 days 0:00:03.406
  79:18f0      0 days 0:00:03.312
  64:1920      0 days 0:00:03.265
  63:32bc      0 days 0:00:03.218
  41:e70       0 days 0:00:03.015
  66:1148      0 days 0:00:02.921
  67:1398      0 days 0:00:02.453
  42:2180      0 days 0:00:02.296
  43:1c28      0 days 0:00:02.265
  33:1208      0 days 0:00:01.546
  46:3928      0 days 0:00:01.265
  45:2854      0 days 0:00:01.125
 114:34e4      0 days 0:00:00.875
  55:f4        0 days 0:00:00.796
  49:2e68      0 days 0:00:00.781
   6:2fb4      0 days 0:00:00.781
   4:3354      0 days 0:00:00.781
  32:3110      0 days 0:00:00.765
  60:2054      0 days 0:00:00.718
  56:18c4      0 days 0:00:00.703
  61:111c      0 days 0:00:00.656
  59:1cb0      0 days 0:00:00.625
  58:28d0      0 days 0:00:00.562
  99:14ac      0 days 0:00:00.500
  57:3078      0 days 0:00:00.437
  38:35fc      0 days 0:00:00.390
  82:2ebc      0 days 0:00:00.312
  26:38cc      0 days 0:00:00.312
  27:23a4      0 days 0:00:00.296
  85:e78       0 days 0:00:00.281
  28:35bc      0 days 0:00:00.281
  22:3284      0 days 0:00:00.281
  86:b7c       0 days 0:00:00.265
  29:888       0 days 0:00:00.265
  97:19c4      0 days 0:00:00.250
  96:e88       0 days 0:00:00.250
  23:3b08      0 days 0:00:00.234
  83:9b0       0 days 0:00:00.218
  88:13c8      0 days 0:00:00.187
 107:a0c       0 days 0:00:00.156
  14:90        0 days 0:00:00.156
   5:2ae4      0 days 0:00:00.140
  36:25cc      0 days 0:00:00.093
 115:35a0      0 days 0:00:00.078
  87:3b54      0 days 0:00:00.078
  84:10c0      0 days 0:00:00.078
  39:2454      0 days 0:00:00.062
  37:1644      0 days 0:00:00.046
   0:35c8      0 days 0:00:00.046
 109:940       0 days 0:00:00.031
 105:4a4       0 days 0:00:00.031
 104:14a4      0 days 0:00:00.031
 103:1c98      0 days 0:00:00.031
 100:2b88      0 days 0:00:00.031
  94:1b04      0 days 0:00:00.031
  92:363c      0 days 0:00:00.031
  89:e2c       0 days 0:00:00.031
  80:3660      0 days 0:00:00.031
  34:1bd4      0 days 0:00:00.031
  18:37fc      0 days 0:00:00.031
  17:1e30      0 days 0:00:00.031
 113:29a0      0 days 0:00:00.015
 112:8d0       0 days 0:00:00.015
 111:2074      0 days 0:00:00.015
 110:3a64      0 days 0:00:00.015
 108:e0c       0 days 0:00:00.015
 106:e14       0 days 0:00:00.015
 102:335c      0 days 0:00:00.015
 101:2270      0 days 0:00:00.015
  98:12fc      0 days 0:00:00.015
  95:2308      0 days 0:00:00.015
  93:39e0      0 days 0:00:00.015
  90:27e8      0 days 0:00:00.015
  48:2b60      0 days 0:00:00.015
  30:16c8      0 days 0:00:00.015
  24:38dc      0 days 0:00:00.015
  19:3b70      0 days 0:00:00.015
   1:12c8      0 days 0:00:00.015
  91:317c      0 days 0:00:00.000
  81:28c0      0 days 0:00:00.000
  54:28cc      0 days 0:00:00.000
  40:2bec      0 days 0:00:00.000
  35:19a0      0 days 0:00:00.000
  25:20c0      0 days 0:00:00.000
  20:2620      0 days 0:00:00.000
  16:2cdc      0 days 0:00:00.000
  15:3474      0 days 0:00:00.000
   9:3ab4      0 days 0:00:00.000
   8:2940      0 days 0:00:00.000
   7:2b14      0 days 0:00:00.000
   3:365c      0 days 0:00:00.000
   2:2278      0 days 0:00:00.000

Answer 1

In order to figure out the cause of the hang (accurate conclusions about bottlenecks), I would suggest you to perform tracing profiling session (it would give an information about number of methods calls and their duration). But that is possible when you know the hang scenario =\

You can find more information about profiling method here: http://www.jetbrains.com/profiler/webhelp/Profiling_Guidelines__Choosing_the_Right_Profiling_Mode.html

Please consider the scenario below:

1. Prepare program for tracing profiling, but don't start it immediately
2. Prepare an operation, which causes 'hang'
3. Start profiling and perform the operation. If you start profiling immediately before page opening and stop immediately after, the snapshot will contain less "noise" from another executions inside application;
4. Get snapshot

The snapshot would show stacktraces with elapsed time.

However, if you do not know the hang scenario, you may capture a memory dump based on HttpResponse time performance counter. You can do it using the DebugDiag tool:

1) Run the DebugDiag tool.

2) Click on the "Add Rule...";

3) In the appeared dialog, select the Performance rule type;

4) Select the "HTTP Response Times";

5) Click on the "Add URL" button;

6) Select "Use ETW to monitor ...". Specify the relative URL to the pages that take much time to load and a timeout - 40 seconds.

7) Add a dump target. Select the "Web application pool" type and select the app pool of the site.

8) Collect all dumps in separate series with 10 seconds interval. These 3 dumps should be full user dumps.

Please take a look at the following post for more details about collecting a "hang dump": http://blogs.msdn.com/b/debugdiag/archive/2013/03/15/debug-diagnostic-1-2-creating-a-rule-in-hang-mode-to-use-the-response-time-of-the-request-etw.aspx

Then you may use !syncblock command to see the chain.

Here is a nice explanation:

Please explain !SyncBlk the windbg command

Answer 2

Try troubleshooting with Failed Request Tracing or PerfView. Both tools can monitor passively and trigger log collection on requests that take longer than the time specified.