microsoft / navcontainerhelper

Official Microsoft repository for BcContainerHelper, a PowerShell module, which makes it easier to work with Business Central Containers on Docker.
MIT License
385 stars 246 forks source link

Issue in Multi-tenant container while publishing new apps #3082

Open vivek-jindal opened 1 year ago

vivek-jindal commented 1 year ago

PLEASE DO NOT INCLUDE ANY PASSWORDS OR TOKENS IN YOUR ISSUE!!!

Describe the issue In a multi-tenant container, at a particular time (unable to reproduce precisely but happening every week) we are no longer able to publish new apps.

Scripts used to create container and cause the issue

*Script used to create container*

                    New-BcContainer -accept_eula -accept_outdated -updateHosts -dns '8.8.8.8' `
                        -imageName $imageName `
                        -containerName $ContainerName `
                        -multitenant `
                        -enableTaskScheduler:$False `
                        -auth AAD -Credential $credential `
                        -authenticationEMail $adminEmail `
                        -memoryLimit $Memory `
                        -isolation $isolation `
                        -includeAL `
                        -assignPremiumPlan `
                        -alwaysPull `
                        -licenseFile $flfFilename `
                        -AadAppId $AADAppID `
                        -useSSL:$UseSSL `
                        -installCertificateOnHost:$UseSSL `
                        -runSandboxAsOnPrem:$runSandboxAsOnPrem `
                        -additionalParameters @("--storage-opt size=$StorageLimit", "--env AppIdUri=$appIdUri") `

*Script causing issue:*
Publish-BcContainerApp -containerName $ContainerName -tenant $TenantId -appFile $appFile -skipVerification -install -sync -upgrade:$Upgrade -scope Tenant

Full output of scripts

Output script while publishing app once issue has been encountered:
No matching apps to uninstall!
Pull Binaries is currently set to True.
Compilation skipped, binaries will be used...
Pulling iNECTA Artifact for:  YIBASE
Starting App blob file download...
INFO: Publishing C:\ProgramData\BcContainerHelper\Extensions\test\3aedd2cf-1c92-4ce9-8793-17b00d91e12c\22.YIBASE.app
INFO: Synchronizing YIBASE - Base App on tenant 50662
INFO: Installing YIBASE - Base App on tenant 50662
>> TerminatingError(): "The running command stopped because the preference variable "ErrorActionPreference" or common parameter is set to Stop: We can't save your changes right now, because the data is being updated in a transaction done by another session.

You'll have to wait until the other transaction has completed, which may take a while. Please try again later."
We can't save your changes right now, because the data is being updated in a transaction done by another session.

You'll have to wait until the other transaction has completed, which may take a while. Please try again later.

Exception Script Stack Trace:
at <ScriptBlock>, <No file>: line 78

