High CPU Util 90 % of a w3wp Service

High CPU Utilization OF W3wp reach 90% and stuck and only get resolved by IIS reset. We had just 1 dump and that was very tricky to get the right reason behind the CPU usage:

  #1 There are a lot of long running threads and here is the threads’ CPU time:

 0:000> !runaway

User Mode Time

 Thread Time

  25:4a9c 0 days 0:28:42.875

  27:17cc 0 days 0:15:01.810

  28:4a34 0 days 0:15:00.203

 

!aspxpages

Going to dump the HttpContexts found in the heap.

HttpContext Timeout Completed Running ThreadId ReturnCode Verb RequestPath+QueryString

0x00000000ff2466f8 3600 Sec no 1710 Sec 25 200 GET /file/get/5435dc94-1b37-4a7a-8910-ae4295ad66d3

0x00000000ff2a47e0 3600 Sec no 339 Sec 34 200 POST /DirectRouter.ashx

0x000000013f266cc0 3600 Sec no 907 Sec 28 200 GET /file/GetImageCustom/947a3628-3e4e-42ca-8aa9-b3954d328513/48/48

0x000000013f26c328 3600 Sec no 887 Sec 27 200 GET /file/get/947a3628-3e4e-42ca-8aa9-b3954d328513

0x000000013f2a5270 3600 Sec no 481 Sec 31 200 POST /DirectRouter.ashx

0x000000013f378788 3600 Sec no 34 Sec 33 200 POST /DirectRouter.ashx

0x000000013f37fd88 3600 Sec no 22 Sec 38 200 POST /DirectRouter.ashx

0x000000017f32e040 3600 Sec no 517 Sec 30 200 POST /DirectRouter.ashx

0x000000017f364f80 3600 Sec no 238 Sec 37 200 POST /DirectRouter.ashx

0x000000017f393ba8 3600 Sec no 42 Sec 36 200 POST /DirectRouter.ashx

 

So looked deep in these long running threads 25 27  28 are showing same

!clrstack

OS Thread Id: 0x4a9c (25)

Child-SP RetAddr Call Site

000000000530dd50 000007fef98cf46c System.Collections.Generic.Dictionary`2[[System.__Canon, mscorlib],[System.Boolean, mscorlib]].Insert(System.__Canon, Boolean, Boolean)

000000000530dde0 000007ff00506a99 System.Collections.Generic.Dictionary`2[[System.__Canon, mscorlib],[System.Boolean, mscorlib]].set_Item(System.__Canon, Boolean)

000000000530de10 000007ff00510c78 ModuleName.Security.EcmObjectBase.CanExecuteMethod(System.String)

000000000530dea0 000007ff00510773 ModuleName.Data.DataContexts.Public.FileDataOperation.GetByID(System.Object, Boolean)

000000000530df00 000007ff003b1135 ModuleName.Web.Publish.Controllers.FileController.Get(System.String)

000000000530e0a0 000007feee70ee2f DynamicClass.lambda_method(System.Runtime.CompilerServices.ExecutionScope, System.Web.Mvc.ControllerBase, System.Object[])

000000000530e0e0 000007feee71f98c System.Web.Mvc.ActionMethodDispatcher+<>c__DisplayClass1.<WrapVoidAction>b__0(System.Web.Mvc.ControllerBase, System.Object[])

000000000530e110 000007feee72a36f System.Web.Mvc.ReflectedActionDescriptor.Execute(System.Web.Mvc.ControllerContext, System.Collections.Generic.IDictionary`2<System.String,System.Object>)

000000000530e170 000007feee72b525 System.Web.Mvc.ControllerActionInvoker.InvokeActionMethod(System.Web.Mvc.ControllerContext, System.Web.Mvc.ActionDescriptor, System.Collections.Generic.IDictionary`2<System.String,System.Object>)

000000000530e1b0 000007feee72a43f System.Web.Mvc.ControllerActionInvoker+<>c__DisplayClassa.<InvokeActionMethodWithFilters>b__7()

……………………………

 

If we looked to unmanaged part

Child-SP RetAddr Call Site

00000000`0530dd50 000007fe`f98cf46c mscorlib_ni!System.Collections.Generic.Dictionary`2[[System.IntPtr, mscorlib],[System.Int16, mscorlib]].Insert(IntPtr, Int16, Boolean)+0xffffffff`ff9d7e1f

