umbraco / Umbraco-CMS

Umbraco is a free and open source .NET content management system helping you deliver delightful digital experiences.
https://umbraco.com
MIT License
4.42k stars 2.66k forks source link

Confusing exception message during deploy #15569

Open tormnator opened 8 months ago

tormnator commented 8 months ago

Which Umbraco version are you using? (Please write the exact version, example: 10.1.0)

12.3.6

Bug summary

This issue shows up in Umbraco Cloud, via Umbraco Deploy, but the relevant source code is in Umbraco CMS so I'm posting here.

During a deploy from my local Umbraco Deploy environment to my Development env, I end up with a bad looking error in the Cloud dashboard stating that the deploy failed. The shown error is "failed to get child with id=2458". The error makes it look like there's a problem with the deployment data, and it makes it look like the deployment failed. Neither is actually true. It turns out the problem is related to the NuCache not being able to refresh itself after the deploy has succeeded. Also, the error uses an int node id which makes it hard to search for and identify which node is being referenced (e.g. you can't search the .uda files for int node id's).

To help out I think a few changes/additions to the relevant source code could be made to 1) show the Guid of the node, 2) the type of node (content, media, content type, media type, etc.), and 3) during what part of the deploy process the error occurred.

Specifics

The exception is thrown in the ContentStore.GetRequiredLinkedNode method. This method doesn't have much helpful information to provide, but the calling ContentStore.ClearBranchLocked method has a reference to the parent ContentNode with more information. A try/catch wrapper here could add a message like "Unable to get reference to child content of type {content.ContentType.Name}. The parent node's id is {content.Uid}, path is {content.Path}." (pseudocode).

