Unable to provision after upgrading to 1.7

[rafaelrph]

Describe the bug

To Reproduce

I'm not able to provision a new tenant/client after upgrading to 1.7. (my current version is 1.5)
If fails in the DocumentManager class -> GetOrCreateMutableAsync() when it tries to get/create the OrchardCore.Settings.SiteSettings and OrchardCore.Roles.Models.RolesDocument from the memory cache.

The following exception is thrown:

OrchardCore/src/OrchardCore/OrchardCore.Infrastructure/Documents/DocumentManager.cs

Line 75 in 6cf70aa

throw new InvalidOperationException("Can't load for update a cached object");

Our application uses it in a multi tenant mode without our own layer on top of it.
We also use our own recipes. I saw the following information and I'm not which changes I have to do to make it work.

OrchardCore/src/docs/reference/modules/Recipes/README.md

Line 323 in 8c18439

As of version 1.6, the default roles are no longer auto created. Setup recipe must define the default roles to be used. The `Roles` feature will automatically map all known permissions to the defined roles each time a feature is enabled.

https://github.com/OrchardCMS/OrchardCore/blob/8c184395c1aa9b40580642a7d0df740ad9cdfac5/src/docs/releases/1.7.0.md#breaking-changes

[MikeAlhayek]

As of version 1.6, the default roles are no longer auto created. Setup recipe must define the default roles to be used. The Roles feature will automatically map all known permissions to the defined roles each time a feature is enabled.

Add this to your setup recipe

{
  "steps": [
    {
      "name": "Roles",
      "Roles": [
        {
          "Name": "Administrator",
          "Description": "Administrator",
          "Permissions": []
        },
        {
          "Name": "Moderator",
          "Description": "Moderator",
          "Permissions": []
        },
        {
          "Name": "Editor",
          "Description": "Editor",
          "Permissions": []
        },
        {
          "Name": "Author",
          "Description": "Author",
          "Permissions": []
        },
        {
          "Name": "Contributor",
          "Description": "Contributor",
          "Permissions": []
        },
        {
          "Name": "Authenticated",
          "Description": "Authenticated",
          "Permissions": []
        },
        {
          "Name": "Anonymous",
          "Description": "Anonymous",
          "Permissions": []
        }
      ]
    }
  ]
}

If you continue to have the issue, please share your error logs.

[rafaelrph]

Hi @MikeAlhayek ,
Our recipe already contains the roles list of objects in the steps list as you mentioned above.
Here is an example:

{
  "name": "Tenant-Default",
  "steps": [
    {
      "name": "Roles",
      "Roles": [
        {
          "Name": "Anonymous",
          "Description": "Anonymous role",
          "Permissions": []
        },
        {
          "Name": "Authenticated",
          "Description": "Authenticated role",
          "Permissions": []
        }
      ]
    }
  ]
}

As I said before, the DocumentManager.cs throws the following error: "Can't load for update a cached object"
The new tenant DB is created, however the full process is not finished, the endpoint returns 417 - "Client Provisioning: Failed to setup tenant for client tenantName".

Here is the error log:

Root.Tenants.Services.Interfaces.IProvisioningService|ERROR|Error: Client Provisioning: Failed to setup tenant for client tenant112abc; Message: Cant load for update a cached object; StackTrace:    at OrchardCore.Documents.DocumentManager1.GetOrCreateMutableAsync(Func1 factoryAsync) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Infrastructure\Documents\DocumentManager.cs:line 75
   at OrchardCore.Settings.Services.SiteService.LoadSiteSettingsAsync() in C:\Root\App\OrchardCore\src\OrchardCore.Modules\OrchardCore.Settings\Services\SiteService.cs:line 26
   at OrchardCore.Media.Processing.MediaTokenSettingsUpdater.ActivatedAsync() in C:\Root\App\OrchardCore\src\OrchardCore.Modules\OrchardCore.Media\Processing\MediaTokenSettingsUpdater.cs:line 39
   at OrchardCore.Environment.Shell.Scope.ShellScope.<>c.<<ActivateShellInternalAsync>b__43_0>d.MoveNext() in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Abstractions\Shell\Scope\ShellScope.cs:line 322
