xrm-ci-framework icon indicating copy to clipboard operation
xrm-ci-framework copied to clipboard

Published 20 hours ago • verified publisher icon WaelHamze

Package Deployer fails after import activity with connection issue

Open h-karthik12 opened this issue 2 years ago • 2 comments

Hi Hamze,

Thanks for the great work on the Power DevOps Tool

We are deploying managed solution into CRM Using azure DevOps Pipeline with your market place extension. We are seeing connection issue while Stage fails after 30-35 min after successfully import and fails during deleting and upgrading the holding

I have pasted the log of the pipeline. 2022-06-29T07:51:59.7451838Z PackageDeployer Information: 8 : Message: TestSolution - Fetching Data 2022-06-29T07:51:59.7465704Z PackageDeployer Verbose: 16 : Message: TestSolution - UploadHoldingSolutionV2 - SkipImportJobCheck=False 2022-06-29T07:51:59.8625142Z PackageDeployer Information: 8 : Message: TestSolution - Import Progress is : 91.0144927536232 2022-06-29T07:51:59.8647021Z PackageDeployer Information: 8 : Message: TestSolution Solution Import Result = UNKNOWN - Duration: 00:02:00.7971267 2022-06-29T07:51:59.8655120Z PackageDeployer Information: 8 : Message: TestSolution - Pausing for 5 seconds before resuming operation. Retry# 0 2022-06-29T07:52:04.8696548Z PackageDeployer Information: 8 : Message: TestSolution - Fetching Data 2022-06-29T07:52:04.8709124Z PackageDeployer Verbose: 16 : Message: TestSolution - UploadHoldingSolutionV2 - SkipImportJobCheck=False 2022-06-29T07:52:04.9110025Z PackageDeployer Information: 8 : Message: TestSolution - Import Progress is : 100 2022-06-29T07:52:04.9153687Z PackageDeployer Information: 8 : Message: TestSolution Solution Import Result = success - Duration: 00:02:00.7971267 2022-06-29T07:52:04.9625845Z PackageDeployer Information: 8 : Message: TestSolution - Updated solution Version: 1.0.0.2 to Version : 1.0.0.3 2022-06-29T07:52:04.9662890Z PackageDeployer Information: 8 : Message: Updating solution Test Solution version 1.0.0.2 to version 1.0.0.3: Running custom migration code.--Working 2022-06-29T07:52:04.9671130Z PackageDeployer Information: 8 : Message: TestSolution : User Code Execution : OP=RunSolutionUpgradeMigrationStep : Status=Execute 2022-06-29T07:52:04.9683170Z PackageDeployer Information: 8 : Message: TestSolution : User Code Execution : OP=RunSolutionUpgradeMigrationStep : Status=Complete : Duration=00:00:00.0049679 2022-06-29T07:52:04.9745468Z PackageDeployer Information: 8 : Message: TestSolution - Updating solution Version: 1.0.0.2 to Version : 1.0.0.3 - Deleting Holding Solution 2022-06-29T07:52:04.9755226Z PackageDeployer Information: 8 : Message: Updating solution Test Solution version 1.0.0.2 to version 1.0.0.3: Deleting Holding solution.--Working 2022-06-29T07:52:04.9768286Z PackageDeployer Information: 8 : Message: TestSolution - Executing Solution Import - PromoteHoldingSolutionV2 2022-06-29T07:54:05.0777142Z PackageDeployer Verbose: 16 : Message: solution does not exist on server - solutionName = TestSolution - targetEnviromentSolutionVersion = 1.0.0.2 - incomingSolutionVersion = 1.0.0.3 2022-06-29T07:54:05.0793473Z PackageDeployer Error: 2 : Message: TestSolution - Updating solution Version: 1.0.0.2 to Version : 1.0.0.3 - Deleting Holding Solution FAILED : : ************ CommunicationException - DeleteAndPromote : Delete and Promote Solution to New version(DeleteAndPromoteSolutionRequest) |=> The underlying connection was closed: A connection that was expected to be kept alive was closed by the server. 2022-06-29T07:54:05.0796538Z The underlying connection was closed: A connection that was expected to be kept alive was closed by the server. => The underlying connection was closed: A connection that was expected to be kept alive was closed by the server. => Unable to read data from the transport connection: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond. => A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond[TerminalFailure] Failed to Execute Command - DeleteAndPromote : RequestID=22ec3bea-0a87-4c3f-8a83-c05568bc45f2 : Delete and Promote Solution to New version(DeleteAndPromoteSolutionRequest) duration=00:02:00.0243969 ExceptionMessage = The underlying connection was closed: A connection that was expected to be kept alive was closed by the server. 2022-06-29T07:54:05.0799678Z The underlying connection was closed: A connection that was expected to be kept alive was closed by the server. => The underlying connection was closed: A connection that was expected to be kept alive was closed by the server. => Unable to read data from the transport connection: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond. => A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 2022-06-29T07:54:05.0800986Z Source : mscorlib 2022-06-29T07:54:05.0801294Z Method : HandleReturnMessage 2022-06-29T07:54:05.0801565Z Date : 7:54:05 AM 2022-06-29T07:54:05.0801954Z Time : 6/29/2022 2022-06-29T07:54:05.0802404Z Error : The underlying connection was closed: A connection that was expected to be kept alive was closed by the server. 2022-06-29T07:54:05.0802833Z Stack Trace : Server stack trace: 2022-06-29T07:54:05.0803413Z at System.ServiceModel.Channels.HttpChannelUtilities.ProcessGetResponseWebException(WebException webException, HttpWebRequest request, HttpAbortReason abortReason) 2022-06-29T07:54:05.0804153Z at System.ServiceModel.Channels.HttpChannelFactory1.HttpRequestChannel.HttpChannelRequest.WaitForReply(TimeSpan timeout) 2022-06-29T07:54:05.0804721Z at System.ServiceModel.Channels.RequestChannel.Request(Message message, TimeSpan timeout) 2022-06-29T07:54:05.0805284Z at System.ServiceModel.Dispatcher.RequestChannelBinder.Request(Message message, TimeSpan timeout) 2022-06-29T07:54:05.0805921Z at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout) 2022-06-29T07:54:05.0806650Z at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation) 2022-06-29T07:54:05.0807199Z at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message) 2022-06-29T07:54:05.0807410Z 2022-06-29T07:54:05.0807674Z Exception rethrown at [0]: 2022-06-29T07:54:05.0808079Z at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg) 2022-06-29T07:54:05.0808643Z at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type) 2022-06-29T07:54:05.0809219Z at Microsoft.Xrm.Sdk.IOrganizationService.Execute(OrganizationRequest request) 2022-06-29T07:54:05.0809768Z at Microsoft.Xrm.Sdk.WebServiceClient.WebProxyClient1.ExecuteAction[TResult](Func1 action) 2022-06-29T07:54:05.0810377Z at Microsoft.Xrm.Tooling.Connector.CrmServiceClient.CrmCommand_Execute(OrganizationRequest req, String errorStringCheck) 2022-06-29T07:54:05.0811007Z ====================================================================================================================== 2022-06-29T07:54:05.0811414Z Inner Exception Level 1 : 2022-06-29T07:54:05.0811804Z Source : System 2022-06-29T07:54:05.0812050Z Method : GetResponse 2022-06-29T07:54:05.0812378Z Date : 7:54:05 AM 2022-06-29T07:54:05.0812623Z Time : 6/29/2022 2022-06-29T07:54:05.0813030Z Error : The underlying connection was closed: A connection that was expected to be kept alive was closed by the server. 2022-06-29T07:54:05.0813543Z Stack Trace : at System.Net.HttpWebRequest.GetResponse() 2022-06-29T07:54:05.0814043Z at System.ServiceModel.Channels.HttpChannelFactory1.HttpRequestChannel.HttpChannelRequest.WaitForReply(TimeSpan timeout) 2022-06-29T07:54:05.0815329Z ====================================================================================================================== 2022-06-29T07:54:05.0815740Z Inner Exception Level 2 : 2022-06-29T07:54:05.0816032Z Source : System 2022-06-29T07:54:05.0816260Z Method : Read 2022-06-29T07:54:05.0816541Z Date : 7:54:05 AM 2022-06-29T07:54:05.0816784Z Time : 6/29/2022 2022-06-29T07:54:05.0817431Z Error : Unable to read data from the transport connection: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond. 2022-06-29T07:54:05.0818166Z Stack Trace : at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size) 2022-06-29T07:54:05.0818694Z at System.Net.FixedSizeReader.ReadPacket(Byte[] buffer, Int32 offset, Int32 count) 2022-06-29T07:54:05.0819257Z at System.Net.Security._SslStream.StartFrameHeader(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest) 2022-06-29T07:54:05.0819931Z at System.Net.Security._SslStream.StartReading(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest) 2022-06-29T07:54:05.0820542Z at System.Net.Security._SslStream.ProcessRead(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest) 2022-06-29T07:54:05.0821101Z at System.Net.TlsStream.Read(Byte[] buffer, Int32 offset, Int32 size) 2022-06-29T07:54:05.0821655Z at System.Net.PooledStream.Read(Byte[] buffer, Int32 offset, Int32 size) 2022-06-29T07:54:05.0822200Z at System.Net.Connection.SyncRead(HttpWebRequest request, Boolean userRetrievedStream, Boolean probeRead) 2022-06-29T07:54:05.0822762Z ====================================================================================================================== 2022-06-29T07:54:05.0823206Z Inner Exception Level 3 : 2022-06-29T07:54:05.0823461Z Source : System 2022-06-29T07:54:05.0823735Z Method : Read 2022-06-29T07:54:05.0823971Z Date : 7:54:05 AM 2022-06-29T07:54:05.0824249Z Time : 6/29/2022 2022-06-29T07:54:05.0824773Z Error : A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 2022-06-29T07:54:05.0825460Z Stack Trace : at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size) 2022-06-29T07:54:05.0825993Z ====================================================================================================================== 2022-06-29T07:54:05.0908269Z PackageDeployer Verbose: 16 : Message: package deployment failure exception type : System.ServiceModel.CommunicationException 2022-06-29T07:54:05.0917599Z PackageDeployer Verbose: 16 : Message: converting exception to error details 2022-06-29T07:54:05.0927621Z PackageDeployer Verbose: 16 : Message: package deployment failure exception type : System.Net.WebException 2022-06-29T07:54:05.0937247Z PackageDeployer Verbose: 16 : Message: converting exception to error details 2022-06-29T07:54:05.0946021Z PackageDeployer Verbose: 16 : Message: package deployment failure exception type : System.IO.IOException 2022-06-29T07:54:05.0961420Z PackageDeployer Verbose: 16 : Message: converting exception to error details 2022-06-29T07:54:05.0964238Z PackageDeployer Verbose: 16 : Message: package deployment failure exception type : System.Net.Sockets.SocketException 2022-06-29T07:54:05.0972936Z PackageDeployer Verbose: 16 : Message: converting exception to error details 2022-06-29T07:54:05.1012395Z PackageDeployer Information: 8 : Message: errorDetails - ErrorCode - -2146233087 2022-06-29T07:54:05.1023742Z PackageDeployer Information: 8 : Message: errorDetails - ErrorName - NotProvided 2022-06-29T07:54:05.1036469Z PackageDeployer Information: 8 : Message: errorDetails - Message - The underlying connection was closed: A connection that was expected to be kept alive was closed by the server. 2022-06-29T07:54:05.1044980Z PackageDeployer Information: 8 : Message: errorDetails - Type - Application 2022-06-29T07:54:05.1053167Z PackageDeployer Information: 8 : Message: errorDetails - StatusCode - 500 2022-06-29T07:54:05.1062392Z PackageDeployer Information: 8 : Message: errorDetails - Source - PackageDeployer 2022-06-29T07:54:05.1075500Z PackageDeployer Information: 8 : Message: errorDetails - TraceText - ......Server stack trace: ...... at System.ServiceModel.Channels.HttpChannelUtilities.ProcessGetResponseWebException(WebException webException, HttpWebRequest request, HttpAbortReason abortReason)...... at System.ServiceModel.Channels.HttpChannelFactory1.HttpRequestChannel.HttpChannelRequest.WaitForReply(TimeSpan timeout)...... at System.ServiceModel.Channels.RequestChannel.Request(Message message, TimeSpan timeout)...... at System.ServiceModel.Dispatcher.RequestChannelBinder.Request(Message message, TimeSpan timeout)...... at System.ServiceModel.Channels.ServiceChannel.Call(String action, Boolean oneway, ProxyOperationRuntime operation, Object[] ins, Object[] outs, TimeSpan timeout)...... at System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(IMethodCallMessage methodCall, ProxyOperationRuntime operation)...... at System.ServiceModel.Channels.ServiceChannelProxy.Invoke(IMessage message)............Exception rethrown at [0]: ...... at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)...... at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)...... at Microsoft.Xrm.Sdk.IOrganizationService.Execute(OrganizationRequest request)...... at Microsoft.Xrm.Sdk.WebServiceClient.WebProxyClient1.ExecuteAction[TResult](Func1 action)...... at Microsoft.Xrm.Tooling.Connector.CrmServiceClient.CrmCommand_Execute(OrganizationRequest req, String errorStringCheck) 2022-06-29T07:54:05.1082206Z PackageDeployer Information: 8 : Message: errorDetails - ErrorCode - -2146233079 2022-06-29T07:54:05.1090825Z PackageDeployer Information: 8 : Message: errorDetails - ErrorName - NotProvided 2022-06-29T07:54:05.1098858Z PackageDeployer Information: 8 : Message: errorDetails - Message - The underlying connection was closed: A connection that was expected to be kept alive was closed by the server. 2022-06-29T07:54:05.1106874Z PackageDeployer Information: 8 : Message: errorDetails - Type - Application 2022-06-29T07:54:05.1115924Z PackageDeployer Information: 8 : Message: errorDetails - StatusCode - 500 2022-06-29T07:54:05.1124240Z PackageDeployer Information: 8 : Message: errorDetails - Source - PackageDeployer 2022-06-29T07:54:05.1132784Z PackageDeployer Information: 8 : Message: errorDetails - TraceText - at System.Net.HttpWebRequest.GetResponse()...... at System.ServiceModel.Channels.HttpChannelFactory1.HttpRequestChannel.HttpChannelRequest.WaitForReply(TimeSpan timeout) 2022-06-29T07:54:05.1140997Z PackageDeployer Information: 8 : Message: errorDetails - ErrorCode - -2146232800 2022-06-29T07:54:05.1148785Z PackageDeployer Information: 8 : Message: errorDetails - ErrorName - NotProvided 2022-06-29T07:54:05.1157804Z PackageDeployer Information: 8 : Message: errorDetails - Message - Unable to read data from the transport connection: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond. 2022-06-29T07:54:05.1165865Z PackageDeployer Information: 8 : Message: errorDetails - Type - Application 2022-06-29T07:54:05.1186038Z PackageDeployer Information: 8 : Message: errorDetails - StatusCode - 500 2022-06-29T07:54:05.1199023Z PackageDeployer Information: 8 : Message: errorDetails - Source - PackageDeployer 2022-06-29T07:54:05.1209600Z PackageDeployer Information: 8 : Message: errorDetails - TraceText - at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)...... at System.Net.FixedSizeReader.ReadPacket(Byte[] buffer, Int32 offset, Int32 count)...... at System.Net.Security._SslStream.StartFrameHeader(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest)...... at System.Net.Security._SslStream.StartReading(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest)...... at System.Net.Security._SslStream.ProcessRead(Byte[] buffer, Int32 offset, Int32 count, AsyncProtocolRequest asyncRequest)...... at System.Net.TlsStream.Read(Byte[] buffer, Int32 offset, Int32 size)...... at System.Net.PooledStream.Read(Byte[] buffer, Int32 offset, Int32 size)...... at System.Net.Connection.SyncRead(HttpWebRequest request, Boolean userRetrievedStream, Boolean probeRead) 2022-06-29T07:54:05.1216804Z PackageDeployer Information: 8 : Message: errorDetails - ErrorCode - -2147467259 2022-06-29T07:54:05.1225579Z PackageDeployer Information: 8 : Message: errorDetails - ErrorName - NotProvided 2022-06-29T07:54:05.1234460Z PackageDeployer Information: 8 : Message: errorDetails - Message - A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond 2022-06-29T07:54:05.1242363Z PackageDeployer Information: 8 : Message: errorDetails - Type - Application 2022-06-29T07:54:05.1250288Z PackageDeployer Information: 8 : Message: errorDetails - StatusCode - 500 2022-06-29T07:54:05.1260091Z PackageDeployer Information: 8 : Message: errorDetails - Source - PackageDeployer 2022-06-29T07:54:05.1296099Z PackageDeployer Information: 8 : Message: errorDetails - TraceText - at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size) 2022-06-29T07:54:05.1297974Z PackageDeployer Information: 8 : Message: RaiseFailEvent - update progress with fail event 2022-06-29T07:54:05.1298957Z PackageDeployer Information: 8 : Message: Updating solution Test Solution version 1.0.0.2 to version 1.0.0.3: Deleting Holding solution.--Failed 2022-06-29T07:54:05.1311567Z PackageDeployer Information: 8 : Message: ************** BEGIN Queuing UpdateRibbonClientMetadata Job ***************** 2022-06-29T07:54:05.1322360Z PackageDeployer Information: 8 : Message: Trying to queue up UpdateRibbonClientMetadata Job. 2022-06-29T07:54:05.9285447Z PackageDeployer Information: 8 : Message: Successfully queued up UpdateRibbonClientMetadata request.--Complete 2022-06-29T07:54:05.9298958Z PackageDeployer Information: 8 : Message: Time taken for queuing the ribbon job: 00:00:00.7968789 2022-06-29T07:54:05.9306349Z PackageDeployer Information: 8 : Message: ************** UpdateRibbonClientMetadata Job QUEUED ***************** 2022-06-29T07:54:05.9346575Z PackageDeployer Information: 8 : Message: ****** PACKAGE DEPLOYMENT PROCESS COMPLETED. Result:FAILED Duration:00:33:17.5728409 ****** 2022-06-29T07:54:05.9356359Z PackageDeployer Information: 8 : Message: TestSolution - Pausing for 5 seconds before resuming operation. Retry# 0 2022-06-29T07:54:06.2110640Z ##[error]Import Failed 2022-06-29T07:54:06.2591631Z ##[section]Finishing: Package Deployer for Solutions

image

But in backend the Promoting of the Holding solution and deleting will be in process. So we have to wait till those activity completes in CRM. But in azure DevOps the Pipeline will be shown as failed. We need to trigger again so it will skip because the same version is already deployed and pipeline will be successful The solution is little huge. we have other small solutions which will complete without any issue. Is there something we are missing from our end.

h-karthik12 avatar Jul 12 '22 11:07 h-karthik12

@WaelHamze Please need your expertise here. It would be a great help

h-karthik12 avatar Aug 01 '22 11:08 h-karthik12

@h-karthik12 as workaround you can try change import mode to async (requiredimportmode="async") in ImportConfig.xml: <configsolutionfile solutionpackagefilename="your-solution.zip" overwriteunmanagedcustomizations="true" publishworkflowsandactivateplugins="true" requiredimportmode="async" />

majakubowski avatar Aug 01 '22 11:08 majakubowski

@majakubowski Thanks for the input it really worked. Sorry for late reply. But many thanks for the resolution

h-karthik12 avatar Nov 24 '22 14:11 h-karthik12