CreateRestorePoint timeout after v17 upgrade

Questions
1

After upgrading Umbraco, uSync Publisher pushes to our servers are failing.

The push reaches the target server and invokes the following endpoint:

POST /umbraco/uSyncReceive/uSyncReceiveApi/CreateRestorePoint

However, during the failing push, the CreateRestorePoint request continuously performs SQL Server distributed lock operations on the same lock ID:

Lock type: ReadLock
Lock ID: -335

The logs show the following pattern repeating continuously within milliseconds:

Requesting ReadLock for id -335
Acquired ReadLock for id -335
Dropped ReadLock for id -335

Requesting ReadLock for id -335
Acquired ReadLock for id -335
Dropped ReadLock for id -335

Requesting ReadLock for id -335
Acquired ReadLock for id -335
Dropped ReadLock for id -335

For example:



10:36:14.3916883  Requesting ReadLock for id -335
10:36:14.3920615  Acquired ReadLock for id -335
10:36:14.3924509  Dropped ReadLock for id -335

10:36:14.3985947  Requesting ReadLock for id -335
10:36:14.3989308  Acquired ReadLock for id -335
10:36:14.3993217  Dropped ReadLock for id -335

10:36:14.4048274  Requesting ReadLock for id -335
10:36:14.4051250  Acquired ReadLock for id -335
10:36:14.4054805  Dropped ReadLock for id -335

This continues for the duration of the request.

All of these operations are part of:



uSync.Publisher.Controllers.uSyncReceiveApiController.CreateRestorePoint

with the following request ID:

800009f0-0000-b000-b63f-84710c7967bb

The lock implementation involved is:

Umbraco.Cms.Persistence.SqlServer.Services.SqlServerDistributedLockingMechanism

Eventually, the Publisher-side request times out after approximately 100 seconds:

The request was canceled due to the configured HttpClient.Timeout of 100 seconds elapsing.

This behaviour started after the Umbraco upgrade. The same uSync push was working before the upgrade.

image
image1462×686 53.2 KB

2

Hi,

Was this working previously of uSync.Complete v17, (and if so what version) and what version are you running now ?

The lock might not be the actual problem (it can be large media archives being part of the restore point, and the timeout is the compression part where it zips the whole restore together). We do have something in the latest v18.x release for this, but we haven’t pushed it down to the v17 branch yet.

but we will check its not something else, before we assume its that, so the versions are good for us to do the checks.

Kevin

3

Hi Kevin,

These are the versions we are currently running:

<PackageVersion Include="Umbraco.Cms" Version="17.4.2" />
<PackageVersion Include="Umbraco.Cms.Core" Version="17.4.2" />
<PackageVersion Include="Umbraco.Cms.Examine.Lucene" Version="17.4.2" />
<PackageVersion Include="Umbraco.Cms.Infrastructure" Version="17.4.2" />
<PackageVersion Include="Umbraco.Cms.Api.Management" Version="17.4.2" />
<PackageVersion Include="Umbraco.Cms.Web.Common" Version="17.4.2" />
<PackageVersion Include="Umbraco.Cms.Web.Website" Version="17.4.2" />
<PackageVersion Include="Umbraco.Community.Contentment" Version="6.1.4" />
<PackageVersion Include="Umbraco.Engage" Version="17.2.3" />
<PackageVersion Include="Umbraco.UIBuilder" Version="17.2.2" />
<PackageVersion Include="Umbraco.Workflow" Version="17.3.3" />
<PackageVersion Include="uSync.Complete" Version="17.3.9" />
<PackageVersion Include="TinyMCE.Umbraco" Version="17.4.1" />

These were the versions we were using previously:

  <ItemGroup Label="Umbraco">
    <PackageVersion Include="Umbraco.Cms" Version="13.12.1" />
    <PackageVersion Include="Umbraco.Cms.Core" Version="13.12.1" />
    <PackageVersion Include="Umbraco.Cms.Infrastructure" Version="13.12.1" />
    <PackageVersion Include="Umbraco.Cms.Web.BackOffice" Version="13.12.1" />
    <PackageVersion Include="Umbraco.Cms.Web.Common" Version="13.12.1" />
    <PackageVersion Include="Umbraco.Cms.Web.Website" Version="13.12.1" />
    <PackageVersion Include="Umbraco.Community.Contentment" Version="5.1.1" />
    <PackageVersion Include="Umbraco.Engage" Version="13.8.0" />
    <PackageVersion Include="Umbraco.UIBuilder" Version="13.2.4" />
    <PackageVersion Include="uSync.Complete" Version="13.1.10" />
    <PackageVersion Include="Smidge" Version="4.6.0" />
  </ItemGroup>

The issue started after upgrading to the current versions above. The uSync push was working with the previous versions.

Please let us know if you need any additional logs or details to help investigate whether this is related to the restore point compression or something else.

4

Hi,

We’ve pushed out a new version (v17.4.0) with quite a few changes to how the restore point stuff works to try and mitigate this (it is really big zip archive actions blocking, which is something we’ve moved out of the path).

Release Notes : Release v17.4.0 - Restore point reliability & live progress · Jumoo/uSync.Complete.Issues · GitHub

So hopefully this resolves this for you :crossed_fingers:

I think one thing we are probably going to work on a bit more is the wording around the restore points, because while it is totally your choice as to when you create them, actually creating them on every content push is probably overkill for most people.

the idea behind the restore points is they capture a point in time of the site for operations that you can’t reverse easily.

if you publish content by mistake its usually quite easy to get that content back to the state you wanted it either by umbraco’s rollback, or changing the content back.

we created restore points for the bigger changes - e.g if you remove a property from a document type, then when that is saved/pushed, Umbraco removes the value from all your content items using that and their isn’t an easy way for you to then reverse the action, because its unwound a load of content as well as the single doctype change.

that’s what the “Restore detection” setting does, it works out if you are about to push/pull one of those ‘big’ changes across the site and at that point goes, you know what lets create a restore point here.

but for most changes (content/media) changes, it just lets the action through,

So in theory you don’t need restore points on all the time -

but again it is a choice and we do support it. I think we just need to be clearer to people what it does and why you may / may not want it on all the time.

and I am interested to hear what you think, because that’s only how we think people need it, it might well be wrong, and in the real world there are other use case/arguments for having it on more we haven’t given enough thought too.