--- End of stack trace from previous location ---
at OrchardCore.Environment.Shell.Scope.ShellScope.UsingAsync(Func2 execute, Boolean activateShell) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Abstractions\Shell\Scope\ShellScope.cs:line 253
at OrchardCore.Environment.Shell.Scope.ShellScope.UsingAsync(Func2 execute, Boolean activateShell) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Abstractions\Shell\Scope\ShellScope.cs:line 258
at OrchardCore.Environment.Shell.Scope.ShellScope.UsingAsync(Func2 execute, Boolean activateShell) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Abstractions\Shell\Scope\ShellScope.cs:line 263
at OrchardCore.Environment.Shell.Scope.ShellScope.UsingAsync(Func2 execute, Boolean activateShell) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Abstractions\Shell\Scope\ShellScope.cs:line 268
at OrchardCore.Environment.Shell.Scope.ShellScope.UsingAsync(Func2 execute, Boolean activateShell) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Abstractions\Shell\Scope\ShellScope.cs:line 269
at OrchardCore.Environment.Shell.Scope.ShellScope.ActivateShellInternalAsync() in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Abstractions\Shell\Scope\ShellScope.cs:line 312
at OrchardCore.Environment.Shell.Scope.ShellScope.ActivateShellInternalAsync() in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Abstractions\Shell\Scope\ShellScope.cs:line 327
at OrchardCore.Environment.Shell.Scope.ShellScope.UsingAsync(Func2 execute, Boolean activateShell) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Abstractions\Shell\Scope\ShellScope.cs:line 250
at OrchardCore.Environment.Shell.Scope.ShellScope.UsingAsync(Func2 execute, Boolean activateShell) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Abstractions\Shell\Scope\ShellScope.cs:line 258
at OrchardCore.Environment.Shell.Scope.ShellScope.UsingAsync(Func2 execute, Boolean activateShell) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Abstractions\Shell\Scope\ShellScope.cs:line 263
at OrchardCore.Environment.Shell.Scope.ShellScope.UsingAsync(Func2 execute, Boolean activateShell) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Abstractions\Shell\Scope\ShellScope.cs:line 268
at OrchardCore.Environment.Shell.Scope.ShellScope.UsingAsync(Func2 execute, Boolean activateShell) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Abstractions\Shell\Scope\ShellScope.cs:line 269
at OrchardCore.Recipes.Services.RecipeExecutor.ExecuteStepAsync(RecipeExecutionContext recipeStep) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Recipes.Core\Services\RecipeExecutor.cs:line 160
at OrchardCore.Recipes.Services.RecipeExecutor.ExecuteAsync(String executionId, RecipeDescriptor recipeDescriptor, IDictionary2 environment, CancellationToken cancellationToken) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Recipes.Core\Services\RecipeExecutor.cs:line 102
at OrchardCore.Recipes.Services.RecipeExecutor.ExecuteAsync(String executionId, RecipeDescriptor recipeDescriptor, IDictionary2 environment, CancellationToken cancellationToken) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Recipes.Core\Services\RecipeExecutor.cs:line 120
at OrchardCore.Recipes.Services.RecipeExecutor.ExecuteAsync(String executionId, RecipeDescriptor recipeDescriptor, IDictionary2 environment, CancellationToken cancellationToken) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Recipes.Core\Services\RecipeExecutor.cs:line 146
at OrchardCore.Setup.Services.SetupService.SetupInternalAsync(SetupContext context) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Setup.Core\SetupService.cs:line 226
at OrchardCore.Setup.Services.SetupService.SetupInternalAsync(SetupContext context) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Setup.Core\SetupService.cs:line 227
at OrchardCore.Setup.Services.SetupService.SetupAsync(SetupContext context) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Setup.Core\SetupService.cs:line 95
at OrchardCore.Setup.Services.SetupService.SetupAsync(SetupContext context) in C:\Root\App\OrchardCore\src\OrchardCore\OrchardCore.Setup.Core\SetupService.cs:line 110

[MikeAlhayek]

Maybe in your code, you are calling GetOrCreateImmutableAsync() method which causes the document to be cached. Maybe try step back into your logic and see if you are calling the Immutable method.

[rafaelrph]

Hey @MikeAlhayek ,

All calls, to the DocumentManager.GetOrCreateMutableAsync method, are coming from OC files.

[MikeAlhayek]

In your code, are you not calling GetOrCreateImmutableAsync?

Not sure if GetOrCreateImmutableAsync is called during setup. @jtkech maybe be able to provide more feedback or if this an OC internal issue.

[rafaelrph]

Our provision logic gets the recipe, add some customized information, call the OrchardCore.Setup.Services.SetupService -> SetupAsync() method and then SetupService calls the GetOrCreateImmutableAsync method multiple times behind the scene.
Our provision implementation hasn't changed recently. It works fine with the OC 1.5 version.

