Stack Overflows are hard errors to Google

Sometimes you find yourself investigating errors which are made more difficult to solve by the sheer weight of hits for a term out on the internet. Top of my list of things that are a pain to Google, is any sort of Stack Overflow exception. You can guess why, right? 😉 Having gone throught that pain recently, here's some notes on an issue I helped my colleagues diagnose recently which fell straight into that trap...

What was the issue we saw? url copied!

A while after a deployment, testers reported that some content editing operations caused the server in question to hang. Trying to lock an item for edit, change its Presentation Details or do some other operations which modified the item seemed to cause the problem. It happened on some items, but not others. Testers would see error dialogs poping up in Content Editor after a wait:

The server logs included crashes on the authoring server at about the same time. To confuse matters, it was only repeatable on the QA and UAT servers – developers could not reproduce it on their dev boxes. So initially, this was a bit of a confusing problem for the developers involved.

Looking at the server event logs, these hangs eventually resolved into crashes caused running out of Stack space with a InsufficientExecutionStackException. Which is sort of a Stack Overflow... When we managed to see the actuall IIS error, it looked like this:

The stack traces varied a bit depending on how the error was triggered, but they were all huge (unsurprisingly). One example, from changing presentation details looked like this:

[InsufficientExecutionStackException: Insufficient stack to continue executing the program safely. This can happen from having too many functions on the call stack or function on the stack using too much stack space.]
   System.Runtime.CompilerServices.RuntimeHelpers.EnsureSufficientExecutionStack() +0
   System.Web.UI.Control.FindControl(String id, Int32 pathOffset) +24
   Sitecore.Web.WebUtil.FindControl(Control parent, String name) +90
   Sitecore.Web.UI.HtmlControls.TreePicker.GetDisplayValue() +133
   Sitecore.Web.UI.HtmlControls.ComboboxBase.set_Value(String value) +157
   Sitecore.Web.UI.HtmlControls.TreePicker.OnDataContextChanged(DataContext dataContext) +328
   Sitecore.Web.UI.HtmlControls.Control.HandleMessage(Message message) +971
   Sitecore.Shell.Framework.Commands.MessageCommand.DispatchMessage(Control control) +79
   Sitecore.Shell.Framework.Commands.MessageCommand.DispatchMessage(Control control) +171
   Sitecore.Shell.Framework.Commands.MessageCommand.DispatchMessage(Control control) +171
   Sitecore.Shell.Framework.Commands.MessageCommand.DispatchMessage(Control control) +171
   Sitecore.Shell.Framework.Commands.MessageCommand.DispatchMessage(Control control) +171
   Sitecore.Shell.Framework.Commands.MessageCommand.DispatchMessage(Control control) +171
   Sitecore.Shell.Framework.Commands.MessageCommand.DispatchMessage(Control control) +171
   Sitecore.Shell.Framework.Commands.MessageCommand.DispatchMessage(Control control) +171
   Sitecore.Shell.Framework.Commands.MessageCommand.DispatchMessage(Control control) +171
   Sitecore.Shell.Framework.Commands.MessageCommand.DispatchMessage(Control control) +171
   Sitecore.Shell.Framework.Commands.MessageCommand.Execute(CommandContext context) +181
   Sitecore.Web.UI.Sheer.ClientPage.SendMessage(Message message) +102
   Sitecore.Web.UI.HtmlControls.DataContext.OnChanged() +294
   Sitecore.Web.UI.HtmlControls.DataContext.ItemSavedNotification(Object sender, ItemSavedEventArgs args) +280
   Sitecore.Data.Events.ItemSavedDelegate.Invoke(Object sender, ItemSavedEventArgs args) +0
   Sitecore.Events.Event.RaiseItemSaved(Object sender, ItemSavedEventArgs args) +226
   System.EventHandler`1.Invoke(Object sender, TEventArgs e) +0
   Sitecore.Data.Engines.EngineCommand`2.RaiseEvent(EventHandler`1 handlers, Func`2 argsCreator) +129
   Sitecore.Data.Engines.EngineCommand`2.Execute() +263

   Sitecore.Data.Engines.DataEngine.SaveItem(Item item) +280
   Sitecore.Data.Managers.ItemProvider.SaveItem(Item item) +291
   Sitecore.Data.Managers.PipelineBasedItemProvider.ExecuteAndReturnResult(String pipelineName, String pipelineDomain, Func`1 pipelineArgsCreator, Func`1 fallbackResult) +165
   Sitecore.Data.Managers.PipelineBasedItemProvider.SaveItem(Item item) +230
   Sitecore.Data.Items.ItemEditing.AcceptChanges(Boolean updateStatistics, Boolean silent) +229
   Sitecore.Data.Items.ItemEditing.EndEdit(Boolean updateStatistics, Boolean silent) +16
   Sitecore.Data.Managers.ItemProvider.UpdateRevisions(Item item, Boolean includeAllLanguages) +577

--
-- Previous seven lines repeated hundreds of times --
--

[TargetInvocationException: Exception has been thrown by the target of an invocation.]
   System.RuntimeMethodHandle.InvokeMethod(Object target, Object[] arguments, Signature sig, Boolean constructor) +0
   System.Reflection.RuntimeMethodInfo.UnsafeInvokeInternal(Object obj, Object[] parameters, Object[] arguments) +76
   System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture) +211
   System.Reflection.MethodBase.Invoke(Object obj, Object[] parameters) +35
   Sitecore.Nexus.Pipelines.NexusPipelineApi.Resume(PipelineArgs args, Pipeline pipeline) +398
   Sitecore.Web.UI.Sheer.ClientPage.ResumePipeline() +285
   Sitecore.Web.UI.Sheer.ClientPage.OnPreRender(EventArgs e) +547
   Sitecore.Shell.Applications.ContentManager.ContentEditorPage.OnPreRender(EventArgs e) +25
   System.Web.UI.Control.PreRenderRecursiveInternal() +113
   System.Web.UI.Page.ProcessRequestMain(Boolean includeStagesBeforeAsyncPoint, Boolean includeStagesAfterAsyncPoint) +4297

					

What was the underlying issue? url copied!

The stack trace was interesting for two reasons:

• Firstly: It contained no references to any of the custom code deployed to this instance of Sitecore.
• Secondly: The bit that is repeated a lot is all to do with the process of saving an item.

That lead to us thinking about why the save operation might get into a loop.

The obvious answer here was custom event handlers. If an event was triggering after Sitecore saved an item, causing it to be saved again and if Sitecore was running custom code on a separate thread, that could cause this sort of issue. So we tried disabling all of the custom events wired up in patches to the default Sitecore config.

That didn't work.

So then we looked down a rabbit hole relating to search. The project was using Coveo, with some customisations to ensure that if a Data Source item for a page got saved, the page itself was re-indexed. The re-index was triggered by changing the "last updated" time on the page item. So we tried disabling search.

That didn't solve the problem either.

Finally, after a lot of hair-pulling, we noticed that a custom Rule had been configured inside the Sitecore UI that was running in the On-Saved event. This rule was related to some SEO requirements to ensure that page Name and Display Name fields used "correct" values. Looking at the rule, an issue popped out:

The last thing in the rule is a custom "save the changes" action, and the rule is running in the "Item Saved" event.

The "shooting yourself in the foot" alarm went off at this point – and removing the "save the changes" action caused the hang/crash issues to go away.

Fixing the issue url copied!

Having found the underlying problem, the fix was pretty simple. And it's an important rule to remember:

Don't write changes to an item in a rule running on the "Item Saved" event – because it can cause the event to run again, leading to a loop. (Yes, it is possible to write to an item without triggering events – but I'd argue it's better to put your code into the correct event than to hack around this issue)

If you need to modify the state of an item when it is saved, use the "Item Saving" event instead. That allows you to change the state, but rely on Sitecore to do the save operation for you afterwards. And it won't trigger any further events at that point.

Note that out of the box, there isn't a Rules Engine event for "Item Saving". But you can plumb one in yourself easily enough – Have a Google for blogs on the subject of triggering rules, or just point your favourite decompiler at Sitecore's code for running "Item Saved" to see how.

↑ Back to top