00000000`0530dde0 000007ff`00506a99 mscorlib_ni!System.Collections.Generic.Dictionary`2[[System.IntPtr, mscorlib],[System.Int16, mscorlib]].set_Item(IntPtr, Int16)+0x160c

00000000`0530de10 000007ff`00510c78 ModuleName !Ecm.Core.Security.EcmObjectBase.CanExecuteMethod(System.String)+0x219

00000000`0530dea0 000007ff`00510773 Ecm_Data_Sql!Ecm.Data.DataContexts.Public.FileDataOperation.GetByID(System.Object, Boolean)+0x68

00000000`0530df00 000007ff`003b1135 ModuleName_Web_Publish!ModuleName.Web.Publish.Controllers.FileController.Get(System.String)+0x143

00000000`0530e0a0 000007fe`ee70ee2f DynamicClass.lambda_method(System.Runtime.CompilerServices.ExecutionScope, System.Web.Mvc.ControllerBase, System.Object[])+0x45

00000000`0530e0e0 000007fe`ee71f98c System_Web_Mvc_ni!System.Web.Mvc.ActionMethodDispatcher+<>c__DisplayClass1.<WrapVoidAction>b__0(System.Web.Mvc.ControllerBase, System.Object[])+0xf

00000000`0530e110 000007fe`ee72a36f System_Web_Mvc_ni!System.Web.Mvc.ReflectedActionDescriptor.Execute(System.Web.Mvc.ControllerContext, System.Collections.Generic.IDictionary`2<System.String,System.Object>)+0xec

…………………..

 

lmvm ModuleName

start end module name

00000000`73410000 00000000`73442000 ModuleName (deferred)            

    Image path: C:\Windows\Microsoft.NET\Framework64\v2.0.50727\Temporary ASP.NET Files\root\2f462865\1d06f6d2\assembly\dl3\9aaaa036\3e11e003_ff30cd01\ ModuleName.DLL

    Image name: ModuleName.DLL

    Using CLR debugging support for all symbols

    Has CLR image header, track-debug-data flag not set

    Timestamp: Sun May 13 13:53:29 2012 (4FAFA0B9)

    CheckSum: 00000000

    ImageSize: 00032000

    File version: 1.0.0.0

    Product version: 1.0.0.0

    File flags: 0 (Mask 3F)

    File OS: 4 Unknown Win32

    File type: 2.0 Dll

    File date: 00000000.00000000

    Translations: 0000.04b0

    CompanyName: ihorizons

    ProductName: ModuleName.Core

    InternalName: ModuleName.Core.dll

    OriginalFilename: ModuleName.Core.dll

    ProductVersion: 1.0.0.0

    FileVersion: 1.0.0.0

    FileDescription: ModuleName.Core

    LegalCopyright: Copyright © ihorizons 2009

 

 

lmvm ModuleName_Data_Sql

Browse full module list

start end module name

00000000`71700000 00000000`71774000 ModuleName_Data_Sql (deferred)            

    Image path: C:\Windows\Microsoft.NET\Framework64\v2.0.50727\Temporary ASP.NET Files\root\2f462865\1d06f6d2\assembly\dl3\af0599e9\b060c105_ff30cd01\ModuleName.Data.Sql.DLL

    Image name: ModuleName.Data.Sql.DLL

    Browse all global symbols functions data

    Using CLR debugging support for all symbols

    Has CLR image header, track-debug-data flag not set

    Timestamp: Sun May 13 13:53:32 2012 (4FAFA0BC)

    CheckSum: 00000000

    ImageSize: 00074000

    File version: 1.0.0.0

    Product version: 1.0.0.0

    File flags: 0 (Mask 3F)

    File OS: 4 Unknown Win32

    File type: 2.0 Dll

    File date: 00000000.00000000

    Translations: 0000.04b0

    CompanyName: ihorizons

    ProductName: ModuleName.Data.Sql

    InternalName: ModuleName.Data.Sql.dll

    OriginalFilename: ModuleName.Data.Sql.dll

    ProductVersion: 1.0.0.0

    FileVersion: 1.0.0.0

    FileDescription: ModuleName.Data.Sql

    LegalCopyright: Copyright © ihorizons 2009

0:030> ModuleName_Web_Publish

 

 

lmvm ModuleName_Web_Publish

Browse full module list

start end module name