[sebastienros]

@jtkech this code

https://github.com/OrchardCMS/OrchardCore/blob/main/src/OrchardCore.Modules/OrchardCore.Media/Processing/MediaTokenSettingsUpdater.cs#L35-L47

It loads the site settings as immutable, then load it again as mutable if the hash is not defined.
Is it possible that this code is invoked and finds an immutable entry so it fails?

OrchardCore/src/OrchardCore/OrchardCore.Infrastructure/Documents/DocumentManager.cs

Lines 71 to 76 in 6cf70aa

	document = await DocumentStore.GetOrCreateMutableAsync(factoryAsync);
	if (_memoryCache.TryGetValue<TDocument>(_options.CacheKey, out var cached) && document == cached)
	{
	throw new InvalidOperationException("Can't load for update a cached object");
	}

Then maybe just load the site settings for change in the MediaUpdater, or handle this case without failing in the document manager?

@rafaelrph Could you try to replace var mediaTokenSettings = (await _siteService.GetSiteSettingsAsync()).As<MediaTokenSettings>(); with LoadSiteSettings in the MediaTokenSettingsUpdater class to see if that fixes it?

Another option could be for you to set the HashKey in a previous step so it doesn't try to update it. (just a mitigation for now).

[rafaelrph]

Hi @sebastienros,
I tried to replace the logic in the MediaTokenSettingsUpdater and it didn't work. After the change, the code was like this:
var mediaTokenSettings = (await _siteService.LoadSiteSettingsAsync()).As<MediaTokenSettings>();

Debugging the application with this change:

1. It throws the InvalidOperationException("Can't load for update a cached object"); in the DocumentManager.cs for the OrchardCore.Roles.Models.RolesDocument key.
2. It goes through the MediaTokenSettingsUpdater -> ActivatedAsync() method.
3. It throws the InvalidOperationException("Can't load for update a cached object"); in the DocumentManager.cs again, now for the OrchardCore.Settings.SiteSettings key.

I didn't understand the HashKey option that you mentioned above. If possible, could you please provide more details?

[jtkech]

@sebastienros @rafaelrph

Okay, I will look at it this night

[jtkech]

@sebastienros @rafaelrph

For now I can't repro, before throwing we not only check that the document is already cached but also that it is the same instance, knowing that in the document store when getting an immutable document for caching we also Detach() it from the session so that normally when loading a document for update the database query returns another instance.

@rafaelrph Hmm, can you check in your code if there is an async task that is not correctly awaited.

[ShaneCourtrille]

@jtkech so the code in question works on 1.5 but we can double-check if anything is missing. In the meantime here is a screenshot showing where it throws the error along with the document & cached version.

[ShaneCourtrille]

So I have more information now about this.

The exception is happening during the execution of our EnvironmentMigration (which inherits from DataMigration) class. Specifically, it happens when we run a step that tries to add a role after an earlier step has already added roles.

EnvironmentMigration runs other steps 

EnvironmentMigration runs role-permission-oc-update.json
	- Adds new role named Anonymous
	- Adds new role named Authenticated
	
EnvironmentMigration runs other steps

EnvironmentMigration runs step for open-id-toolbox-application.recipe.json
	- Tries to add new role named "TENANTSADMINISTRATOR" but exception is thrown when loading the roles

Here is the stack of the origin thread if that helps at all.

[ShaneCourtrille]

Out of curiosity, shouldn't the RoleStore reset _updating = false at the end of the UpdateRolesAsync() call? What if the instance is used to update something and then used to read a role after without the intent of updating? This is more of a general question since it doesn't seem to be the cause of our problem as I tested out a change that reset _updating = false and it didn't help.

[rafaelrph]

@jtkech @sebastienros Here is some additional information:

I was debugging the EnvironmentMigration class, that Shane mentioned above, going through each recipe.

All of our OpenId recipes are failing. All of them have a Roles step, following the same structure that @MikeAlhayek mentioned in one of the very first comments.

