When our ASP.NET website is under heavy load, every now and then, one of the servers will just go wild and use 100% CPU without responding at all. When I run stackdump.exe
on the running process, I see that practically all threads are ending in the method LocalDataStoreMgr.GetNamedDataSlot
. Some stacks look as if our own code calls into GetNamedDataSlot
, others show HttpApplication.ExecuteStep
or HttpWriter.Write
doing it. Here is a snippet from the stack dump:
OS Thread Id:9232
System.LocalDataStoreMgr.GetNamedDataSlot(System.LocalDataStoreMgrN/A)
System.Web.HttpApplication.ExecuteStep(ASP.global_asaxSystem.Web.HttpApplication+AsyncEventExecutionStepSystem.Boolean&)
System.Web.HttpApplication+PipelineStepManager.ResumeSteps(System.Web.HttpApplication+PipelineStepManagerN/A)
System.Web.HttpApplication.BeginProcessRequestNotification(N/AN/AN/A)
System.Web.HttpRuntime.ProcessRequestNotificationPrivate(System.Web.HttpRuntimeSystem.Web.Hosting.IIS7WorkerRequestSystem.Web.HttpContext)
System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(N/ASystem.IntPtrN/AN/A)
System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(N/AN/AN/AN/A)
System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(N/AN/AN/AN/A)
System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(N/AN/AN/AN/A)
OS Thread Id:15308
System.LocalDataStoreMgr.GetNamedDataSlot(System.LocalDataStoreMgrN/A)
System.Web.HttpWriter.Write(System.Web.HttpWriterSystem.String)
System.Web.HttpWriter.Write(N/AN/A)
ASP.views_shared_advertcat_setadvertinformation_ascx.__Render__control1(N/AN/AN/A)
System.Web.UI.Control.RenderChildrenInternal(N/AN/AN/A)
System.Web.UI.Control.RenderControl(N/AN/AN/A)
System.Web.UI.Control.RenderControl(N/AN/AN/A)
System.Web.UI.Control.RenderChildrenInternal(N/AN/AN/A)
System.Web.Mvc.ViewPage.Render(System.Web.Mvc.ViewUserControl+ViewUserControlContainerPageN/A)
System.Web.UI.Control.RenderControl(N/AN/AN/A)
System.Web.UI.Control.RenderControl(N/AN/AN/A)
System.Web.UI.Page.ProcessRequestMain(System.Web.Mvc.ViewUserControl+ViewUserControlContainerPageSystem.BooleanSystem.Boolean)
System.Web.UI.Page.ProcessRequest(System.Web.Mvc.ViewUserControl+ViewUserControlContainerPageN/ASystem.Boolean)
System.Web.UI.Page.ProcessRequest(N/AN/AN/A)
System.Web.UI.Page.ProcessRequest(System.Web.Mvc.ViewUserControl+ViewUserControlContainerPage)
System.Web.UI.Page.ProcessRequest(N/AN/A)
System.Web.Mvc.ViewPage.ProcessRequest(N/AN/A)
System.Web.Mvc.ViewUserControl+ViewUserControlContainerPage.ProcessRequest(N/AN/A)
System.Web.Mvc.HttpHandlerUtil+ServerExecuteHttpHandlerWrapper+<>c__DisplayClass4.<Wrap>b__3(N/A)
System.Web.Mvc.HttpHandlerUtil+ServerExecuteHttpHandlerWrapper.Wrap(N/A)
System.Web.HttpServerUtility.ExecuteInternal(System.Web.HttpServerUtilitySystem.Web.Mvc.HttpHandlerUtil+ServerExecuteHttpHandlerWrapperN/AN/AN/ASystem.Web.VirtualPathN/AN/ASystem.ExceptionSystem.String)
System.Web.HttpServerUtility.Execute(N/AN/AN/AN/AN/A)
System.Web.HttpServerUtility.Execute(N/AN/AN/AN/A)
System.Web.Mvc.ViewPage.RenderView(N/AN/A)
System.Web.Mvc.ViewUserControl.RenderView(N/AN/A)
System.Web.Mvc.ViewResultBase.ExecuteResult(N/AN/A)
System.Web.Mvc.ControllerActionInvoker+<>c__DisplayClass1a.<InvokeActionResultWithFilters>b__17(N/A)
System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilter(Funda.Web.Mvc.Controllers.Shared.AdvertControllerSystem.Web.Mvc.ResultExecutingContextN/A)
System.Web.Mvc.ControllerActionInvoker.InvokeActionResultWithFilters(N/AN/AN/AN/A)
System.Web.Mvc.Async.AsyncControllerActionInvoker+<>c__DisplayClass25.<BeginInvokeAction>b__22(System.Web.Mvc.Async.AsyncControllerActionInvoker+<>c__DisplayClass25N/A)
System.Web.Mvc.Controller+<>c__DisplayClass1d.<BeginExecuteCore>b__18(N/AN/A)
System.Web.Mvc.Async.AsyncResultWrapper+<>c__DisplayClass4.<MakeVoidDelegate>b__3(N/AN/A)
System.Web.Mvc.Controller.EndExecuteCore(Funda.Web.Mvc.Controllers.Shared.AdvertControllerN/A)
System.Web.Mvc.Async.AsyncResultWrapper+<>c__DisplayClass4.<MakeVoidDelegate>b__3(N/AN/A)
System.Web.Mvc.MvcHandler+<>c__DisplayClass8.<BeginProcessRequest>b__3(System.Web.Mvc.MvcHandler+<>c__DisplayClass8N/A)
System.Web.Mvc.Async.AsyncResultWrapper+<>c__DisplayClass4.<MakeVoidDelegate>b__3(N/AN/A)
System.Web.Mvc.HttpHandlerUtil+ServerExecuteHttpHandlerWrapper+<>c__DisplayClass4.<Wrap>b__3(N/A)
System.Web.Mvc.HttpHandlerUtil+ServerExecuteHttpHandlerWrapper.Wrap(N/A)
System.Web.HttpServerUtility.ExecuteInternal(System.Web.HttpServerUtilitySystem.Web.Mvc.HttpHandlerUtil+ServerExecuteHttpHandlerAsyncWrapperN/AN/AN/ASystem.Web.VirtualPathN/AN/ASystem.ExceptionSystem.String)
System.Web.HttpServerUtility.Execute(N/AN/AN/AN/AN/A)
System.Web.HttpServerUtility.Execute(N/AN/AN/AN/A)
System.Web.Mvc.Html.ChildActionExtensions.ActionHelper(N/AN/AN/AN/AN/A)
ASP.views_homepage_homepage_aspx.__Render__control5(N/AN/AN/A)
System.Web.UI.Control.RenderChildrenInternal(N/AN/AN/A)
System.Web.UI.Control.RenderControl(N/AN/AN/A)
System.Web.UI.Control.RenderControl(N/AN/AN/A)
ASP.views_masterpages_homepage_master.__Render__control1(ASP.views_masterpages_homepage_masterSystem.Web.UI.HtmlTextWriterASP.views_masterpages_homepage_master)
System.Web.UI.Control.RenderChildrenInternal(N/AN/AN/A)
System.Web.UI.Control.RenderControl(N/AN/AN/A)
System.Web.UI.Control.RenderControl(N/AN/AN/A)
System.Web.UI.Control.RenderChildrenInternal(N/AN/AN/A)
System.Web.Mvc.ViewPage.Render(ASP.views_homepage_homepage_aspxN/A)
System.Web.UI.Control.RenderControl(N/AN/AN/A)
System.Web.UI.Control.RenderControl(N/AN/AN/A)
System.Web.UI.Page.ProcessRequestMain(ASP.views_homepage_homepage_aspxSystem.BooleanSystem.Boolean)
System.Web.UI.Page.ProcessRequest(ASP.views_homepage_homepage_aspxN/ASystem.Boolean)
System.Web.UI.Page.ProcessRequest(N/AN/AN/A)
System.Web.UI.Page.ProcessRequest(ASP.views_homepage_homepage_aspx)
System.Web.UI.Page.ProcessRequest(N/AN/A)
System.Web.Mvc.ViewPage.ProcessRequest(N/AN/A)
System.Web.Mvc.HttpHandlerUtil+ServerExecuteHttpHandlerWrapper+<>c__DisplayClass4.<Wrap>b__3(N/A)
System.Web.Mvc.HttpHandlerUtil+ServerExecuteHttpHandlerWrapper.Wrap(N/A)
System.Web.HttpServerUtility.ExecuteInternal(System.Web.HttpServerUtilitySystem.Web.Mvc.HttpHandlerUtil+ServerExecuteHttpHandlerWrapperN/AN/AN/ASystem.Web.VirtualPathN/AN/ASystem.ExceptionSystem.String)
System.Web.HttpServerUtility.Execute(N/AN/AN/AN/AN/A)
System.Web.HttpServerUtility.Execute(N/AN/AN/AN/A)
System.Web.Mvc.ViewPage.RenderView(N/AN/A)
System.Web.Mvc.ViewResultBase.ExecuteResult(N/AN/A)
System.Web.Mvc.ControllerActionInvoker+<>c__DisplayClass1a.<InvokeActionResultWithFilters>b__17(N/A)
System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilter(Funda.Web.Mvc.Attributes.DataForGoogleAnalyticsAttributeSystem.Web.Mvc.ResultExecutingContextN/A)
System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilter(Funda.Web.Mvc.Attributes.SetLanguageFromProfileAttributeSystem.Web.Mvc.ResultExecutingContextN/A)
System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilter(Funda.Web.Mvc.Attributes.DataForLoginAttributeSystem.Web.Mvc.ResultExecutingContextN/A)
System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilter(Funda.Web.Mvc.Attributes.DataForNotifyAttributeSystem.Web.Mvc.ResultExecutingContextN/A)
System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilter(Funda.Web.Mvc.Controllers.HomepageControllerSystem.Web.Mvc.ResultExecutingContextN/A)
System.Web.Mvc.ControllerActionInvoker.InvokeActionResultWithFilters(N/AN/AN/AN/A)
System.Web.Mvc.Async.AsyncControllerActionInvoker+<>c__DisplayClass25.<BeginInvokeAction>b__22(System.Web.Mvc.Async.AsyncControllerActionInvoker+<>c__DisplayClass25N/A)
System.Web.Mvc.Controller+<>c__DisplayClass1d.<BeginExecuteCore>b__18(N/AN/A)
System.Web.Mvc.Async.AsyncResultWrapper+<>c__DisplayClass4.<MakeVoidDelegate>b__3(N/AN/A)
System.Web.Mvc.Controller.EndExecuteCore(Funda.Web.Mvc.Controllers.HomepageControllerN/A)
System.Web.Mvc.Async.AsyncResultWrapper+<>c__DisplayClass4.<MakeVoidDelegate>b__3(N/AN/A)
System.Web.Mvc.MvcHandler+<>c__DisplayClass8.<BeginProcessRequest>b__3(System.Web.Mvc.MvcHandler+<>c__DisplayClass8N/A)
System.Web.Mvc.Async.AsyncResultWrapper+<>c__DisplayClass4.<MakeVoidDelegate>b__3(N/AN/A)
System.Web.HttpApplication+CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute(N/A)
System.Web.HttpApplication+CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute(N/A)
System.Web.HttpApplication.ExecuteStep(ASP.global_asaxN/ASystem.Boolean&)
System.Web.HttpApplication.ExecuteStep(N/AN/AN/A)
System.Web.HttpApplication+PipelineStepManager.ResumeSteps(System.Web.HttpApplication+PipelineStepManagerN/A)
System.Web.HttpApplication.BeginProcessRequestNotification(N/AN/AN/A)
System.Web.HttpRuntime.ProcessRequestNotificationPrivate(System.Web.HttpRuntimeSystem.Web.Hosting.IIS7WorkerRequestSystem.Web.HttpContext)
System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(N/ASystem.IntPtrN/AN/A)
System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(N/AN/AN/AN/A)
System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(N/AN/AN/AN/A)
System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(N/AN/AN/AN/A)
OS Thread Id:25392
System.LocalDataStoreMgr.GetNamedDataSlot(System.LocalDataStoreMgrN/A)
Funda.App.Caching.CacheManager.GetFromCache(Funda.App.Caching.CacheManagerSystem.StringSystem.Func`1<Funda.Common.ServiceLayer.KoppelenEngineService.KlantMijnMakelaarKoppeling>)
Funda.Web.Mvc.Mappers.Shared.MijnMakelaarMapper.GetMijnMakelaarKoppeling(N/AN/A)
Funda.Web.Mvc.Mappers.SharedViewModelMapper.MapToLoginViewModel(N/AN/AN/AN/AN/AN/A)
Funda.Web.Mvc.Attributes.DataForLoginAttribute.OnActionExecuted(N/AN/A)
...
I think I understand what Thread Local Storage is, but I don't understand why this call is apparently made from these places. We do not explicitly call Thread.GetNamedDataSlot
anywhere. Neither does the BCL code in the methods indicated by these logs (if I may trust ILSpy).
Why is this method called so often? What should I do to prevent this situation (looks like a locking hotspot to me)?
The GetFromCache method(s) can be seen below. The _instrumentation
field is static. The implementation of that class, that does involve thread-aware code is also included.
public T GetFromCache<T>(string key, Func<T> fetchAction, bool stampedeProtection, Func<T, Boolean> needsStoring)
{
// argh?
key = AddCacheVersionNumberToKey(key);
long startTime = 0;
long endTime = 0;
int timesSlept = 0;
if (_usingCounters)
{
NativeMethods.QueryPerformanceCounter(ref startTime);
}
_log.Debug("GetFromCache: [" + _durationGroup + "] " + key);
object obj = null;
while (obj == null)
{
obj = _store.Get(key);
if(obj is NotImplementedException)
{
// this is a nasty case where the store is not able to deserialize without knowing the type
obj = _store.Get<T>(key);
}
if (obj is NullValue)
{
return default(T);
}
if (CacheDisabledFromUrl(key) || obj is String && string.IsNullOrEmpty(obj.ToString()))
{
obj = null;
}
if (obj == null)
{
// Niet gevonden
if (timesSlept > Settings.Default.StampedeMaxSleepCycles)
{
_log.WarnFormat("Waiting for {0} x {1} ms for a locked cache key. Some other thread is taking very long to fill {2}. We will try it ourselves.", Settings.Default.StampedeMaxSleepCycles, Settings.Default.StampedeSleepTime, key);
stampedeProtection = false;
}
if (stampedeProtection)
{
// special case: we want to make sure that only one thread does the fetch after the miss.
if (_store.AcquireLock(key))
{
if (_usingCounters)
{
// log a miss only when we acquire the lock: other cases are just a slow hit
NativeMethods.QueryPerformanceCounter(ref endTime);
_instrumentation.RegisterMiss(_durationGroup, endTime - startTime, key);
startTime = endTime;
}
try
{
// We have to do the work
obj = fetchAction.Invoke();
if (_usingCounters)
{
NativeMethods.QueryPerformanceCounter(ref endTime);
_instrumentation.RegisterFetch(_durationGroup, obj, endTime - startTime, key);
}
if (obj == null)
{
_store.Store(key, new NullValue());
return default(T);
}
else if (needsStoring((T)obj))
{
if (_usingCounters)
{
NativeMethods.QueryPerformanceCounter(ref startTime);
}
_store.Store<T>(key, (T)obj);
if (_usingCounters)
{
NativeMethods.QueryPerformanceCounter(ref endTime);
_instrumentation.RegisterStore(_durationGroup, obj, endTime - startTime, key);
}
}
}
finally
{
_store.ReleaseLock(key);
}
}
else
{
// Wait and try again
// after 500 ms, hopefully, another thread will have filled the cache
Thread.Sleep(500);
timesSlept++;
}
}
else
{
// Standard flow for miss: fetch and store
if (_usingCounters)
{
// log a miss
NativeMethods.QueryPerformanceCounter(ref endTime);
_instrumentation.RegisterMiss(_durationGroup, endTime - startTime, key);
startTime = endTime;
}
obj = fetchAction.Invoke();
if (_usingCounters)
{
// log a fetch
NativeMethods.QueryPerformanceCounter(ref endTime);
_instrumentation.RegisterFetch(_durationGroup, obj, endTime - startTime, key);
}
if (obj == null)
{
_store.Store(key, new NullValue());
return default(T);
}
if (needsStoring((T)obj))
{
if (_usingCounters) NativeMethods.QueryPerformanceCounter(ref startTime);
_store.Store<T>(key, (T)obj);
if (_usingCounters)
{
NativeMethods.QueryPerformanceCounter(ref endTime);
_instrumentation.RegisterStore(_durationGroup, obj, endTime - startTime, key);
}
}
}
}
else
{
// Get is (uiteindelijk) gelukt. We loggen een Hit
if (_usingCounters)
{
NativeMethods.QueryPerformanceCounter(ref endTime);
_instrumentation.RegisterHit(_durationGroup, obj, endTime - startTime, key);
}
if (HttpContext.Current != null && HttpContext.Current.Request.Url.Query.Contains("queryinfo") && QueryTraceHttpContextAppender.Current != null)
{
string storeName = _store.GetType().Name.Replace("Store", "");
QueryTraceHttpContextAppender.Current.AppendDirect(String.Format("{0}: [Key] {1}", storeName, key));
}
}
}
return (T)obj;
}
More extensive code snippet here.
It turned out that the strange call was indeed caused by the New Relic Agent. The methods in case are all instrumented methods. However, with New Relic disabled, the performance problem did not go away. The stacks were more informative though. So question answered. @jessehouwing, if you reformulate your remark as an answer, I'd be happy to accept.
I found this explanation
"Threads use a local store memory mechanism to store thread-specific data. The common language runtime allocates a multi-slot data store array to each process when it is created. The thread can allocate a data slot in the data store, store and retrieve a data value in the slot, and free the slot for reuse after the thread expires. Data slots are unique per thread. No other thread (not even a child thread) can get that data.
If the named slot does not exist, a new slot is allocated. Named data slots are public and can be manipulated by anyone. "
The source is :http://msdn.microsoft.com/en-us/library/system.threading.thread.getnameddataslot%28v=vs.110%29.aspx
in this article explain that is possible to rewrite this behavior
http://msdn.microsoft.com/en-us/library/6sby1byh%28v=vs.110%29.aspx
the problem i think is that .net are reusing the same name for save the slot and this cause the bad performance.
is posible than one solution is to clean the runtime callable wrappers.
i found this:
http://msdn.microsoft.com/en-us/library/system.threading.thread.disablecomobjecteagercleanup%28v=vs.100%29.aspx
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With