SqlAgDatabase: Timeout elapsed during restore on secondary

[Teutenberg]

Details of the scenario you tried and the problem that is occurring

Trying to add 150GB database to SQL AG.

Verbose logs showing the problem

Job {1849F2C3-7124-11E9-80ED-00505691B803} :
Message The operation on the database 'SP_CONTENT_MCF_PROD_T1_5' failed with the following errors: System.Exception: System.InvalidOperationException: Executing non-query failed on database 'master'. ---> System.Management.Automation.MethodInvocationException: Exception calling "ExecuteNonQuery" with "1" argument(s): "ExecuteNonQuery failed for Database 'master'. " ---> Microsoft.SqlServer.Management.Smo.FailedOperationException: ExecuteNonQuery failed for Database 'master'. ---> Microsoft.SqlServer.Management.Common.ExecutionFailureException: An exception occurred while executing a Transact-SQL statement or batch. ---> System.Data.SqlClient.SqlException: Execution Timeout Expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
The backup or restore was aborted. ---> System.ComponentModel.Win32Exception: The wait operation timed out
--- End of inner exception stack trace ---
at Microsoft.SqlServer.Management.Common.ConnectionManager.ExecuteTSql(ExecuteTSqlAction action, Object execObject, DataSet fillDataSet, Boolean catchException)
at Microsoft.SqlServer.Management.Common.ServerConnection.ExecuteNonQuery(String sqlCommand, ExecutionTypes executionType, Boolean retry)
--- End of inner exception stack trace ---
at Microsoft.SqlServer.Management.Common.ServerConnection.ExecuteNonQuery(String sqlCommand, ExecutionTypes executionType, Boolean retry)
at Microsoft.SqlServer.Management.Common.ServerConnection.ExecuteNonQuery(StringCollection sqlCommands, ExecutionTypes executionType, Boolean retry)
at Microsoft.SqlServer.Management.Smo.ExecutionManager.ExecuteNonQuery(StringCollection queries, ExecutionTypes executionType)
at Microsoft.SqlServer.Management.Smo.Database.ExecuteNonQuery(StringCollection sqlCommands, ExecutionTypes executionType)
--- End of inner exception stack trace ---
at Microsoft.SqlServer.Management.Smo.Database.ExecuteNonQuery(StringCollection sqlCommands, ExecutionTypes executionType)
at CallSite.Target(Closure , CallSite , Object , String )
--- End of inner exception stack trace ---
at System.Management.Automation.ExceptionHandlingOps.CheckActionPreference(FunctionContext funcContext, Exception exception)
at System.Management.Automation.Interpreter.ActionCallInstruction2.Run(InterpretedFrame frame) at System.Management.Automation.Interpreter.EnterTryCatchFinallyInstruction.Run(InterpretedFrame frame) at System.Management.Automation.Interpreter.EnterTryCatchFinallyInstruction.Run(InterpretedFrame frame) --- End of inner exception stack trace ---. HResult -2146233087 StackTrack at System.Management.Automation.Runspaces.AsyncResult.EndInvoke() at System.Management.Automation.PowerShell.CoreInvokeRemoteHelper[TInput,TOutput](PSDataCollection1 input, PSDataCollection1 output, PSInvocationSettings settings) at System.Management.Automation.PowerShell.CoreInvoke[TInput,TOutput](PSDataCollection1 input, PSDataCollection1 output, PSInvocationSettings settings) at System.Management.Automation.PowerShell.Invoke(IEnumerable input, PSInvocationSettings settings) at Microsoft.PowerShell.DesiredStateConfiguration.Internal.ResourceProviderAdapter.ExecuteCommand(PowerShell powerShell, ResourceModuleInfo resInfo, String operationCmd, List1 acceptedProperties, CimInstance nonResourcePropeties, CimInstance resourceConfiguration, LCMDebugMode debugMode, PSInvocationSettings pSInvocationSettings, UInt32& resultStatusHandle, Collection`1& result, ErrorRecord& errorRecord, PSModuleInfo localRunSpaceModuleInfo)

Suggested solution to the issue

The DSC configuration that is used to reproduce the issue (as detailed as possible)

$Params = @{
            AvailabilityGroupName   = $SqlAgName
            BackupPath              = $SqlShareUnc
            DatabaseName            = $SqlDatabases
            InstanceName            = $Primary.InstanceName
            ServerName              = $Primary.ComputerNamePhysicalNetBIOS
            MatchDatabaseOwner      = $true
            Force                   = $false
            Ensure                  = 'Present'
            PsDscRunAsCredential    = $SqlAdministratorCredential
        }

        if (Invoke-DscResource -ModuleName SqlServerDsc -Name SqlAGDatabase -Property $Params -Method Test) {
            Write-Output 'Skipping SqlAGDatabase - Already Configured...'	
        }
        else {
            Write-Output 'Configuring SqlAGDatabase...'
	        Invoke-DscResource -ModuleName SqlServerDsc -Name SqlAGDatabase -Property $Params -Method Set
        }

SQL Server edition and version the target node is running

Microsoft SQL Server 2014 (SP3-CU3) (KB4491539) - 12.0.6259.0 (X64) Apr 1 2019 22:19:54 Copyright (c) Microsoft Corporation Enterprise Edition (64-bit) on Windows NT 6.3 (Build 9600: ) (Hypervisor)

SQL Server PowerShell modules present on the target node

Name Version Path

---

SqlServer 21.1.18102 C:\Program Files\WindowsPowerShell\Modules\SqlServer\SqlServer.psd1
SQLASCMDLETS 1.0 C:\Program Files (x86)\Microsoft SQL Server\120\Tools\PowerShell\Modules\SQLASCMDLETS\SQLASCMDLETS.psd1
SQLPS 1.0 C:\Program Files (x86)\Microsoft SQL Server\120\Tools\PowerShell\Modules\SQLPS\SQLPS.psd1

The operating system the target node is running

OsName : Microsoft Windows Server 2012 R2 Standard
OsOperatingSystemSKU : StandardServerEdition
OsArchitecture : 64-bit
WindowsBuildLabEx : 9600.19321.amd64fre.winblue_ltsb_escrow.190313-1806
OsLanguage : en-US
OsMuiLanguages : {en-US}

Version and build of PowerShell the target node is running

Name Value

---

PSVersion 5.1.14409.1018
PSEdition Desktop
PSCompatibleVersions {1.0, 2.0, 3.0, 4.0...}
BuildVersion 10.0.14409.1018
CLRVersion 4.0.30319.42000
WSManStackVersion 3.0
PSRemotingProtocolVersion 2.3
SerializationVersion 1.1.0.1

Version of the DSC module that was used ('dev' if using current dev branch)

Name Version Path

---

SqlServerDsc 12.4.0.0 C:\Program Files\WindowsPowerShell\Modules\SqlServerDsc\SqlServerDsc.psd1

[Teutenberg]

I think the issue is with Connect-Sql smo object not having a long enough statement timeout. Perhaps adding a new parameter to pass thru a user specified timeout value. Otherwise any database restore taking longer than 10mins will be aborted.

https://docs.microsoft.com/en-us/dotnet/api/microsoft.sqlserver.management.common.serverconnection.statementtimeout?view=sql-smo-140.17283.0#Microsoft_SqlServer_Management_Common_ServerConnection_StatementTimeout

[Teutenberg]

Commented out Invoke-Query and replaced with Invoke-Sqlcmd with max QueryTimeout set. Restores are working now.

Line 532:

# Restore the database
                        #Invoke-Query -SQLServer $currentAvailabilityGroupReplicaServerObject.NetName -SQLInstanceName $currentAvailabilityGroupReplicaServerObject.ServiceName -Database master -Query $restoreDatabaseQueryString
                        #Invoke-Query -SQLServer $currentAvailabilityGroupReplicaServerObject.NetName -SQLInstanceName $currentAvailabilityGroupReplicaServerObject.ServiceName -Database master -Query $restoreLogQueryString

                        $MyServerInstance = Join-Path $currentAvailabilityGroupReplicaServerObject.NetName $currentAvailabilityGroupReplicaServerObject.ServiceName 
                        Invoke-Sqlcmd -ServerInstance $MyServerInstance -Database master -Query $restoreDatabaseQueryString -QueryTimeout 65535
                        Invoke-Sqlcmd -ServerInstance $MyServerInstance -Database master -Query $restoreLogQueryString -QueryTimeout 65535

[johlju]

Sounds like there are two options.

1. Adding a Timeout parameter to both the resource and to the helper function Invoke-Query that sets the Statement timeout.
2. Change Invoke-Query with Invoke-Sqlcmd (and handle any errors thrown correctly).

I think we moved away from Invoke-Sqlcmd for a reason, or maybe that was for something else 🤔