If we go further up the call stack, we see that the PublishedSnapshotService.RefreshMediaTypesLocked method is called. In this method we could add another try/catch wrapper with more useful information, e.g. "An exception was thrown while refreshing media types in the NuCache" (or something similar, I'm not sure if one can say NuCache here, or if this method is too general).

Finally, closer to the top of the exception call stack, we see that DistributedCacheExtensions.RefreshContentTypeCache() is called. This might be a good place to add more accurate information about where/when in the deployment process the error occurred.

Here's the entire error message and exception call stack as seen when digging into the error details (I have annotated the call stack a bit with line number info):

{
  "Date": "2024-01-10T18:55:15.0468858+00:00",
  "Message": "failed to get child with id=2458",
  "Ex": {
    "ClassName": "Umbraco.Cms.Core.Exceptions.PanicException",
    "Message": "failed to get child with id=2458",
    "Data": null,
    "InnerException": null,
    "HelpURL": null,
    "StackTraceString": "
   at Umbraco.Cms.Infrastructure.PublishedCache.ContentStore.GetRequiredLinkedNode(Int32 id, String description, Nullable`1 gen)\r\n // Line 1347
   at Umbraco.Cms.Infrastructure.PublishedCache.ContentStore.ClearBranchLocked(ContentNode content)\r\n // Line 1322
   at Umbraco.Cms.Infrastructure.PublishedCache.ContentStore.ClearBranchLocked(ContentNode content)\r\n // Line 1322
   at Umbraco.Cms.Infrastructure.PublishedCache.ContentStore.ClearBranchLocked(ContentNode content)\r\n // Line 1322
   at Umbraco.Cms.Infrastructure.PublishedCache.ContentStore.ClearBranchLocked(ContentNode content)\r\n // Line 1322
   at Umbraco.Cms.Infrastructure.PublishedCache.ContentStore.ClearBranchLocked(Int32 id)\r\n // Line 1298
   at Umbraco.Cms.Infrastructure.PublishedCache.ContentStore.UpdateContentTypesLocked(IReadOnlyCollection`1 removedIds, IReadOnlyCollection`1 refreshedTypes, IReadOnlyCollection`1 kits)\r\n // Line 719
   at Umbraco.Cms.Infrastructure.PublishedCache.PublishedSnapshotService.RefreshMediaTypesLocked(List`1 removedIds, List`1 refreshedIds, List`1 otherIds, List`1 newIds)\r\n // Line 1202
   at Umbraco.Cms.Infrastructure.PublishedCache.PublishedSnapshotService.Notify[T](ContentStore store, JsonPayload[] payloads, Action`4 action)\r\n // Line 1074
   at Umbraco.Cms.Infrastructure.PublishedCache.PublishedSnapshotService.Notify(JsonPayload[] payloads)\r\n // Line 198
   at Umbraco.Cms.Core.Cache.ContentTypeCacheRefresher.<>c__DisplayClass11_0.<Refresh>b__6()\r\n
   at Umbraco.Extensions.PublishedModelFactoryExtensions.WithSafeLiveFactoryReset(IPublishedModelFactory factory, Action action)\r\n
   at Umbraco.Cms.Core.Cache.ContentTypeCacheRefresher.Refresh(JsonPayload[] payloads)\r\n
   at Umbraco.Cms.Infrastructure.Sync.ServerMessengerBase.DeliverLocal[TPayload](ICacheRefresher refresher, TPayload[] payload)\r\n
   at Umbraco.Cms.Infrastructure.Sync.ServerMessengerBase.Deliver[TPayload](ICacheRefresher refresher, TPayload[] payload)\r\n
   at Umbraco.Cms.Infrastructure.Sync.ServerMessengerBase.QueueRefresh[TPayload](ICacheRefresher refresher, TPayload[] payload)\r\n
   at Umbraco.Cms.Core.Cache.DistributedCache.RefreshByPayload[TPayload](Guid refresherGuid, TPayload[] payload)\r\n
   at Umbraco.Cms.Core.Cache.DistributedCache.RefreshByPayload[TPayload](Guid refresherGuid, IEnumerable`1 payloads)\r\n
   at Umbraco.Extensions.DistributedCacheExtensions.RefreshContentTypeCache(DistributedCache dc, IEnumerable`1 changes)\r\n
   at Umbraco.Cms.Core.Cache.MediaTypeChangedDistributedCacheNotificationHandler.Handle(IEnumerable`1 entities)\r\n
   at Umbraco.Cms.Core.Cache.DistributedCacheNotificationHandlerBase`2.Handle(IEnumerable`1 notifications)\r\n
   at Umbraco.Cms.Core.Events.EventAggregator.PublishCore[TNotification](IEnumerable`1 allHandlers, IEnumerable`1 notifications)\r\n
   at Umbraco.Cms.Core.Events.NotificationHandlerWrapperImpl`1.Handle[TNotification,TNotificationHandler](IEnumerable`1 notifications, ServiceFactory serviceFactory, Action`2 publish)\r\n
   at Umbraco.Cms.Core.Events.EventAggregator.PublishNotifications[TNotification,TNotificationHandler](IEnumerable`1 notifications)\r\n
   at Umbraco.Cms.Core.Events.EventAggregator.Publish[TNotification,TNotificationHandler](IEnumerable`1 notifications)\r\n
   at Umbraco.Deploy.Infrastructure.DeployScopedNotificationPublisher.PublishScopedNotifications(IList`1 notifications)\r\n
   at Umbraco.Cms.Core.Events.ScopedNotificationPublisher`1.ScopeExit(Boolean completed)\r\n
   at Umbraco.Cms.Core.Scoping.CoreScope.HandleScopedNotifications()\r\n
   at Umbraco.Cms.Infrastructure.Scoping.Scope.TryFinally(Action[] actions)",
    "RemoteStackTraceString": null,
    "RemoteStackIndex": 0,
    "ExceptionMethod": null,
    "HResult": -2146233088,
    "Source": "Umbraco.PublishedCache.NuCache",
    "WatsonBuckets": null
  },
  "Sender": "Umbraco.Deploy.Infrastructure.Work.WorkItems.DiskReadWorkItem"
}

Steps to reproduce

I don't know how to reproduce the error. As mentioned above, it happens during Umbraco Cloud deployment process, and might be related to other bugs not yet identified.

There are a couple (at least) other issues which probably would've benefitted from improved error messages, maybe studying these will help reproducing the error situation:

Expected result / actual result

The desired outcome is to have error information which is clear enough to help you understand why the error occurred (a system failure when attempting to refresh the NuCache after deployment completed) and what corrective action to take (until the underlying bug(s) are fixed, force a rebuild of the cache (how to do that is another issue)).

github-actions[bot] commented 8 months ago

Hi there @tormnator!

Firstly, a big thank you for raising this issue. Every piece of feedback we receive helps us to make Umbraco better.

We really appreciate your patience while we wait for our team to have a look at this but we wanted to let you know that we see this and share with you the plan for what comes next.

We wish we could work with everyone directly and assess your issue immediately but we're in the fortunate position of having lots of contributions to work with and only a few humans who are able to do it. We are making progress though and in the meantime, we will keep you in the loop and let you know when we have any questions.

Thanks, from your friendly Umbraco GitHub bot :robot: :slightly_smiling_face:

Migaroez commented 7 months ago

Hey Torm, thank you for this report. Our resident deploy expert has also been able to trigger this error on a CMS 13.0.0 & Deploy 13.0.3 cloud project, so it's definitely not a one off.

I will check with the team on when we might be able to have a look at this and your suggestions around extra error catching/logging.