I checked your sample files for the OpenId recipes (here: https://github.com/OrchardCMS/OrchardCore/tree/0c4e0541b895af5b0afc82e8e4ac01e8dc06333f/test/OrchardCore.Tests/Modules/OrchardCore.OpenId/RecipeFiles) and I didn't see any Roles step there. So I removed the roles step from our own recipes and the OrchardCore.Roles.Models.RolesDocument entry didn't throw the exception anymore. But I'm not sure if that's the right solution for us because we use separate roles. Maybe you guys could clarify that.

Here is a sample OpenId recipe file that we are using:

• openid-sample-recipe.json

Also the following recipes are the ones that throw the exception for the OrchardCore.Settings.SiteSettings entry.

• content-audit-trail-settings.recipe.json
• localization.recipe.json

[jtkech]

@ShaneCourtrille @rafaelrph Thanks for the additional info, I''ll try to look at it this weekend.

What if the instance is used to update something and then used to read a role after without the intent of updating?

In that case normally we return the already loaded instance for updating but also a boolean = false meaning that this instance should not be cached so that when the update occurs it will not fail.

But managing roles is specific as we have to deal with the dotnet IRolesManager which is not aware of this, that' why as I remember we needed an additional _updating boolean.

[rafaelrph]

@jtkech @sebastienros Here is a new finding.

I was debugging our EnvironmentMigration. After I changed the openId recipes removing the roles step (mentioned in my previous comment), and commented out the audit-trail-settings and localization recipes, to not be executed, the DocumentManager still throws the same error InvalidOperationException("Can't load for update a cached object");

I did some investigation and the MediaTokenSettingsUpdater throws the error. It's the same logic that @sebastienros mentioned here: #14574 (comment)
However the _siteService.GetSiteSettingsAsync() method call doesn't throw the error, it's actually the _siteService.LoadSiteSettingsAsync() method call that throws the error.

I tried to do what @sebastienros suggested and the error started to happen in the line that I changed (the same line wasn't throwing the error before). I also tried to change it in the opposite way, making both logics to call _siteService.GetSiteSettingsAsync().

The error InvalidOperationException("Can't load for update a cached object"); is gone, however it throws a new error in the same DocumentManager class, now it throws the error throw new InvalidOperationException("Can't update a cached object"); when it tries to update the settings here:

OrchardCore/src/OrchardCore.Modules/OrchardCore.Media/Processing/MediaTokenSettingsUpdater.cs

Line 47 in ec12082

await _siteService.UpdateSiteSettingsAsync(siteSettings);

[jtkech]

@rafaelrph

Sorry I didn't have time to look at it, for sure I will work on it this night.

[jtkech]

Okay, so the only ways I could repro.

1. When before we do a GET for updating, which is not allowed.

   var siteSettings = await _siteService.GetSiteSettingsAsync();
   await _siteService.UpdateSiteSettingsAsync(siteSettings);
   
   siteSettings = await _siteService.LoadSiteSettingsAsync();
   await _siteService.UpdateSiteSettingsAsync(siteSettings);
   

2. Or if between 2 updates the DocumentStore is committed, which happens in a 'Features' step, not a problem if run in its own scope, but this is not the case if run from a 'migration' recipe.

   var siteSettings = await _siteService.LoadSiteSettingsAsync();
   await _siteService.UpdateSiteSettingsAsync(siteSettings);
   
   await documentStore.CommitAsync(); 
   
   siteSettings = await _siteService.LoadSiteSettingsAsync();
   await _siteService.UpdateSiteSettingsAsync(siteSettings);
   

1. is not allowed and 2. changing features in a migrations recipe is not recommended, all migrations run in the same shell scope and while activating the shell, so this is not the right place.

That said both happen because after the store is well committed this is where we update the shared cache in place of just invalidating it, we did this for perf and because we also have a consistency checking.

So both cases could be fixed by just invalidating the shared cache in place of setting it on updating the store. But 1. would be still not allowed and 2. still not recommended.

Can you confirm that you are in one of the above case?

---

Note: Inside a DataMigrations in place of using the recipe migrator (if the recipe changes features), you can trigger a deferred task or background job in which the regular recipe executor would be used.

Note: Hmm, maybe good to just invalidate the shared cache on updating the store, currently we also do a db query for consistency checking that would no longer be necessary (simpler code), but a db query will be done on a next demand but only once.

---

About the specific case of Roles where we use an _updating flag in the RoleStore because it is called by the aspnetcore RoleManager which is not aware about our caching, now on features change the RolesUpdater update directly the RolesDocument with other metadata, so we would need to inform the RoleStore that the RolesDocument is being updated.

But here too this may be a problem only in a migrations recipe where all run in the same scope, and if features are changed.

[jtkech]

@ShaneCourtrille @rafaelrph

If you can try what I did here #14612.

[rafaelrph]

Just to confirm that these changes (#14612) have fixed the cache issue. Thanks for the help.

[jtkech]

Cool, good to know, thanks!