00000000`72a50000 00000000`72aac000 ModuleName_Web_Publish (deferred)            

    Image path: C:\Windows\Microsoft.NET\Framework64\v2.0.50727\Temporary ASP.NET Files\root\2f462865\1d06f6d2\assembly\dl3\61a2e23e\15111852_f326cd01\ModuleName.Web.Publish.DLL

    Image name: ModuleName.Web.Publish.DLL

    Browse all global symbols functions data

    Using CLR debugging support for all symbols

    Has CLR image header, track-debug-data flag not set

    Timestamp: Mon Apr 30 19:04:35 2012 (4F9EC623)

    CheckSum: 00000000

    ImageSize: 0005C000

    File version: 1.0.0.0

    Product version: 1.0.0.0

    File flags: 0 (Mask 3F)

    File OS: 4 Unknown Win32

    File type: 2.0 Dll

    File date: 00000000.00000000

    Translations: 0000.04b0

    CompanyName: iHorizons

    ProductName: ModuleName.Web.Publish 

    InternalName: ModuleName.Web.Publish.dll

    OriginalFilename: ModuleName.Web.Publish.dll

    ProductVersion: 1.0.0.0

    FileVersion: 1.0.0.0

    FileDescription: ModuleName.Web.Publish

    LegalCopyright: Copyright © iHorizons 2009

 

#2 There is a lot of threads are showing System.ArgumentOutOfRangeException

0:000> !threads -special

ThreadCount: 27

UnstartedThread: 0

BackgroundThread: 22

PendingThread: 0

DeadThread: 5

Hosted Runtime: no

                                              PreEmptive Lock

       ID OSID ThreadOBJ State GC GC Alloc Context Domain Count APT Exception

   6 1 4b20 00000000025323f0 8220 Enabled 0000000000000000:0000000000000000 00000000013f8240 0 Ukn

  21 2 2868 0000000002548c90 b220 Enabled 0000000000000000:0000000000000000 00000000013f8240 0 MTA (Finalizer)

  22 3 724 0000000002583f20 80a220 Enabled 0000000000000000:0000000000000000 00000000013f8240 0 MTA (Threadpool Completion Port)

  23 4 497c 00000000025846d0 1220 Enabled 0000000000000000:0000000000000000 00000000013f8240 0 Ukn

  25 7 4a9c 00000000056acac0 180b220 Disabled 0000000000000000:0000000000000000 0000000002584ca0 1 MTA (Threadpool Worker)

  14 9 2d4c 00000000056a6ab0 880a220 Enabled 0000000000000000:0000000000000000 00000000013f8240 0 MTA (Threadpool Completion Port)

   5 a 1fd8 0000000002652020 220 Enabled 0000000000000000:0000000000000000 00000000013f8240 0 Ukn

   3 d 3888 0000000002651480 220 Enabled 0000000000000000:0000000000000000 00000000013f8240 0 Ukn

   4 c 4508 00000000026508e0 220 Enabled 0000000000000000:0000000000000000 00000000013f8240 0 Ukn

  27 10 17cc 00000000056b6290 180b220 Disabled 0000000000000000:0000000000000000 0000000002584ca0 1 MTA (Threadpool Worker)

  28 5 4a34 00000000056b6860 180b220 Disabled 0000000000000000:0000000000000000 0000000002584ca0 1 MTA (Threadpool Worker)

  29 e 2864 00000000056b6e30 220 Enabled 0000000000000000:0000000000000000 00000000013f8240 0 Ukn

XXXX 15 0 0000000002650eb0 10820 Enabled 0000000000000000:0000000000000000 00000000013f8240 0 MTA

  30 16 4758 0000000002651a50 180b220 Enabled 00000000ffa327a0:00000000ffa33e40 0000000002584ca0 1 MTA (Threadpool Worker) System.ArgumentOutOfRangeException (00000000ff337d48)

XXXX 1b 0 00000000090300f0 1801820 Enabled 0000000000000000:0000000000000000 00000000013f8240 0 MTA (Threadpool Worker)

XXXX 1d 0 0000000009030c90 1801820 Enabled 0000000000000000:0000000000000000 00000000013f8240 0 Ukn (Threadpool Worker)

XXXX 1f 0 0000000009031830 1801820 Enabled 0000000000000000:0000000000000000 00000000013f8240 0 Ukn (Threadpool Worker)

  31 19 4a6c 000000000902f550 180b220 Enabled 00000001bfa8c1e0:00000001bfa8c530 0000000002584ca0 1 MTA (Threadpool Worker) System.ArgumentOutOfRangeException (00000001bf296000)

  32 20 4a00 0000000009031e00 220 Enabled 0000000000000000:0000000000000000 00000000013f8240 0 Ukn

  33 21 264c 000000000902a9b0 180b220 Enabled 000000013fa54d08:000000013fa54d20 0000000002584ca0 1 MTA (Threadpool Worker) System.ArgumentOutOfRangeException (00000001bf702a70)

  34 25 4854 000000000902c0f0 180b220 Enabled 000000017fb7e800:000000017fb7faa8 0000000002584ca0 1 MTA (Threadpool Worker) System.ArgumentOutOfRangeException (000000017f3acd10)

