Debugging Story: Race-condition v Umbraco CMS (DeepClone)

Řešil jsem dnes s kolegou Jakubem Čermákem zajímavou situaci. Komprimovanou podobu situace zaznamenávám jako inspiraci pro podobné situace ladění.

Symptom

Na jednom z našich produkčních webových serverů dnes v časných ranních hodinách vyskočila zátěž CPU na 100%. Rychlý pohled do TaskManageru ukázal, že viníkem byl aplikační pool s redakčním systémem UmbracoCMS, který používáme pro jeden z frontendů jako content-databázi a administrační UI (UmbracoCMS zde tedy nerenderuje front-end, ale samostatná ASP.NET front-endová aplikace si přes API říká Umbraco-webu pouze pro data, z kterých výstup sestavuje – různé HTML segmenty, resources atp. editované v CMS).

Stejná situace již v minulosti dvakrát nastala (rozestup v řádu týdnů), vždy pomohlo restartování aplikačního poolu Umbraco. Tentokrát se nám podařilo před restartem poolu sejmout memory-dump postiženého procesu.

Analysis

Na každý získaný memory-dump dnes již automaticky jako první úkon pouštím DebugDiag. Získám tím relativně rychle základní přehled o situaci, např.

  • kolik je zhruba čeho v paměti (kolik zabírá managed heap, jaké typy v něm zabírají nejvíce paměti, …)
  • kolik je threadů a co dělají (call-stacky, waity/locky, …)
  • jestli zrovna běží úkolid garbage-collectorem,
  • atp.

Výstup z DebugDiag ukázal, že call-stack několika desítek aktivních threadů se shoduje:

mscorlib_ni!System.Collections.Generic.Dictionary`2[[System.__Canon, mscorlib],[System.Boolean, mscorlib]].Insert(System.__Canon, Boolean, Boolean)+1f0 
Umbraco.Core.Models.EntityBase.TracksChangesEntityBase.OnPropertyChanged(System.Reflection.PropertyInfo)+3e 
Umbraco.Core.Models.EntityBase.TracksChangesEntityBase.SetPropertyValueAndDetectChanges[[System.__Canon, mscorlib]](System.Func`2<System.__Canon,System.__Canon>, System.__Canon, System.Reflection.PropertyInfo)+5c 
Umbraco.Core.Models.ContentType.set_AllowedTemplates(System.Collections.Generic.IEnumerable`1<Umbraco.Core.Models.ITemplate>)+80 
clr!CallDescrWorkerInternal+83 
clr!CallDescrWorkerWithHandler+4a 
clr!CallDescrWorkerReflectionWrapper+1a 
clr!RuntimeMethodHandle::InvokeMethod+46a 
[[DebuggerU2MCatchHandlerFrame]] 
[[HelperMethodFrame_PROTECTOBJ] (System.RuntimeMethodHandle.InvokeMethod)] System.RuntimeMethodHandle.InvokeMethod(System.Object, System.Object[], System.Signature, Boolean) 
mscorlib_ni!System.Reflection.RuntimeMethodInfo.UnsafeInvokeInternal(System.Object, System.Object[], System.Object[])+4c 
mscorlib_ni!System.Reflection.RuntimeMethodInfo.Invoke(System.Object, System.Reflection.BindingFlags, System.Reflection.Binder, System.Object[], System.Globalization.CultureInfo)+d3 
mscorlib_ni!System.Reflection.RuntimePropertyInfo.SetValue(System.Object, System.Object, System.Object[])+2c 
Umbraco.Core.Models.DeepCloneHelper.DeepCloneRefProperties(Umbraco.Core.Models.IDeepCloneable, Umbraco.Core.Models.IDeepCloneable)+61d 
Umbraco.Core.Models.ContentTypeCompositionBase.DeepClone()+3d 
Umbraco.Core.Models.ContentTypeCompositionBase.<DeepClone>b__2f(Umbraco.Core.Models.IContentTypeComposition)+14 
System_Core_ni!System.Linq.Enumerable+WhereSelectListIterator`2[[System.__Canon, mscorlib],[System.__Canon, mscorlib]].MoveNext()+f4 
mscorlib_ni!System.Collections.Generic.List`1[[System.__Canon, mscorlib]]..ctor(System.Collections.Generic.IEnumerable`1<System.__Canon>)+218 
System_Core_ni!System.Linq.Enumerable.ToList[[System.__Canon, mscorlib]](System.Collections.Generic.IEnumerable`1<System.__Canon>)+50 
Umbraco.Core.Models.ContentTypeCompositionBase.DeepClone()+1bb 
Umbraco.Core.Persistence.Caching.RuntimeCacheProvider.GetById(System.Type, System.Guid)+ea 
Umbraco.Core.Persistence.Repositories.RepositoryBase`2[[System.Int32, mscorlib],[System.__Canon, mscorlib]].TryGetFromCache(Int32)+bb 
Umbraco.Core.Persistence.Repositories.RepositoryBase`2[[System.Int32, mscorlib],[System.__Canon, mscorlib]].Get(Int32)+3c 
Umbraco.Core.Persistence.Repositories.ContentRepository.CreateContentFromDto(Umbraco.Core.Models.Rdbms.DocumentDto, System.Guid)+5d 
Umbraco.Core.Persistence.Repositories.ContentRepository.PerformGet(Int32)+2e0 
Umbraco.Core.Persistence.Repositories.RepositoryBase`2[[System.Int32, mscorlib],[System.__Canon, mscorlib]].Get(Int32)+7b 
Umbraco.Core.Services.ContentService.GetById(Int32)+69 
Havit.XyzPortal.Services.ContentManagement.EpoUrlProvider.GetUrl(Umbraco.Core.ApplicationContext, Int32, System.Uri, Umbraco.Web.Routing.UrlProviderMode)+108 
Umbraco.Web.Routing.UrlProvider+<>c__DisplayClass3.<GetUrl>b__0(Umbraco.Web.Routing.IUrlProvider)+32 
System_Core_ni!System.Linq.Enumerable+WhereSelectArrayIterator`2[[System.__Canon, mscorlib],[System.__Canon, mscorlib]].MoveNext()+52 
System_Core_ni!System.Linq.Enumerable.FirstOrDefault[[System.__Canon, mscorlib]](System.Collections.Generic.IEnumerable`1<System.__Canon>, System.Func`2<System.__Canon,Boolean>)+d7 
Umbraco.Web.Routing.UrlProvider.GetUrl(Int32, System.Uri, Umbraco.Web.Routing.UrlProviderMode)+ec 
Umbraco.Web.Templates.TemplateUtilities.ParseInternalLinks(System.String)+170 
Havit.XyzPortal.UmbracoCMS.UmContentApiController.TraverseResourceDictionary(System.Collections.Generic.List`1<Havit.XyzPortal.Services.Resources.DataObjects.ResourceDictionaryDTO>, Umbraco.Core.Models.IContent, Boolean)+32e 
Havit.XyzPortal.UmbracoCMS.UmContentApiController.TraverseResourceDictionary(System.Collections.Generic.List`1<Havit.XyzPortal.Services.Resources.DataObjects.ResourceDictionaryDTO>, Umbraco.Core.Models.IContent, Boolean)+dd 
Havit.XyzPortal.UmbracoCMS.UmContentApiController.TraverseResourceDictionary(System.Collections.Generic.List`1<Havit.XyzPortal.Services.Resources.DataObjects.ResourceDictionaryDTO>, Umbraco.Core.Models.IContent, Boolean)+dd 
Havit.XyzPortal.UmbracoCMS.UmContentApiController.Resources(System.Nullable`1<Boolean>)+113 
Havit.XyzPortal.UmbracoCMS.UmContentApiController.Resources()+21 
DynamicClass.lambda_method(System.Runtime.CompilerServices.Closure, System.Object, System.Object[])+4f 
System.Web.Http.Controllers.ReflectedHttpActionDescriptor+ActionExecutor+<>c__DisplayClass13.<GetExecutor>b__c(System.Object, System.Object[])+15 
System.Web.Http.Controllers.ReflectedHttpActionDescriptor+ActionExecutor.Execute(System.Object, System.Object[])+f 
System.Threading.Tasks.TaskHelpers.RunSynchronously[[System.__Canon, mscorlib]](System.Func`1<System.Threading.Tasks.Task`1<System.__Canon>>, System.Threading.CancellationToken)+78 
System.Web.Http.Controllers.ApiControllerActionInvoker+<>c__DisplayClass3.<InvokeActionAsync>b__0()+29 
System.Threading.Tasks.TaskHelpers.RunSynchronously[[System.__Canon, mscorlib]](System.Func`1<System.Threading.Tasks.Task`1<System.__Canon>>, System.Threading.CancellationToken)+78 
System.Web.Http.Controllers.ApiControllerActionInvoker.InvokeActionAsync(System.Web.Http.Controllers.HttpActionContext, System.Threading.CancellationToken)+98 
System.Web.Http.ApiController+<>c__DisplayClass3.<ExecuteAsync>b__2()+33 
System.Web.Http.ApiController+<>c__DisplayClass3.<ExecuteAsync>b__1()+c5 
System.Threading.Tasks.TaskHelpersExtensions+<>c__DisplayClass32`1[[System.__Canon, mscorlib]].<Then>b__31(System.Threading.Tasks.Task)+f 
System.Threading.Tasks.TaskHelpersExtensions.ThenImpl[[System.__Canon, mscorlib],[System.__Canon, mscorlib]](System.__Canon, System.Func`2<System.__Canon,System.Threading.Tasks.Task`1<System.__Canon>>, System.Threading.CancellationToken, Boolean)+114 
System.Web.Http.ApiController+<>c__DisplayClass3.<ExecuteAsync>b__0()+74 
System.Web.Http.ApiController.ExecuteAsync(System.Web.Http.Controllers.HttpControllerContext, System.Threading.CancellationToken)+1cf 
System.Web.Http.Dispatcher.HttpControllerDispatcher.SendAsync(System.Net.Http.HttpRequestMessage, System.Threading.CancellationToken)+76 
System_Net_Http_ni!System.Net.Http.HttpMessageInvoker.SendAsync(System.Net.Http.HttpRequestMessage, System.Threading.CancellationToken)+4f 
System.Web.Http.Dispatcher.HttpRoutingDispatcher.SendAsync(System.Net.Http.HttpRequestMessage, System.Threading.CancellationToken)+175 
System.Web.Http.HttpServer.SendAsync(System.Net.Http.HttpRequestMessage, System.Threading.CancellationToken)+ff 
System_Net_Http_ni!System.Net.Http.HttpMessageInvoker.SendAsync(System.Net.Http.HttpRequestMessage, System.Threading.CancellationToken)+4f 
System.Web.Http.WebHost.HttpControllerHandler.BeginProcessRequest(System.Web.HttpContextBase, System.AsyncCallback, System.Object)+11f 
System_Web_ni!System.Web.HttpApplication+CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()+1e2 
System_Web_ni!System.Web.HttpApplication.ExecuteStep(IExecutionStep, Boolean ByRef)+120 
System_Web_ni!System.Web.HttpApplication+PipelineStepManager.ResumeSteps(System.Exception)+92a 
System_Web_ni!System.Web.HttpApplication.BeginProcessRequestNotification(System.Web.HttpContext, System.AsyncCallback)+83 
System_Web_ni!System.Web.HttpRuntime.ProcessRequestNotificationPrivate(System.Web.Hosting.IIS7WorkerRequest, System.Web.HttpContext)+28e 
System_Web_ni!System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(IntPtr, IntPtr, IntPtr, Int32)+5c1 
System_Web_ni!System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(IntPtr, IntPtr, IntPtr, Int32)+22 
System_Web_ni!DomainNeutralILStubClass.IL_STUB_ReversePInvoke(Int64, Int64, Int64, Int32)+51 
clr!UMThunkStub+6e 
webengine4!W3_MGD_HANDLER::ProcessNotification+78 
webengine4!W3_MGD_HANDLER::DoWork+34f 
webengine4!RequestDoWork+34e 
webengine4!CMgdEngHttpModule::OnExecuteRequestHandler+21 
iiscore!NOTIFICATION_CONTEXT::RequestDoWork+233 
iiscore!NOTIFICATION_CONTEXT::CallModulesInternal+174 
iiscore!NOTIFICATION_CONTEXT::CallModules+25 
iiscore!W3_CONTEXT::DoWork+34d 
iiscore!W3_CONTEXT::IndicateCompletion+8c 
webengine4!MgdIndicateCompletion+60 
System_Web_ni!DomainNeutralILStubClass.IL_STUB_PInvoke(IntPtr, System.Web.RequestNotificationStatus ByRef)+7b 
[[InlinedCallFrame] (System.Web.Hosting.UnsafeIISMethods.MgdIndicateCompletion)] System.Web.Hosting.UnsafeIISMethods.MgdIndicateCompletion(IntPtr, System.Web.RequestNotificationStatusByRef) 
System_Web_ni!System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(IntPtr, IntPtr, IntPtr, Int32)+7af 
System_Web_ni!System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(IntPtr, IntPtr, IntPtr, Int32)+22 
System_Web_ni!DomainNeutralILStubClass.IL_STUB_ReversePInvoke(Int64, Int64, Int64, Int32)+51 
clr!UM2MThunk_WrapperHelper+43 
clr!UM2MThunk_Wrapper+5a 
clr!Thread::DoADCallBack+139 
[[ContextTransitionFrame]] 
clr!UM2MDoADCallBack+91 
clr!UMThunkStub+26d 
webengine4!W3_MGD_HANDLER::ProcessNotification+78 
webengine4!ProcessNotificationCallback+42 
clr!UnManagedPerAppDomainTPCount::DispatchWorkItem+122 
clr!ThreadpoolMgr::ExecuteWorkRequest+46 
clr!ThreadpoolMgr::WorkerThreadStart+f4 
clr!Thread::intermediateThreadProc+7d 
kernel32!BaseThreadInitThunk+d 
ntdll!RtlUserThreadStart+1d 

První procházení zdrojových kódů dotčených metod (nejprve „just my code“, dále i Umbraco a nakonec i .NET) neukázalo na očividného viníka. Na call-stacku se děje zhruba toto:

  1. Přichází web-request na službu poskytující front-endu data o resources. Náš REST-API UmContentApiController vrací front-endu strukturu všech resources, které UmbracoCMS v má (UmContentApiController.Resources()).
  2. Během sestavování výstupu pro jednotlivé resources vyhodnocuje případné symbolické odkazy v nich a překládá je na reálné URL adresy jednotlivých cílových objektů – TemplateUtilities.ParseInternalLinks()
  3. Pro každý nalezený symbolický odkaz je známo ID cílového objektu a přes UrlProvider.GetUrl() se Umbraco snaží vyhodnotit cílové URL. Dělá to voláním metody GetUrl() na každém zaregistrovaném UrlProvideru, jedním z nichž je náš EpoUrlProvider.
  4. V EpoUrlProvider.GetUrl() se hned na začátku získává z ID entita reprezentující cílový content (jehož URL se má sestavit), volá se tedy ContentService.GetById(), které přes ContentRepository (transient) dojde až na RuntimeCacheProvider.GetById(), který když v cache objekt najde, chce vrátit jeho DeepClone().
  5. DeepClone() dělá kopii objektu a to tak, že nejprve vytvoří shallow-copy a následně klonuje jednotlivé referencované objekty. V jednom z nich (ContentType) se tak dostane až na setter property AllowedTemplates. V něm (a všech obdobných properties na potomcích třídy TracksChangesEntityBase) je setter ošetřen tak, že při ukládání nové hodnoty porovná s hodnotou původní, a pokud je honota změněna, uloží do slovníku informaci, že property daného jména je Changed/Dirty (vše pomocí metody SetPropertyValueAndDetectChanges() a OnPropertyChanged():
    // class ContentType : TracksChangesEntityBase
            public IEnumerable<ITemplate> AllowedTemplates
            {
                get
                {
                    return this._allowedTemplates;
                }
                set
                {
                    base.SetPropertyValueAndDetectChanges<IEnumerable<ITemplate>>(delegate (IEnumerable<ITemplate> o) {
                        this._allowedTemplates = value;
                        return this._allowedTemplates;
                    }, this._allowedTemplates, AllowedTemplatesSelector);
                }
            }
    
    // TracksChangesEntityBase
            internal bool SetPropertyValueAndDetectChanges<T>(Func<T, T> setValue, T value, PropertyInfo propertySelector)
            {
                T local = value;
                T local2 = setValue(value);
                if (!object.Equals(local, local2))
                {
                    this.OnPropertyChanged(propertySelector);
                    return true;
                }
                return false;
            }
    
            protected virtual void OnPropertyChanged(PropertyInfo propertyInfo)
            {
                this._propertyChangedInfo.set_Item(propertyInfo.get_Name(), true);
                if (this.PropertyChanged != null)
                {
                    this.PropertyChanged(this, new PropertyChangedEventArgs(propertyInfo.get_Name()));
                }
            }
    

Onen Dictionary<>.Insert(), který je na vrcholu call-stacků je tedy ve skutečnosti in-linovaná podoba slovníkového indexeru _propertyChangedInfo[propertyInfo.Name] = true;

Víme, že Dictionary je thread-safe pouze pro čtení, ale co se nám to tam v tom Insertu() děje, když každý tracked-objekt vzniká jako clone a má vlastní slovník pro ukládání změněných properties?

Pro doplnění z diagnostiky:

  • System.__Canon je interní záležitost .NET frameworku, která se vyskytuje v určitých runtime situacích u generik,

Deeper Analysis

Zkusili jsme dále bádat, co přesně se v metodě Dictionary<>.Insert() děje, co by se mohlo zacyklit.  Zdrojový kód metody Insert() vypadá poměrně očekávaně, klasické tanečky kolem hash-tabulky. Vytahuje se GetHashCode(), hledá se volný bucket, umísťuje se hodnota, …

private void Insert(TKey key, TValue value, bool add) {
        
            if( key == null ) {
                ThrowHelper.ThrowArgumentNullException(ExceptionArgument.key);
            }
 
            if (buckets == null) Initialize(0);
            int hashCode = comparer.GetHashCode(key) & 0x7FFFFFFF;
            int targetBucket = hashCode % buckets.Length;
 
#if FEATURE_RANDOMIZED_STRING_HASHING
            int collisionCount = 0;
#endif
 
            for (int i = buckets[targetBucket]; i >= 0; i = entries[i].next) {
                if (entries[i].hashCode == hashCode && comparer.Equals(entries[i].key, key)) {
                    if (add) { 
                        ThrowHelper.ThrowArgumentException(ExceptionResource.Argument_AddingDuplicate);
                    }
                    entries[i].value = value;
                    version++;
                    return;
                } 
 
#if FEATURE_RANDOMIZED_STRING_HASHING
                collisionCount++;
#endif
            }
            int index;
            if (freeCount > 0) {
                index = freeList;
                freeList = entries[index].next;
                freeCount--;
            }
            else {
                if (count == entries.Length)
                {
                    Resize();
                    targetBucket = hashCode % buckets.Length;
                }
                index = count;
                count++;
            }
 
            entries[index].hashCode = hashCode;
            entries[index].next = buckets[targetBucket];
            entries[index].key = key;
            entries[index].value = value;
            buckets[targetBucket] = index;
            version++;
 
#if FEATURE_RANDOMIZED_STRING_HASHING
            if(collisionCount > HashHelpers.HashCollisionThreshold && HashHelpers.IsWellKnownEqualityComparer(comparer)) 
            {
                comparer = (IEqualityComparer<TKey>) HashHelpers.GetRandomizedEqualityComparer(comparer);
                Resize(entries.Length, true);
            }
#endif
 
        }

Vydali jsme se cestou pokusu o zjištění, kde přesně se v metodě Insert() nacházíme (což bylo asi nadbytečné, jak se ukázalo později, navíc v metodě je jediný cyklus, takže se celkem nabízí, nicméně nám to pomohlo nasměrovat další síly k cíli).

Ve WinDbg jsme si nechali vypsat pomocí !ClrStack zásobník jednoho z postižených threadů (všechny vypadaly stejně plus/mínus pár instrukcí dopředu/dozadu uvnitř metody Insert()):

0:041> !ClrStack
OS Thread Id: 0xbe0 (41)
        Child SP               IP Call Site
000000001206bb70 000007fef7371fc0 System.Collections.Generic.Dictionary`2[[System.__Canon, mscorlib],[System.Boolean, mscorlib]].Insert(System.__Canon, Boolean, Boolean)
000000001206bc00 000007fe999e025e Umbraco.Core.Models.EntityBase.TracksChangesEntityBase.OnPropertyChanged(System.Reflection.PropertyInfo)
000000001206bc50 000007fe999e92bc Umbraco.Core.Models.EntityBase.TracksChangesEntityBase.SetPropertyValueAndDetectChanges[[System.__Canon, mscorlib]](System.Func`2<System.__Canon,System.__Canon>, System.__Canon, System.Reflection.PropertyInfo)
000000001206bc90 000007fe99b611c0 Umbraco.Core.Models.ContentType.set_AllowedTemplates(System.Collections.Generic.IEnumerable`1<Umbraco.Core.Models.ITemplate>)
000000001206bf20 000007fef85ba7f3 [DebuggerU2MCatchHandlerFrame: 000000001206bf20] 
000000001206c238 000007fef85ba7f3 [HelperMethodFrame_PROTECTOBJ: 000000001206c238] System.RuntimeMethodHandle.InvokeMethod(System.Object, System.Object[], System.Signature, Boolean)
000000001206c3b0 000007fef72b3b4c System.Reflection.RuntimeMethodInfo.UnsafeInvokeInternal(System.Object, System.Object[], System.Object[])
000000001206c420 000007fef72b1273 System.Reflection.RuntimeMethodInfo.Invoke(System.Object, System.Reflection.BindingFlags, System.Reflection.Binder, System.Object[], System.Globalization.CultureInfo)
000000001206c4a0 000007fef73782cc System.Reflection.RuntimePropertyInfo.SetValue(System.Object, System.Object, System.Object[])
000000001206c4f0 000007fe99b6222d Umbraco.Core.Models.DeepCloneHelper.DeepCloneRefProperties(Umbraco.Core.Models.IDeepCloneable, Umbraco.Core.Models.IDeepCloneable)
000000001206c5a0 000007fe99b6256d Umbraco.Core.Models.ContentTypeCompositionBase.DeepClone()
000000001206c5f0 000007fe999eeb84 Umbraco.Core.Models.ContentTypeCompositionBase.<DeepClone>b__2f(Umbraco.Core.Models.IContentTypeComposition)
000000001206c620 000007fef5972134 System.Linq.Enumerable+WhereSelectListIterator`2[[System.__Canon, mscorlib],[System.__Canon, mscorlib]].MoveNext()
000000001206c680 000007fef72e55b8 System.Collections.Generic.List`1[[System.__Canon, mscorlib]]..ctor(System.Collections.Generic.IEnumerable`1<System.__Canon>)
000000001206c6f0 000007fef5975180 System.Linq.Enumerable.ToList[[System.__Canon, mscorlib]](System.Collections.Generic.IEnumerable`1<System.__Canon>)
000000001206c730 000007fe99b626eb Umbraco.Core.Models.ContentTypeCompositionBase.DeepClone()
000000001206c780 000007fe999cefaa Umbraco.Core.Persistence.Caching.RuntimeCacheProvider.GetById(System.Type, System.Guid)
000000001206c7e0 000007fe999d00fb Umbraco.Core.Persistence.Repositories.RepositoryBase`2[[System.Int32, mscorlib],[System.__Canon, mscorlib]].TryGetFromCache(Int32)
000000001206c880 000007fe999cfe5c Umbraco.Core.Persistence.Repositories.RepositoryBase`2[[System.Int32, mscorlib],[System.__Canon, mscorlib]].Get(Int32)
000000001206c900 000007fe999d24dd Umbraco.Core.Persistence.Repositories.ContentRepository.CreateContentFromDto(Umbraco.Core.Models.Rdbms.DocumentDto, System.Guid)
000000001206c9d0 000007fe999d0a10 Umbraco.Core.Persistence.Repositories.ContentRepository.PerformGet(Int32)
000000001206ca60 000007fe999cfe9b Umbraco.Core.Persistence.Repositories.RepositoryBase`2[[System.Int32, mscorlib],[System.__Canon, mscorlib]].Get(Int32)
000000001206cae0 000007fe999c6069 Umbraco.Core.Services.ContentService.GetById(Int32)
000000001206cb40 000007fe99b88228 Havit.XyzPortal.Services.ContentManagement.EpoUrlProvider.GetUrl(Umbraco.Core.ApplicationContext, Int32, System.Uri, Umbraco.Web.Routing.UrlProviderMode)
000000001206cba0 000007fe99b86452 Umbraco.Web.Routing.UrlProvider+<>c__DisplayClass3.<GetUrl>b__0(Umbraco.Web.Routing.IUrlProvider)
000000001206cbe0 000007fef5972012 System.Linq.Enumerable+WhereSelectArrayIterator`2[[System.__Canon, mscorlib],[System.__Canon, mscorlib]].MoveNext()
000000001206cc20 000007fef5964e47 System.Linq.Enumerable.FirstOrDefault[[System.__Canon, mscorlib]](System.Collections.Generic.IEnumerable`1<System.__Canon>, System.Func`2<System.__Canon,Boolean>)
000000001206cc80 000007fe99b8684c Umbraco.Web.Routing.UrlProvider.GetUrl(Int32, System.Uri, Umbraco.Web.Routing.UrlProviderMode)
000000001206ccd0 000007fe99b7c580 Umbraco.Web.Templates.TemplateUtilities.ParseInternalLinks(System.String)
000000001206cd60 000007fe99d1e99e Havit.XyzPortal.UmbracoCMS.UmContentApiController.TraverseResourceDictionary(System.Collections.Generic.List`1<Havit.XyzPortal.Services.Resources.DataObjects.ResourceDictionaryDTO>, Umbraco.Core.Models.IContent, Boolean)
000000001206ce20 000007fe99d1e74d Havit.XyzPortal.UmbracoCMS.UmContentApiController.TraverseResourceDictionary(System.Collections.Generic.List`1<Havit.XyzPortal.Services.Resources.DataObjects.ResourceDictionaryDTO>, Umbraco.Core.Models.IContent, Boolean)
000000001206cee0 000007fe99d1e74d Havit.XyzPortal.UmbracoCMS.UmContentApiController.TraverseResourceDictionary(System.Collections.Generic.List`1<Havit.XyzPortal.Services.Resources.DataObjects.ResourceDictionaryDTO>, Umbraco.Core.Models.IContent, Boolean)
000000001206cfa0 000007fe99d1b003 Havit.XyzPortal.UmbracoCMS.UmContentApiController.Resources(System.Nullable`1<Boolean>)
000000001206d000 000007fe99d1aed1 Havit.XyzPortal.UmbracoCMS.UmContentApiController.Resources()
000000001206d040 000007fe99e1d25f DynamicClass.lambda_method(System.Runtime.CompilerServices.Closure, System.Object, System.Object[])
000000001206d070 000007fe999c6555 System.Web.Http.Controllers.ReflectedHttpActionDescriptor+ActionExecutor+<>c__DisplayClass13.<GetExecutor>b__c(System.Object, System.Object[])
000000001206d0b0 000007fe999c663f System.Web.Http.Controllers.ReflectedHttpActionDescriptor+ActionExecutor.Execute(System.Object, System.Object[])
000000001206d0e0 000007fe999c7ec8 System.Threading.Tasks.TaskHelpers.RunSynchronously[[System.__Canon, mscorlib]](System.Func`1<System.Threading.Tasks.Task`1<System.__Canon>>, System.Threading.CancellationToken)
000000001206d130 000007fe999c7c19 System.Web.Http.Controllers.ApiControllerActionInvoker+<>c__DisplayClass3.<InvokeActionAsync>b__0()
000000001206d180 000007fe999c7ec8 System.Threading.Tasks.TaskHelpers.RunSynchronously[[System.__Canon, mscorlib]](System.Func`1<System.Threading.Tasks.Task`1<System.__Canon>>, System.Threading.CancellationToken)
000000001206d1d0 000007fe999c8188 System.Web.Http.Controllers.ApiControllerActionInvoker.InvokeActionAsync(System.Web.Http.Controllers.HttpActionContext, System.Threading.CancellationToken)
000000001206d220 000007fe999c82a3 System.Web.Http.ApiController+<>c__DisplayClass3.<ExecuteAsync>b__2()
000000001206d250 000007fe999c84c5 System.Web.Http.ApiController+<>c__DisplayClass3.<ExecuteAsync>b__1()
000000001206d2a0 000007fe999c84ff System.Threading.Tasks.TaskHelpersExtensions+<>c__DisplayClass32`1[[System.__Canon, mscorlib]].<Then>b__31(System.Threading.Tasks.Task)
000000001206d2d0 000007fe999c88a4 System.Threading.Tasks.TaskHelpersExtensions.ThenImpl[[System.__Canon, mscorlib],[System.__Canon, mscorlib]](System.__Canon, System.Func`2<System.__Canon,System.Threading.Tasks.Task`1<System.__Canon>>, System.Threading.CancellationToken, Boolean)
000000001206d340 000007fe999c7614 System.Web.Http.ApiController+<>c__DisplayClass3.<ExecuteAsync>b__0()
000000001206d3a0 000007fe999c05df System.Web.Http.ApiController.ExecuteAsync(System.Web.Http.Controllers.HttpControllerContext, System.Threading.CancellationToken)
000000001206d410 000007fe999bb3a6 System.Web.Http.Dispatcher.HttpControllerDispatcher.SendAsync(System.Net.Http.HttpRequestMessage, System.Threading.CancellationToken)
000000001206d4a0 000007fefb2ee33f System.Net.Http.HttpMessageInvoker.SendAsync(System.Net.Http.HttpRequestMessage, System.Threading.CancellationToken)
000000001206d4f0 000007fe999bbd55 System.Web.Http.Dispatcher.HttpRoutingDispatcher.SendAsync(System.Net.Http.HttpRequestMessage, System.Threading.CancellationToken)
000000001206d550 000007fe999be00f System.Web.Http.HttpServer.SendAsync(System.Net.Http.HttpRequestMessage, System.Threading.CancellationToken)
000000001206d5a0 000007fefb2ee33f System.Net.Http.HttpMessageInvoker.SendAsync(System.Net.Http.HttpRequestMessage, System.Threading.CancellationToken)
000000001206d5f0 000007fe999bb84f System.Web.Http.WebHost.HttpControllerHandler.BeginProcessRequest(System.Web.HttpContextBase, System.AsyncCallback, System.Object)
000000001206d670 000007fee9865ca2 System.Web.HttpApplication+CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
000000001206d750 000007fee982d110 System.Web.HttpApplication.ExecuteStep(IExecutionStep, Boolean ByRef)
000000001206d7f0 000007fee984a78a System.Web.HttpApplication+PipelineStepManager.ResumeSteps(System.Exception)
000000001206d940 000007fee982d2a3 System.Web.HttpApplication.BeginProcessRequestNotification(System.Web.HttpContext, System.AsyncCallback)
000000001206d990 000007fee98271de System.Web.HttpRuntime.ProcessRequestNotificationPrivate(System.Web.Hosting.IIS7WorkerRequest, System.Web.HttpContext)
000000001206da30 000007fee9830161 System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(IntPtr, IntPtr, IntPtr, Int32)
000000001206dc40 000007fee982fb92 System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(IntPtr, IntPtr, IntPtr, Int32)
000000001206dc90 000007fee9f86ec1 DomainNeutralILStubClass.IL_STUB_ReversePInvoke(Int64, Int64, Int64, Int32)
000000001206e478 000007fef861b42e [InlinedCallFrame: 000000001206e478] System.Web.Hosting.UnsafeIISMethods.MgdIndicateCompletion(IntPtr, System.Web.RequestNotificationStatus ByRef)
000000001206e478 000007fee98d919b [InlinedCallFrame: 000000001206e478] System.Web.Hosting.UnsafeIISMethods.MgdIndicateCompletion(IntPtr, System.Web.RequestNotificationStatus ByRef)
000000001206e450 000007fee98d919b DomainNeutralILStubClass.IL_STUB_PInvoke(IntPtr, System.Web.RequestNotificationStatus ByRef)
000000001206e520 000007fee983034f System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(IntPtr, IntPtr, IntPtr, Int32)
000000001206e730 000007fee982fb92 System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(IntPtr, IntPtr, IntPtr, Int32)
000000001206e780 000007fee9f86ec1 DomainNeutralILStubClass.IL_STUB_ReversePInvoke(Int64, Int64, Int64, Int32)
000000001206e978 000007fef861b683 [ContextTransitionFrame: 000000001206e978] 

…a protože nemáme k dispozici převod offsetu na řádky zdrojového kódu mscorlib.dll, vydali jsme se přes !U /d <addr> na disassembly aktuálních instrukcí:

0:041> !U /d 000007fef7371fc0 
preJIT generated code
System.Collections.Generic.Dictionary`2[[System.__Canon, mscorlib],[System.Boolean, mscorlib]].Insert(System.__Canon, Boolean, Boolean)
Begin 000007fef7371dd0, size 29a. Cold region begin 000007fef80c24e4, size 173
Hot region:
000007fe`f7371dd0 53              push    rbx
000007fe`f7371dd1 55              push    rbp
000007fe`f7371dd2 56              push    rsi
000007fe`f7371dd3 57              push    rdi
000007fe`f7371dd4 4154            push    r12
000007fe`f7371dd6 4155            push    r13
000007fe`f7371dd8 4156            push    r14
000007fe`f7371dda 4157            push    r15
000007fe`f7371ddc 4883ec48        sub     rsp,48h
000007fe`f7371de0 410fb6c1        movzx   eax,r9b
000007fe`f7371de4 88442428        mov     byte ptr [rsp+28h],al
000007fe`f7371de8 450fb6e8        movzx   r13d,r8b
000007fe`f7371dec 44886c2429      mov     byte ptr [rsp+29h],r13b
000007fe`f7371df1 4c8be2          mov     r12,rdx
000007fe`f7371df4 488bd9          mov     rbx,rcx
000007fe`f7371df7 48895c2420      mov     qword ptr [rsp+20h],rbx
000007fe`f7371dfc 4d85e4          test    r12,r12
000007fe`f7371dff 0f84e607d500    je      mscorlib_ni+0x12a25eb (000007fe`f80c25eb)
000007fe`f7371e05 488b4308        mov     rax,qword ptr [rbx+8]
000007fe`f7371e09 4885c0          test    rax,rax
000007fe`f7371e0c 0f8463010000    je      mscorlib_ni+0x551f75 (000007fe`f7371f75)
000007fe`f7371e12 488b7b18        mov     rdi,qword ptr [rbx+18h]
000007fe`f7371e16 488b03          mov     rax,qword ptr [rbx]
000007fe`f7371e19 488b4830        mov     rcx,qword ptr [rax+30h]
000007fe`f7371e1d 488b01          mov     rax,qword ptr [rcx]
000007fe`f7371e20 488b4018        mov     rax,qword ptr [rax+18h]
000007fe`f7371e24 4885c0          test    rax,rax
000007fe`f7371e27 750f            jne     mscorlib_ni+0x551e38 (000007fe`f7371e38)
000007fe`f7371e29 488d153a4c1100  lea     rdx,[mscorlib_ni+0x666a6a (000007fe`f7486a6a)]
000007fe`f7371e30 488b0b          mov     rcx,qword ptr [rbx]
000007fe`f7371e33 e82053eaff      call    mscorlib_ni+0x3f7158 (000007fe`f7217158) (mscorlib_ni)
000007fe`f7371e38 803f00          cmp     byte ptr [rdi],0
000007fe`f7371e3b 498bd4          mov     rdx,r12
000007fe`f7371e3e 488bcf          mov     rcx,rdi
000007fe`f7371e41 4c8bd8          mov     r11,rax
000007fe`f7371e44 ff10            call    qword ptr [rax]
000007fe`f7371e46 8be8            mov     ebp,eax
000007fe`f7371e48 81e5ffffff7f    and     ebp,7FFFFFFFh
000007fe`f7371e4e 4c8b4308        mov     r8,qword ptr [rbx+8]
000007fe`f7371e52 498b4808        mov     rcx,qword ptr [r8+8]
000007fe`f7371e56 81fd00000080    cmp     ebp,80000000h
000007fe`f7371e5c 7509            jne     mscorlib_ni+0x551e67 (000007fe`f7371e67)
000007fe`f7371e5e 83f9ff          cmp     ecx,0FFFFFFFFh
000007fe`f7371e61 0f843407d500    je      mscorlib_ni+0x12a259b (000007fe`f80c259b)
000007fe`f7371e67 8bc5            mov     eax,ebp
000007fe`f7371e69 99              cdq
000007fe`f7371e6a f7f9            idiv    eax,ecx
000007fe`f7371e6c 448bfa          mov     r15d,edx
000007fe`f7371e6f 4533f6          xor     r14d,r14d
000007fe`f7371e72 4963f7          movsxd  rsi,r15d
000007fe`f7371e75 483bf1          cmp     rsi,rcx
000007fe`f7371e78 0f831807d500    jae     mscorlib_ni+0x12a2596 (000007fe`f80c2596)
000007fe`f7371e7e 418b74b010      mov     esi,dword ptr [r8+rsi*4+10h]
000007fe`f7371e83 85f6            test    esi,esi
000007fe`f7371e85 0f8d15010000    jge     mscorlib_ni+0x551fa0 (000007fe`f7371fa0)
000007fe`f7371e8b 8b4344          mov     eax,dword ptr [rbx+44h]
000007fe`f7371e8e 85c0            test    eax,eax
000007fe`f7371e90 0f8fd506d500    jg      mscorlib_ni+0x12a256b (000007fe`f80c256b)
000007fe`f7371e96 8b5338          mov     edx,dword ptr [rbx+38h]
000007fe`f7371e99 488b4310        mov     rax,qword ptr [rbx+10h]
000007fe`f7371e9d 488b4808        mov     rcx,qword ptr [rax+8]
000007fe`f7371ea1 3bd1            cmp     edx,ecx
000007fe`f7371ea3 0f849e000000    je      mscorlib_ni+0x551f47 (000007fe`f7371f47)
000007fe`f7371ea9 8b7b38          mov     edi,dword ptr [rbx+38h]
000007fe`f7371eac 8d4701          lea     eax,[rdi+1]
000007fe`f7371eaf 894338          mov     dword ptr [rbx+38h],eax
000007fe`f7371eb2 488b4b10        mov     rcx,qword ptr [rbx+10h]
000007fe`f7371eb6 4863f7          movsxd  rsi,edi
000007fe`f7371eb9 488b4108        mov     rax,qword ptr [rcx+8]
000007fe`f7371ebd 483bf0          cmp     rsi,rax
000007fe`f7371ec0 0f83d006d500    jae     mscorlib_ni+0x12a2596 (000007fe`f80c2596)
000007fe`f7371ec6 488d0476        lea     rax,[rsi+rsi*2]
000007fe`f7371eca 488d4cc110      lea     rcx,[rcx+rax*8+10h]
000007fe`f7371ecf 896908          mov     dword ptr [rcx+8],ebp
000007fe`f7371ed2 488b5308        mov     rdx,qword ptr [rbx+8]
000007fe`f7371ed6 4963ef          movsxd  rbp,r15d
000007fe`f7371ed9 488b4208        mov     rax,qword ptr [rdx+8]
000007fe`f7371edd 483be8          cmp     rbp,rax
000007fe`f7371ee0 0f83b006d500    jae     mscorlib_ni+0x12a2596 (000007fe`f80c2596)
000007fe`f7371ee6 8b44aa10        mov     eax,dword ptr [rdx+rbp*4+10h]
000007fe`f7371eea 89410c          mov     dword ptr [rcx+0Ch],eax
000007fe`f7371eed 498bd4          mov     rdx,r12
000007fe`f7371ef0 e81351eaff      call    mscorlib_ni+0x3f7008 (000007fe`f7217008) (mscorlib_ni)
000007fe`f7371ef5 488b4b10        mov     rcx,qword ptr [rbx+10h]
000007fe`f7371ef9 488b4108        mov     rax,qword ptr [rcx+8]
000007fe`f7371efd 483bf0          cmp     rsi,rax
000007fe`f7371f00 0f839006d500    jae     mscorlib_ni+0x12a2596 (000007fe`f80c2596)
000007fe`f7371f06 488d0476        lea     rax,[rsi+rsi*2]
000007fe`f7371f0a 44886cc120      mov     byte ptr [rcx+rax*8+20h],r13b
000007fe`f7371f0f 488b4b08        mov     rcx,qword ptr [rbx+8]
000007fe`f7371f13 488b4108        mov     rax,qword ptr [rcx+8]
000007fe`f7371f17 483be8          cmp     rbp,rax
000007fe`f7371f1a 0f837606d500    jae     mscorlib_ni+0x12a2596 (000007fe`f80c2596)
000007fe`f7371f20 897ca910        mov     dword ptr [rcx+rbp*4+10h],edi
000007fe`f7371f24 8b433c          mov     eax,dword ptr [rbx+3Ch]
000007fe`f7371f27 ffc0            inc     eax
000007fe`f7371f29 89433c          mov     dword ptr [rbx+3Ch],eax
000007fe`f7371f2c 4183fe64        cmp     r14d,64h
000007fe`f7371f30 0f8fae05d500    jg      mscorlib_ni+0x12a24e4 (000007fe`f80c24e4)
000007fe`f7371f36 4883c448        add     rsp,48h
000007fe`f7371f3a 415f            pop     r15
000007fe`f7371f3c 415e            pop     r14
000007fe`f7371f3e 415d            pop     r13
000007fe`f7371f40 415c            pop     r12
000007fe`f7371f42 5f              pop     rdi
000007fe`f7371f43 5e              pop     rsi
000007fe`f7371f44 5d              pop     rbp
000007fe`f7371f45 5b              pop     rbx
000007fe`f7371f46 c3              ret
000007fe`f7371f47 488bcb          mov     rcx,rbx
000007fe`f7371f4a e8d1010000      call    mscorlib_ni+0x552120 (000007fe`f7372120) (System.Collections.Generic.Dictionary`2[[System.__Canon, mscorlib],[System.Boolean, mscorlib]].Resize(), mdToken: 00000000060021a7)
000007fe`f7371f4f 488b4308        mov     rax,qword ptr [rbx+8]
000007fe`f7371f53 488b4808        mov     rcx,qword ptr [rax+8]
000007fe`f7371f57 81fd00000080    cmp     ebp,80000000h
000007fe`f7371f5d 7509            jne     mscorlib_ni+0x551f68 (000007fe`f7371f68)
000007fe`f7371f5f 83f9ff          cmp     ecx,0FFFFFFFFh
000007fe`f7371f62 0f843306d500    je      mscorlib_ni+0x12a259b (000007fe`f80c259b)
000007fe`f7371f68 8bc5            mov     eax,ebp
000007fe`f7371f6a 99              cdq
000007fe`f7371f6b f7f9            idiv    eax,ecx
000007fe`f7371f6d 448bfa          mov     r15d,edx
000007fe`f7371f70 e934ffffff      jmp     mscorlib_ni+0x551ea9 (000007fe`f7371ea9)
000007fe`f7371f75 33d2            xor     edx,edx
000007fe`f7371f77 488bcb          mov     rcx,rbx
000007fe`f7371f7a e8f1000000      call    mscorlib_ni+0x552070 (000007fe`f7372070) (System.Collections.Generic.Dictionary`2[[System.__Canon, mscorlib],[System.Boolean, mscorlib]].Initialize(Int32), mdToken: 00000000060021a4)
000007fe`f7371f7f e98efeffff      jmp     mscorlib_ni+0x551e12 (000007fe`f7371e12)
000007fe`f7371f84 488d0449        lea     rax,[rcx+rcx*2]
000007fe`f7371f88 8b74c21c        mov     esi,dword ptr [rdx+rax*8+1Ch]
000007fe`f7371f8c 85f6            test    esi,esi
000007fe`f7371f8e 0f8ccc000000    jl      mscorlib_ni+0x552060 (000007fe`f7372060)
000007fe`f7371f94 666666660f1f840000000000 nop word ptr [rax+rax]
000007fe`f7371fa0 488b4b10        mov     rcx,qword ptr [rbx+10h]
000007fe`f7371fa4 4863fe          movsxd  rdi,esi
000007fe`f7371fa7 488b4108        mov     rax,qword ptr [rcx+8]
000007fe`f7371fab 483bf8          cmp     rdi,rax
000007fe`f7371fae 0f83e205d500    jae     mscorlib_ni+0x12a2596 (000007fe`f80c2596)
000007fe`f7371fb4 488d147f        lea     rdx,[rdi+rdi*2]
000007fe`f7371fb8 8b44d118        mov     eax,dword ptr [rcx+rdx*8+18h]
000007fe`f7371fbc 3bc5            cmp     eax,ebp
000007fe`f7371fbe 7419            je      mscorlib_ni+0x551fd9 (000007fe`f7371fd9)
>>> 000007fe`f7371fc0 41ffc6          inc     r14d
000007fe`f7371fc3 488b5310        mov     rdx,qword ptr [rbx+10h]
000007fe`f7371fc7 4863ce          movsxd  rcx,esi
000007fe`f7371fca 488b4208        mov     rax,qword ptr [rdx+8]
000007fe`f7371fce 483bc8          cmp     rcx,rax
000007fe`f7371fd1 0f83bf05d500    jae     mscorlib_ni+0x12a2596 (000007fe`f80c2596)
000007fe`f7371fd7 ebab            jmp     mscorlib_ni+0x551f84 (000007fe`f7371f84)
000007fe`f7371fd9 4c8b6b18        mov     r13,qword ptr [rbx+18h]
000007fe`f7371fdd 488b44d110      mov     rax,qword ptr [rcx+rdx*8+10h]
000007fe`f7371fe2 4889442430      mov     qword ptr [rsp+30h],rax
000007fe`f7371fe7 488b03          mov     rax,qword ptr [rbx]
000007fe`f7371fea 488b4830        mov     rcx,qword ptr [rax+30h]
000007fe`f7371fee 488b01          mov     rax,qword ptr [rcx]
000007fe`f7371ff1 488b4020        mov     rax,qword ptr [rax+20h]
000007fe`f7371ff5 4885c0          test    rax,rax
000007fe`f7371ff8 750f            jne     mscorlib_ni+0x552009 (000007fe`f7372009)
000007fe`f7371ffa 488d15754a1100  lea     rdx,[mscorlib_ni+0x666a76 (000007fe`f7486a76)]
000007fe`f7372001 488b0b          mov     rcx,qword ptr [rbx]
000007fe`f7372004 e84f51eaff      call    mscorlib_ni+0x3f7158 (000007fe`f7217158) (mscorlib_ni)
000007fe`f7372009 41807d0000      cmp     byte ptr [r13],0
000007fe`f737200e 4d8bc4          mov     r8,r12
000007fe`f7372011 488b542430      mov     rdx,qword ptr [rsp+30h]
000007fe`f7372016 498bcd          mov     rcx,r13
000007fe`f7372019 4c8bd8          mov     r11,rax
000007fe`f737201c ff10            call    qword ptr [rax]
000007fe`f737201e 0fb6c8          movzx   ecx,al
000007fe`f7372021 85c9            test    ecx,ecx
000007fe`f7372023 749b            je      mscorlib_ni+0x551fc0 (000007fe`f7371fc0)
000007fe`f7372025 8a442428        mov     al,byte ptr [rsp+28h]
000007fe`f7372029 0fb6c0          movzx   eax,al
000007fe`f737202c 85c0            test    eax,eax
000007fe`f737202e 0f856c05d500    jne     mscorlib_ni+0x12a25a0 (000007fe`f80c25a0)
000007fe`f7372034 488b4b10        mov     rcx,qword ptr [rbx+10h]
000007fe`f7372038 488b4108        mov     rax,qword ptr [rcx+8]
000007fe`f737203c 483bf8          cmp     rdi,rax
000007fe`f737203f 0f835105d500    jae     mscorlib_ni+0x12a2596 (000007fe`f80c2596)
000007fe`f7372045 488d047f        lea     rax,[rdi+rdi*2]
000007fe`f7372049 8a542429        mov     dl,byte ptr [rsp+29h]
000007fe`f737204d 8854c120        mov     byte ptr [rcx+rax*8+20h],dl
000007fe`f7372051 8b433c          mov     eax,dword ptr [rbx+3Ch]
000007fe`f7372054 ffc0            inc     eax
000007fe`f7372056 89433c          mov     dword ptr [rbx+3Ch],eax
000007fe`f7372059 e9d8feffff      jmp     mscorlib_ni+0x551f36 (000007fe`f7371f36)
000007fe`f737205e 6690            xchg    ax,ax
000007fe`f7372060 448a6c2429      mov     r13b,byte ptr [rsp+29h]
000007fe`f7372065 e921feffff      jmp     mscorlib_ni+0x551e8b (000007fe`f7371e8b)
Cold region:
000007fe`f80c24e4 488d7b18        lea     rdi,[rbx+18h]
000007fe`f80c24e8 488b0f          mov     rcx,qword ptr [rdi]
000007fe`f80c24eb e8b098a6ff      call    mscorlib_ni+0xd0bda0 (000007fe`f7b2bda0) (System.Collections.HashHelpers.IsWellKnownEqualityComparer(System.Object), mdToken: 00000000060020f7)
000007fe`f80c24f0 0fb6c8          movzx   ecx,al
000007fe`f80c24f3 85c9            test    ecx,ecx
000007fe`f80c24f5 0f843bfa2aff    je      mscorlib_ni+0x551f36 (000007fe`f7371f36)
000007fe`f80c24fb 488b0f          mov     rcx,qword ptr [rdi]
000007fe`f80c24fe e81d99a6ff      call    mscorlib_ni+0xd0be20 (000007fe`f7b2be20) (System.Collections.HashHelpers.GetRandomizedEqualityComparer(System.Object), mdToken: 00000000060020f8)
000007fe`f80c2503 488bf0          mov     rsi,rax
000007fe`f80c2506 488b03          mov     rax,qword ptr [rbx]
000007fe`f80c2509 488b4830        mov     rcx,qword ptr [rax+30h]
000007fe`f80c250d 488b01          mov     rax,qword ptr [rcx]
000007fe`f80c2510 488b4028        mov     rax,qword ptr [rax+28h]
000007fe`f80c2514 4885c0          test    rax,rax
000007fe`f80c2517 750f            jne     mscorlib_ni+0x12a2528 (000007fe`f80c2528)
000007fe`f80c2519 488d15c04c3cff  lea     rdx,[mscorlib_ni+0x6671e0 (000007fe`f74871e0)]
000007fe`f80c2520 488b0b          mov     rcx,qword ptr [rbx]
000007fe`f80c2523 e8304c15ff      call    mscorlib_ni+0x3f7158 (000007fe`f7217158) (mscorlib_ni)
000007fe`f80c2528 488bd6          mov     rdx,rsi
000007fe`f80c252b 488bc8          mov     rcx,rax
000007fe`f80c252e e8354c15ff      call    mscorlib_ni+0x3f7168 (000007fe`f7217168) (mscorlib_ni)
000007fe`f80c2533 488bd0          mov     rdx,rax
000007fe`f80c2536 488bcf          mov     rcx,rdi
000007fe`f80c2539 e8ca4a15ff      call    mscorlib_ni+0x3f7008 (000007fe`f7217008) (mscorlib_ni)
000007fe`f80c253e 488b4310        mov     rax,qword ptr [rbx+10h]
000007fe`f80c2542 488b5008        mov     rdx,qword ptr [rax+8]
000007fe`f80c2546 41b001          mov     r8b,1
000007fe`f80c2549 488bcb          mov     rcx,rbx
000007fe`f80c254c 488d051dfc2aff  lea     rax,[mscorlib_ni+0x552170 (000007fe`f7372170)]
000007fe`f80c2553 4883c448        add     rsp,48h
000007fe`f80c2557 415f            pop     r15
000007fe`f80c2559 415e            pop     r14
000007fe`f80c255b 415d            pop     r13
000007fe`f80c255d 415c            pop     r12
000007fe`f80c255f 5f              pop     rdi
000007fe`f80c2560 5e              pop     rsi
000007fe`f80c2561 5d              pop     rbp
000007fe`f80c2562 5b              pop     rbx
000007fe`f80c2563 48ffe0          jmp     rax
000007fe`f80c2566 e9cbf92aff      jmp     mscorlib_ni+0x551f36 (000007fe`f7371f36)
000007fe`f80c256b 8b7b40          mov     edi,dword ptr [rbx+40h]
000007fe`f80c256e 488b5310        mov     rdx,qword ptr [rbx+10h]
000007fe`f80c2572 4863cf          movsxd  rcx,edi
000007fe`f80c2575 488b4208        mov     rax,qword ptr [rdx+8]
000007fe`f80c2579 483bc8          cmp     rcx,rax
000007fe`f80c257c 7318            jae     mscorlib_ni+0x12a2596 (000007fe`f80c2596)
000007fe`f80c257e 488d0449        lea     rax,[rcx+rcx*2]
000007fe`f80c2582 8b4cc21c        mov     ecx,dword ptr [rdx+rax*8+1Ch]
000007fe`f80c2586 894b40          mov     dword ptr [rbx+40h],ecx
000007fe`f80c2589 8b4344          mov     eax,dword ptr [rbx+44h]
000007fe`f80c258c ffc8            dec     eax
000007fe`f80c258e 894344          mov     dword ptr [rbx+44h],eax
000007fe`f80c2591 e91cf92aff      jmp     mscorlib_ni+0x551eb2 (000007fe`f7371eb2)
000007fe`f80c2596 e8d54a15ff      call    mscorlib_ni+0x3f7070 (000007fe`f7217070) (mscorlib_ni)
000007fe`f80c259b e8b04b15ff      call    mscorlib_ni+0x3f7150 (000007fe`f7217150) (mscorlib_ni)
000007fe`f80c25a0 b90e000000      mov     ecx,0Eh
000007fe`f80c25a5 e83e9915ff      call    mscorlib_ni+0x3fbee8 (000007fe`f721bee8) (System.ThrowHelper.GetResourceName(System.ExceptionResource), mdToken: 0000000006000261)
000007fe`f80c25aa 488bc8          mov     rcx,rax
000007fe`f80c25ad e8665f15ff      call    mscorlib_ni+0x3f8518 (000007fe`f7218518) (System.Environment.GetResourceFromDefault(System.String), mdToken: 0000000006000c8a)
000007fe`f80c25b2 488bd8          mov     rbx,rax
000007fe`f80c25b5 488d0ddcac44ff  lea     rcx,[mscorlib_ni+0x6ed298 (000007fe`f750d298)]
000007fe`f80c25bc e8574a15ff      call    mscorlib_ni+0x3f7018 (000007fe`f7217018) (mscorlib_ni)
000007fe`f80c25c1 488bf8          mov     rdi,rax
000007fe`f80c25c4 488bd3          mov     rdx,rbx
000007fe`f80c25c7 488bcf          mov     rcx,rdi
000007fe`f80c25ca e8518e1eff      call    mscorlib_ni+0x48b420 (000007fe`f72ab420) (System.Exception..ctor(System.String), mdToken: 000000000600001d)
000007fe`f80c25cf c7878c00000001151380 mov dword ptr [rdi+8Ch],80131501h
000007fe`f80c25d9 c7878c00000057000780 mov dword ptr [rdi+8Ch],80070057h
000007fe`f80c25e3 488bcf          mov     rcx,rdi
000007fe`f80c25e6 e8954a15ff      call    mscorlib_ni+0x3f7080 (000007fe`f7217080) (mscorlib_ni)
000007fe`f80c25eb b905000000      mov     ecx,5
000007fe`f80c25f0 e8e39815ff      call    mscorlib_ni+0x3fbed8 (000007fe`f721bed8) (System.ThrowHelper.GetArgumentName(System.ExceptionArgument), mdToken: 0000000006000260)
000007fe`f80c25f5 488bd8          mov     rbx,rax
000007fe`f80c25f8 488d0d01a144ff  lea     rcx,[mscorlib_ni+0x6ec700 (000007fe`f750c700)]
000007fe`f80c25ff e8144a15ff      call    mscorlib_ni+0x3f7018 (000007fe`f7217018) (mscorlib_ni)
000007fe`f80c2604 488bf8          mov     rdi,rax
000007fe`f80c2607 488d15f2e9d5fe  lea     rdx,[mscorlib_ni+0x1000 (000007fe`f6e21000)]
000007fe`f80c260e b9a8650070      mov     ecx,700065A8h
000007fe`f80c2613 e8604a15ff      call    mscorlib_ni+0x3f7078 (000007fe`f7217078) (mscorlib_ni)
000007fe`f80c2618 488bc8          mov     rcx,rax
000007fe`f80c261b e8f85e15ff      call    mscorlib_ni+0x3f8518 (000007fe`f7218518) (System.Environment.GetResourceFromDefault(System.String), mdToken: 0000000006000c8a)
000007fe`f80c2620 488bd0          mov     rdx,rax
000007fe`f80c2623 488bcf          mov     rcx,rdi
000007fe`f80c2626 e8b58d1eff      call    mscorlib_ni+0x48b3e0 (000007fe`f72ab3e0) (System.SystemException..ctor(System.String), mdToken: 0000000006000515)
000007fe`f80c262b 488d8f98000000  lea     rcx,[rdi+98h]
000007fe`f80c2632 488bd3          mov     rdx,rbx
000007fe`f80c2635 e8ce4915ff      call    mscorlib_ni+0x3f7008 (000007fe`f7217008) (mscorlib_ni)
000007fe`f80c263a c7878c00000057000780 mov dword ptr [rdi+8Ch],80070057h
000007fe`f80c2644 c7878c00000003400080 mov dword ptr [rdi+8Ch],80004003h
000007fe`f80c264e 488bcf          mov     rcx,rdi
000007fe`f80c2651 e82a4a15ff      call    mscorlib_ni+0x3f7080 (000007fe`f7217080) (mscorlib_ni)
000007fe`f80c2656 90              nop

Tohle už je trochu pocitové luštění, přeci-jenom čistý assembler je lepší psát, než interpretovat. Z instrukcí pro inkrementaci, porovnávání a skoky jsme však dospěli k závěru, že se nacházíme právě uvězněni uvnitř cyklu for v metodě Insert. Hypotéza je, že došlo k poškození spojového seznamu entries a ty nejspíš tvoří cyklus, jehož nekonečné procházení nás vězní.

Cause

No dobrá. Myslíme si, že víme, co se děje, ale proč?

Znovu procházíme odspoda zdrojové kódy metod, přes než call-stack prochází. Už tušíme, co chceme hledat (vícenásobný přístup na jeden slovník, který by však měl být pro každou instanci entity samostatný) a dostáváme se do kritického místa:

// class Entity : TracksChangesEntityBase
        private IDictionary<string, bool> _propertyChangedInfo = new Dictionary<string, bool>();

        public virtual object DeepClone()
        {
            Entity output = (Entity) base.MemberwiseClone();
            DeepCloneHelper.DeepCloneRefProperties(this, output);
            output.ResetDirtyProperties(false);
            return output;
        }

// TracksChangesEntityBase
        public virtual void ResetDirtyProperties(bool rememberPreviouslyChangedProperties)
        {
            if (rememberPreviouslyChangedProperties)
            {
                this._lastPropertyChangedInfo = this._propertyChangedInfo.ToDictionary<KeyValuePair<string, bool>, string, bool>(v => v.Key, v => v.Value);
            }
            this._propertyChangedInfo = new Dictionary<string, bool>();
        }

Ukazuje se, že slovník změněných properties _propertyChangedInfo se zakládá nový pouze při vytvoření nové instance entity a při volání ResetDirtyProperties(). Metoda DeepClone() volaná po vyzvednutí originálu z cache však nejprve vytvoří MemberwiseClone() shallow-kopii objektu, která referencuje v _propertyChangedInfo stále původní Dictionary<>, pak začne klonovat referencované properties (avšak pod trackingem původního dosud neřešeného slovníku!!!) a až potom se provede ResetDirtyProperties(), který způsobí vytvoření nové instance slovníku pro _propertyChangedInfo.

Pokud se nám tedy sejde více threadů ve správný okamžik, dojde k simultálnímu zápisu do jednoho slovníku z více threadů, který není pro tuto operaci thread-safe. V našem případě tím dojde k nadrbání vnitřní struktury hash-tabulky (nejspíš k cyklu entries) a výsledkem bylo uvíznutí threadů v nekonečných cyklech for.

Závěr

…jdeme nahlásit bug v UmbracoCMS.

Jako work-around budeme muset zatím přidat nějaké vlastní zámky do míst, která vedou na problematický DeepClone() a zajistí pro začátek vzájemnou výlučnost takových volání.

Update

Koukám, že už je to v Umbraco reportováno a včera opraveno.

Napsat komentář