DeleteAndPromote Failing for MSCRM Apply Solution

[AlexSpodkiewicz]

On a few environments when using the MSCRM Apply Solution step runs and kicks off the DeleteAndPromote Job it is failing with the following error after about 45 minutes has anyone seen this before. If you keep retrying sometimes it eventually applies successfully. However on one environment it keeps failing. Any help would be greatly appreciated.

Unhandled exception: Exception type: System.ServiceModel.FaultException`1[Microsoft.Xrm.Sdk.OrganizationServiceFault] Message: Exception retrieving custom activity info using SandboxPlugin - Unhandled exception: Exception type: Microsoft.Crm.CrmException Message: Unable to retrieve customActivityInfo using RetrieveCustomActivityInfoWithSandboxPlugin. at Microsoft.Crm.Workflow.ObjectModel.CustomActivityInfoMetadataBase.GetCustomActivityInfo(ActivityInfo activityInfo, Int32 isolationMode, Guid pluginAssemblyId) -- End stack trace --

[AlexSpodkiewicz]

Just to add magically a deployment to an environment over several times has worked ok again after several attempts. Have others seen this before?

[mattp65]

There has been an evolving issue with some of the tasks related to something in the underlying platform that causes odd timeouts on some tasks the first time run after a period of inactivity (like 1st of the day). It has been most noticeable on Export but I've seen it intermittently on other tasks like Import, Publish & Apply. It isn't easily reproduce-able and a retry of the job typically works since it it now 'cached'. #183 has some background related specifically to Export, but it seems like similar behavior.

[AlexSpodkiewicz]

Cheers Matt for getting back to me been trying a deployment for over 17 times last 2 days and then just worked fine. Have you experienced issues with particular times of the day? I've found after 2am UK time things seem to work fine. On Sunday during day had no issues. Do people see any times or days to avoid deployments? Any experience of times to avoid would be great.

[WaelHamze]

@AlexSpodkiewicz @mattp65 I have not noticed this personally. Sounds like something related to backend. Are you still experiencing this issue?

[AlexSpodkiewicz]

@WaelHamze Yes we are still getting it from time to time would we be better using Sync rather than Async for the upgrade task?

[WaelHamze]

@AlexSpodkiewicz normally it is better to use async as sync may be subject to different issues such as timeout.

Have you tried to raise this issue with MS?

[cseymr]

We've seen this same issue a number of times over the past few weeks, today being the latest example.

In the past, after the fail, we've usually abandoned that step in the pipeline and done the upgrade through the D365 UI, and this seems to work without problem (or at least, without surfacing it :-) )

Today as an experiment we repeated the upgrade attempt after the first fail (literally just ran the pipeline again) and it failed with the same error after the same amount of time. So based on one data point (...) it's repeatable and it only fails when using the pipeline tool.

I don't really know how to approach MS about this, as they won't support 3rd party tools, and the UI approach doesn't show the same problem.

[cseymr]

Further to the above - running the same upgrade through the UI has just succeeded with no reported errors.

[cseymr]

Here's the log:

2021-01-06T11:09:14.3986179Z ##[debug]Solution retrieved with Id: 6d564022-6cbd-4156-8fa3-d177541b151d 2021-01-06T11:09:14.4042965Z ##[debug]RequestId: c3fbcc36-5779-4d04-90b6-9ae833a3a18c 2021-01-06T11:09:14.4076670Z ##[debug]Applying using Async Mode 2021-01-06T11:09:14.5183830Z ##[debug]Awaiting for Async Operation Completion 2021-01-06T11:09:14.5225945Z ##[debug]Sleeping for 15 seconds 2021-01-06T11:09:29.6447909Z ##[debug]Async Operation Status: WaitingForResources 2021-01-06T11:09:29.6472016Z ##[debug]Sleeping for 15 seconds 2021-01-06T11:09:44.7033466Z ##[debug]Async Operation Status: InProgress 2021-01-06T11:09:44.7054170Z ##[debug]Sleeping for 15 seconds ... 2021-01-06T12:02:48.5145778Z ##[debug]Async Operation Status: InProgress 2021-01-06T12:02:48.5171207Z ##[debug]Sleeping for 15 seconds 2021-01-06T12:03:04.2475004Z ##[debug]Async Operation Status: Failed 2021-01-06T12:03:04.2524490Z ##[debug]Retrieving solution '_Upgrade' 2021-01-06T12:03:04.3278639Z ##[debug]Solution retrieved with Id: 6d564022-6cbd-4156-8fa3-d177541b151d 2021-01-06T12:03:04.3350914Z ##[debug]Retrieving Solution: _Upgrade 2021-01-06T12:03:04.3465794Z Async Job Id: 2021-01-06T12:03:04.3599606Z ##[debug]Caught exception from task script. 2021-01-06T12:03:04.3641614Z ##[debug]Error record: 2021-01-06T12:03:04.4418643Z ##[debug]Merge-XrmSolution : Solution upgrade Failed. Error: Solution still exists after upgrade: _Upgrade 2021-01-06T12:03:04.4453703Z ##[debug]At C:\hostedtoolcache\windows\MSCRMBuildTools\12.0.37\xRMCIFramework\9.0.0\ApplySolution.ps1:40 char:22 2021-01-06T12:03:04.4470921Z ##[debug]+ ... erationId = Merge-XrmSolution -ConnectionString "$CrmConnectionString ... 2021-01-06T12:03:04.4545634Z ##[debug]+ ~~~~~~~~~~~~~ 2021-01-06T12:03:04.4653663Z ##[debug] + CategoryInfo : NotSpecified: (:) [Merge-XrmSolution], Exception 2021-01-06T12:03:04.4685201Z ##[debug] + FullyQualifiedErrorId : System.Exception,Xrm.Framework.CI.PowerShell.Cmdlets.MergeXrmSolutionCommand 2021-01-06T12:03:04.4712254Z ##[debug] 2021-01-06T12:03:04.4798461Z ##[debug]Script stack trace: 2021-01-06T12:03:04.4953654Z ##[debug]at , C:\hostedtoolcache\windows\MSCRMBuildTools\12.0.37\xRMCIFramework\9.0.0\ApplySolution.ps1: line 40 2021-01-06T12:03:04.4977393Z ##[debug]at , D:\a_tasks\MSCRMApplySolution_f08caccb-e6cd-4857-9e69-410c8adb7eb8\12.0.1\MSCRMApplySolution.ps1: line 32 2021-01-06T12:03:04.5003000Z ##[debug]at , : line 1 2021-01-06T12:03:04.5028473Z ##[debug]at , : line 22 2021-01-06T12:03:04.5050733Z ##[debug]at , : line 18 2021-01-06T12:03:04.5092074Z ##[debug]at , : line 1 2021-01-06T12:03:04.5101616Z ##[debug]Exception: 2021-01-06T12:03:04.5171149Z ##[debug]System.Exception: Solution upgrade Failed. Error: Solution still exists after upgrade: _Upgrade 2021-01-06T12:03:04.5195088Z ##[debug] at Xrm.Framework.CI.PowerShell.Cmdlets.MergeXrmSolutionCommand.ProcessRecord() 2021-01-06T12:03:04.5213284Z ##[debug] at System.Management.Automation.CommandProcessor.ProcessRecord() 2021-01-06T12:03:04.5666649Z ##[error]Solution upgrade Failed. Error: Solution still exists after upgrade: _Upgrade 2021-01-06T12:03:04.5668620Z ##[debug]Processed: ##vso[task.logissue type=error]Solution upgrade Failed. Error: Solution still exists after upgrade: _Upgrade 2021-01-06T12:03:04.5709886Z ##[debug]Processed: ##vso[task.complete result=Failed]

[cseymr]

When I look at the log closely, I see that these lines in SolutionManager are never called:

                Logger.LogInformation("Async Operation completed with status: {0}",
                    ((AsyncOperation_StatusCode)asyncOperation.StatusCode.Value).ToString());

                Logger.LogInformation("Async Operation completed with message: {0}",
                    asyncOperation.Message);

So I guess something is going wrong with how exception handling is going on. I guess that's also why the error we see is 'Upgrade still exists', which is masking the real error that we can see in the Solution History log.

The next thing I want to investigate is if this is an async vs sync thing. But I need several free hours to check that...

[Shivaram-i]

I am also facing the same issue while using the DeleteandPromoteRequest class. If we are using the pipeline, we cannot use Sync operation, as from pipeline to CRM connect only last for 4 min (I have read some doc regarding this) as it mentioned earlier, after 45 min we are getting this issue. If we are using D365UI, we are not facing any issues.

[Lukis]

We've been in the Deploy > Patch > Upgrade loop on a project for the last 2 months with minimal issues. Our Deploy Solution pipeline stages the main solution for upgrade and is async. We haven't had any issues with that stage. I ran into an issue this week which lead me to this post. The upgrade was failing with odd errors. Once I worked through all the packaging issues I was still only able to successfully upgrade via the UI. I had updated the Apply Upgrade stage to be async a few weeks back and this issue started. For our project the issue is related to trying to do the apply upgrade via an async job.

I think there might be a duplicate job being created for some reason. Here's what the System Jobs shows, they're ordered by created on date.

Oldest Log: Cannot start another [Uninstall] because there is a previous [Uninstall] running at this moment. Use Solution History for more details. -- The solution installation or removal failed due to the installation or removal of another solution at the same time. Please try again later.

Newest Log: Exception retrieving custom activity info using SandboxPlugin - Unhandled exception: Exception type: Microsoft.Crm.CrmException Message: Unable to retrieve customActivityInfo using RetrieveCustomActivityInfoWithSandboxPlugin. at Microsoft.Crm.Workflow.ObjectModel.CustomActivityInfoMetadataBase.GetCustomActivityInfo(ActivityInfo activityInfo, Int32 isolationMode, Guid pluginAssemblyId, Boolean isFullySigned, String publicKeyToken) -- End stack trace --

[wnbittle]

If it worth anything, we're also seeing this using the Power Platform toolset. The error posted by @Lukis during the DeleteAndPromote process. If we execute the upgrade manually from the UI it works.

Those solutions without custom WF activities are working properly. We've opened a ticket with MS and still have some troubleshooting on our end to do.

[wnbittle]

Update: MS has acknowledged it as a bug, but doesn't expect a fix until end of March to NA region. The recommendation is to continue with the UI upgrade work around until then.

[trepaxrm]

Funny, more than 2 year later, we still have the issue, any one has a work around for automated deployment, thanks