XXXX 23 0 000000000902b550 1801820 Enabled 0000000000000000:0000000000000000 00000000013f8240 0 Ukn (Threadpool Worker)

  36 22 4554 000000000902af80 180b220 Enabled 00000000ffa8bc68:00000000ffa8be40 0000000002584ca0 1 MTA (Threadpool Worker) System.ArgumentOutOfRangeException (00000000ff8f3268)

  37 1e 4538 0000000009031260 180b220 Enabled 00000001bfb34cc8:00000001bfb34d08 0000000002584ca0 1 MTA (Threadpool Worker) System.ArgumentOutOfRangeException (00000001bf99e810)

  35 1c 42e4 00000000090306c0 220 Enabled 0000000000000000:0000000000000000 00000000013f8240 0 Ukn

  38 14 3bcc 000000000902bb20 180b220 Enabled 000000013fa9ec60:000000013fa9ed20 0000000002584ca0 1 MTA (Threadpool Worker) System.ArgumentOutOfRangeException (000000013f930410)

  40 1a 4be8 000000000902c6c0 180b220 Enabled 00000001bf831b78:00000001bf831ca8 0000000002584ca0 0 MTA (Threadpool Worker)

 

       OSID Special thread type

   14 2d4c IOCompletion

   15 4450 Gate

   16 4558 DbgHelper

   17 41cc GC

   18 47f0 GC

   19 4818 GC

   20 4a94 GC

   21 2868 Finalizer

   22 724 Timer

   23 497c ADUnloadHelper

   25 4a9c ThreadpoolWorker

   27 17cc ThreadpoolWorker

   28 4a34 ThreadpoolWorker

   30 4758 ThreadpoolWorker

   31 4a6c ThreadpoolWorker

   33 264c ThreadpoolWorker

   34 4854 ThreadpoolWorker

   36 4554 ThreadpoolWorker

   37 4538 ThreadpoolWorker

   38 3bcc ThreadpoolWorker

   40 4be8 ThreadpoolWorker

 

Most of the exception in the dump:

 

Number of exceptions of this type: 31

Exception MethodTable: 000007fef93b70f8

Exception object: 00000000ff2c8da0

Exception type: System.ArgumentOutOfRangeException

Message: Index was out of range. Must be non-negative and less than the size of the collection.

InnerException: <none>

StackTrace (generated):

    SP IP Function

    0000000005B3CA00 000007FEF983EB2F System.ThrowHelper.ThrowArgumentOutOfRangeException()

    0000000005B3CA40 000007FEF926BA96 System.Collections.Generic.List`1[[System.__Canon, mscorlib]].get_Item(Int32)

    0000000005B3CA80 000007FEF92FB042 System.Collections.ObjectModel.Collection`1[[System.__Canon, mscorlib]].System.Collections.IList.get_Item(Int32)

    0000000005B3CAD0 000007FF0045C9F8 ModuleName.Data.DataContexts.Public.ViewDataOperation.QueryManagerInitialize(ModuleName.Data.DataQuery.Query)

 

Have you any idea why there are so much exceptions of same types...

 

 

# 3 Checked the loaded managed modules’ production. Some are not set to Debug=False.

 

!FindDebugTrue

Debug set to true for Runtime: 3f15b918, AppDomain: D:\Inetpub\DOI_newsite\Publish.DOI.com.Rel\

Total 2 HttpRuntime objects

 

There is 21 Module are running in debug mode.

 

!FindDebugModules

Loading all modules.

Searching for modules built in debug mode...

LIST Of Modules

 

Don’t run production ASP.NET Applications with debug=”true” enabled

https://weblogs.asp.net/scottgu/archive/2006/04/11/442448.aspx

 

ASP.NET Memory: If your application is in production… then why is debug=true

https://blogs.msdn.com/b/tess/archive/2006/04/13/575364.aspx

 

 

Conclusion

==========

 

 Modules ModuleName.Web.Publish, ModuleName.Data.Sql.dll and  Ecm.Core.dll

 

And Methods:

  1. ModuleName.Core.Security.EcmObjectBase.CanExecuteMethod(System.String)
  2. ModuleName.Core.Security.EcmObjectBase.CanExecuteMethod(System.String)
  3. ModuleName.Data.DataContexts.Public.FileDataOperation.GetByID(System.Object, Boolean)
  4. ModuleName.Web.Publish.Controllers.FileController.Get()

 

Are utilizing CPU as seen in the threads  25,27,28.