PowerShell Call Stack:
at Invoke-ScriptInBcContainer, C:\Program Files\WindowsPowerShell\Modules\BcContainerHelper\5.0.3\ContainerHandling\Invoke-ScriptInNavContainer.ps1: line 71
at <ScriptBlock>, C:\Program Files\WindowsPowerShell\Modules\BcContainerHelper\5.0.3\AppHandling\Publish-NavContainerApp.ps1: line 299
at Publish-BcContainerApp, C:\Program Files\WindowsPowerShell\Modules\BcContainerHelper\5.0.3\AppHandling\Publish-NavContainerApp.ps1: line 146
at global:Install-App, C:\Users\inectasvcusr\Desktop\SCRIPTS\SIMPMgmt.ps1: line 3640
at <ScriptBlock>, <No file>: line 1
at <ScriptBlock>, <No file>: line 83
at <ScriptBlock>, <No file>: line 82
INFO: 
Container Free Physical Memory: 30.6Gb
INFO: 
Services in container test:
INFO: - MicrosoftDynamicsNavServer$BC is Running
INFO: - MSSQL$SQLEXPRESS is Running
INFO:
INFO: 
Relevant event log from container test:
INFO: - 20230603 07:17:14 - MicrosoftDynamicsNavServer$BC
INFO: 
  Server instance: BC
  Category: Sql
  ClientSessionId: 00000000-0000-0000-0000-000000000000
  ClientActivityId: 00000000-0000-0000-0000-000000000000
  ServerSessionUniqueId: 2330a793-2dac-43ca-b965-9ba6962cb7a6
  ServerActivityId: 68cdc251-022c-47d1-87e6-e0974993664c
  EventTime: 06/03/2023 11:17:14
  Message (NavCSideSQLLockTimeoutException): Exception happened during execution of a threshold action.
    Exception type: NavCSideSQLLockTimeoutException,
    Threshold tag: 000007L,
    Execution time over threshold: True,
    Execution time: 10012 ms,
    Threshold: 750 ms
    Message: Long running SQL statement
    Task ID: 2
    Connection ID: 5714
    SQL server session ID: 100
    Client Type: Background
    Database Server Name: LOCALHOST\SQLEXPRESS
    Database Name: CRONUS
    Current Company Name: 
    Statement: INSERT INTO [SQLDATABASE].[dbo].[Installed Application] ([Tenant ID], [Runtime Package ID], [Package ID]) VALUES (@0, @1, @2)

  RootException: NavCSideSQLLockTimeoutException
  Error Code:22926090
  We can't save your changes right now, because the data is being updated in a transaction done by another session.

  You'll have to wait until the other transaction has completed, which may take a while. Please try again later.
  ExceptionStackTrace:
     at Microsoft.Dynamics.Nav.Runtime.NavSqlConnection.CheckAndThrowTrapableErrors(Int32 errorNumber, Exception originalException, Boolean transactionNoLongerValid, Nullable`1 timeout, String commandText, NavSqlConnection connection, NavCancellationToken cancellationToken)
     at Microsoft.Dynamics.Nav.Runtime.NavSqlConnection.HandleInnerException(SqlExceptionAdapter exceptionAdapter, Boolean transactionNoLongerValid, Boolean isLastExceptionARollbackCause, String commandText, Nullable`1 timeout, NavCancellationToken cancellationToken)
     at Microsoft.Dynamics.Nav.Runtime.NavSqlConnection.MapException(SqlExceptionAdapter exceptionAdapter, String commandText, Boolean isRollbackAction, Nullable`1 timeout, NavCancellationToken cancellationToken)
     at Microsoft.Dynamics.Nav.Runtime.NavSqlConnection.<>c__DisplayClass133_0`1.<ExecuteFunction>b__0()
     at Microsoft.Dynamics.Nav.Types.NavThread.RunExternalAction[T](Func`1 action)
     at Microsoft.Dynamics.Nav.Runtime.NavSqlConnection.ExecuteFunctionWithTrace[T](EventTask task, Func`1 function, String commandText, SqlCommand sqlCommand, Boolean isAdoCommand, NavCancellationToken cancellationToken)
  CallerStackTrace:
     at Microsoft.Dynamics.Nav.Runtime.NavSqlConnection.FailedSqlOperationExceptionFilter(Exception e, EventTask task, String commandText, Int64 startMilliSeconds, Boolean& recursionDetected)
     at Microsoft.Dynamics.Nav.Runtime.NavSqlConnection.ExecuteFunctionWithTrace[T](EventTask task, Func`1 function, String commandText, SqlCommand sqlCommand, Boolean isAdoCommand, NavCancellationToken cancellationToken)
     at Microsoft.Dynamics.Nav.Runtime.NavSqlConnection.CheckAndThrowTrapableErrors(Int32 errorNumber, Exception originalException, Boolean transactionNoLongerValid, Nullable`1 timeout, String commandText, NavSqlConnection connection, NavCancellationToken cancellationToken)
     at Microsoft.Dynamics.Nav.Runtime.NavSqlConnection.HandleInnerException(SqlExceptionAdapter exceptionAdapter, Boolean transactionNoLongerValid, Boolean isLastExceptionARollbackCause, String commandText, Nullable`1 timeout, NavCancellationToken cancellationToken)
     at Microsoft.Dynamics.Nav.Runtime.NavSqlConnection.MapException(SqlExceptionAdapter exceptionAdapter, String commandText, Boolean isRollbackAction, Nullable`1 timeout, NavCancellationToken cancellationToken)
     at Microsoft.Dynamics.Nav.Runtime.NavSqlConnection.<>c__DisplayClass133_0`1.<ExecuteFunction>b__0()
     at Microsoft.Dynamics.Nav.Types.NavThread.RunExternalAction[T](Func`1 action)
     at Microsoft.Dynamics.Nav.Runtime.NavSqlConnection.ExecuteFunctionWithTrace[T](EventTask task, Func`1 function, String commandText, SqlCommand sqlCommand, Boolean isAdoCommand, NavCancellationToken cancellationToken)
     at Microsoft.Dynamics.Nav.Runtime.NavSqlCommand.ExecuteNonQueryImp(NavCancellationToken cancellationToken)
     at Microsoft.Dynamics.Nav.Runtime.Apps.InstalledApplicationStorage.<>c.<AddRecord>b__14_3(NavSqlCommand cmd)
     at Microsoft.Dynamics.Nav.Runtime.NavSqlConnection.ExecuteCommandAndCacheOnSuccess[T](NavSqlCommandCacheKey commandKey, Func`1 newCommandFunc, Func`2 executeFunc)
     at Microsoft.Dynamics.Nav.Runtime.Apps.InstalledApplicationStorage.AddRecord(PackageId appPackageId, RuntimePackageId runtimePackageId, String tenantId)
     at Microsoft.Dynamics.Nav.Runtime.NavAppInstallationManagement.InstallAppToApplicationDatabase(NavSqlConnectionScope connectionScope, String tenantId, INavAppMetadataReference app)
     at Microsoft.Dynamics.Nav.Runtime.Apps.NavAppInstaller.ExecuteAppDatabaseTransactions(IEnumerable`1 installationProcessors, Action`2 action)
     at Microsoft.Dynamics.Nav.Runtime.RetryManager.<>c__DisplayClass11_0.<PerformOperationWithRetries>b__0()
     at Microsoft.Dynamics.Nav.Runtime.RetryManager.PerformOperationWithRetries[T](Func`1 operation, Action resetAction, String operationName)
     at Microsoft.Dynamics.Nav.Runtime.RetryManager.PerformOperationWithRetries(Action operation, String operationName)
     at Microsoft.Dynamics.Nav.Runtime.Apps.NavAppInstaller.ExecuteAppDatabaseTransactionsWithRetries(NavTenant tenant, IEnumerable`1 installationProcessors, Action`2 action, Boolean install)
     at Microsoft.Dynamics.Nav.Runtime.Apps.NavAppInstaller.Install(NavSqlConnectionScope appDatabaseScope, NavSqlConnectionScope tenantDatabaseScope, NavSqlDatabaseLock tenantLock, NavAppInstallPreCheckHelper precheckResult, NavSession session, String name, NavTenant tenant, Boolean doNotLoadData, String activityId, Boolean enableDebugging, NavAppSyncMode syncMode, String origin)
     at Microsoft.Dynamics.Nav.Runtime.NavManagementTasks.<>c__DisplayClass31_1.<InstallNavApp>b__1(NavTenant tenant, NavSession session)
     at Microsoft.Dynamics.Nav.Runtime.NavTenant.Microsoft.Dynamics.Nav.Runtime.ITenantSessionHandler.RunTenantActionInSystemSessionWithoutTransaction(Action`2 action, Boolean throwExceptions, Boolean useCurrentCulture, LanguageSetting language, NavCancellationToken cancellationToken)
     at Microsoft.Dynamics.Nav.Runtime.NavManagementTasks.<>c__DisplayClass31_0.<InstallNavApp>b__0()
     at Microsoft.Dynamics.Nav.Runtime.NavManagementTasks.InstallNavApp(InstallNavAppArguments installNavAppArguments, Boolean async)
     at Microsoft.Dynamics.Nav.Service.NSAdminService.<>c__DisplayClass60_0`1.<RunActionOnRequestedTenant>b__0()
     at Microsoft.Dynamics.Nav.Runtime.Apps.NavAppDiagnosticSession.<>c__DisplayClass1_0`1.<SendTraceTagOnFailure>b__0()
     at Microsoft.Dynamics.Nav.Runtime.Apps.NavAppDiagnosticSession.SendTraceTagOnFailure(Action operation, String additionalInfo, Func`2 exceptionMap, String callerName)
     at Microsoft.Dynamics.Nav.Runtime.Apps.NavAppDiagnosticSession.SendTraceTagOnFailure[T](Func`1 operation, String additionalInfo, Func`2 exceptionMap, String callerName)
     at Microsoft.Dynamics.Nav.Service.NSAdminService.Microsoft.BusinessCentral.AdminApi.INCLAdminService.InstallNavApp(InstallNavAppArguments installNavAppArguments)
     at System.RuntimeMethodHandle.InvokeMethod(Object target, Span`1& arguments, Signature sig, Boolean constructor, Boolean wrapExceptions)
     at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)
     at CoreWCF.Dispatcher.InvokerUtil.CriticalHelper.<>c__DisplayClass3_0.<GenerateInvokeDelegate>b__0(Object target, Object[] inputs, Object[] outputs)
     at CoreWCF.Dispatcher.SyncMethodInvoker.InvokeAsync(Object instance, Object[] inputs)
     at Microsoft.Dynamics.Nav.Service.ServiceOperationInvoker.<>c__DisplayClass5_0.<Create>b__0(ServiceOperationContext context)
     at Microsoft.Dynamics.Nav.Service.ServiceOperationPipeline.AddToThreadSchedulerCombinator(ServiceOperationContext context, ServiceOperation innerOperation)
     at Microsoft.Dynamics.Nav.Service.ServiceOperationPipeline.ErrorMappingCombinator(ServiceOperationContext context, ServiceOperation innerOperation, Boolean useCoreWcfFaultException)
     at Microsoft.Dynamics.Nav.Service.ServiceOperationPipeline.PartnerTelemetryPermissionErrorCombinator(ServiceOperationContext context, ServiceOperation innerOperation)
     at Microsoft.Dynamics.Nav.Service.ServiceOperationPipeline.PushPopCombinator(ServiceOperationContext context, ServiceOperation innerOperation, Boolean useCoreWcfFaultException)
     at Microsoft.Dynamics.Nav.Service.ServiceOperationPipeline.TelemetryCombinator(Category telemetryCategory, Verbosity telemetryVerbosity, ServiceOperationContext context, ServiceOperation innerOperation)
     at Microsoft.Dynamics.Nav.Service.ServiceOperationTracer.TraceScopeCombinator(Category telemetryCategory, ServiceOperationContext context, ServiceOperation innerOperation)
     at Microsoft.Dynamics.Nav.Service.ServiceOperationPipeline.<>c__DisplayClass7_0.<PerformanceCounterCombinator>b__0()
     at Microsoft.Dynamics.Nav.Runtime.NavPerformanceCounterSetter.UpdatePerformanceCountersWithAverageServiceOperationAction(Action action, NavSession session)
     at Microsoft.Dynamics.Nav.Service.ServiceOperationPipeline.PerformanceCounterCombinator(ServiceOperationContext context, ServiceOperation innerOperation)
     at Microsoft.Dynamics.Nav.Service.ServiceOperationPipeline.InitClientTelemetryIdsCombinator(ServiceOperationContext context, ServiceOperation innerOperation)
     at Microsoft.Dynamics.Nav.Service.ServiceOperationPipeline.TlsClearCombinator(ServiceOperationContext context, ServiceOperation innerOperation)
     at Microsoft.Dynamics.Nav.Service.ServiceOperationInvoker.InvokeAsync(Object instance, Object[] inputs)
     at CoreWCF.Dispatcher.DispatchOperationRuntime.<>c__DisplayClass68_0.<<InvokeAsync>b__0>d.MoveNext()
     at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
     at CoreWCF.Dispatcher.DispatchOperationRuntime.<>c__DisplayClass68_0.<InvokeAsync>b__0()
     at CoreWCF.Dispatcher.SecurityImpersonationBehavior.RunImpersonated[T](MessageRpc rpc, Func`1 func)
     at CoreWCF.Dispatcher.DispatchOperationRuntime.InvokeAsync(MessageRpc rpc)
     at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
     at CoreWCF.Dispatcher.DispatchOperationRuntime.InvokeAsync(MessageRpc rpc)
     at CoreWCF.Dispatcher.ImmutableDispatchRuntime.ProcessMessageAsync(MessageRpc rpc)
     at System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(Thread threadPoolThread, ExecutionContext executionContext, ContextCallback callback, Object state)
     at System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1.AsyncStateMachineBox`1.MoveNext(Thread threadPoolThread)
     at System.Threading.ThreadPoolWorkQueue.Dispatch()
     at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()

  ProcessId: 2752
  Tag: 000007T
  ThreadId: 138
  CounterInformation: 
  CustomParameters: {
  }
  GatewayCorrelationId:
PS>TerminatingError(): "We can't save your changes right now, because the data is being updated in a transaction done by another session.

You'll have to wait until the other transaction has completed, which may take a while. Please try again later."
>> TerminatingError(): "We can't save your changes right now, because the data is being updated in a transaction done by another session.

You'll have to wait until the other transaction has completed, which may take a while. Please try again later."
Publish-BcContainerApp Telemetry Correlation Id: 31a6da48-4df8-4771-9dc0-55f85b9b26af
PS>TerminatingError(): "We can't save your changes right now, because the data is being updated in a transaction done by another session.

You'll have to wait until the other transaction has completed, which may take a while. Please try again later."
Install-App processing time :  YIBASE  00:02:54.5603809

Screenshots If applicable, add screenshots to help explain your problem. N/A Additional context

freddydk commented 1 year ago

Have never seen this before. Based on the output, it seems like something else have a lock on the table: [SQLDATABASE].[dbo].[Installed Application] and your install app fails. The challenge would be to figure out who and what is locking that table - maybe you can connect with SSMS and see? I don't know, haven't tried this