SQL Agent Powershell script not erroring as expected

Question

SQL Agent Powershell script not erroring as expected

Nathan Heaivilin 20

All,

I know that this is a common questions, but the 'fixes' I'm seeing in those questions aren't resolving my issue. The code below is being written to take backups of SSAS Cubes using the SQLServer PS Module.

The basic process is that it pulls the servers, backup location, and backup retention from a JSON file, loops through each server and then takes backups, removes old backups, etc. Think a poor mans version of Ola Hallengren scripts.

My issue is that the error handling I've tried putting in doesn't work correctly. Specifically, it seems to always be returning an exit code of 0 for success, than an exit code of 1. Yet, when I run it in a PS window, I get the results I'm expecting.

Things I've tried:

Running as both PowerShell and CMDExec mode in the SQL Agent Job.
Throw vs Write-error
With and without specifying exit code
Various methods of try/catch, try/catch/finally, moving exit logic to END block, etc.

I'm at a loss as to why I'm not getting failures on the SQL Server Agent based upon the code below.

powershell.exe 'D:\dba\dba - SSAS - Take Backups\Backup_SSAS_Databases.ps1'

[CmdletBinding()]
param ()

BEGIN{
    Import-Module SQLServer

    $ErrorActionPreference = "Stop"

    [boolean]$ErrorOccurred = $false
    [boolean]$ExitWhenFinished = $true
    [string]$LogFileName = "SSAS_Backup_log_$(GET-DATE -Format 'yyyyMMdd_HHmmss').txt"
    [string]$FileNameTemplate = "<ServerName>_<DBName>_$(get-date -Format 'yyyyMMdd_HHmmss').abf"
    [string]$ConfigFile = $MyInvocation.MyCommand.Source.Replace($MyInvocation.MyCommand.Name, 'SSAS_Config.json')

    if ($LogPath)
        {[String]$LogFile = "$LogPath\$LogFileName"}
    else 
        {[String]$LogFile = $MyInvocation.MyCommand.Source.Replace($MyInvocation.MyCommand.Name, $LogFileName)  }
    function Write-Log {
        [CmdletBinding()]
        param(
            [Parameter()]
            [ValidateNotNullOrEmpty()]
            [string]$Message,
     
            [Parameter()]
            [ValidateNotNullOrEmpty()]
            [ValidateSet('INFO','WARN','EROR')]
            [string]$Severity = 'INFO',

            [Parameter()]
            [ValidateNotNullOrEmpty()]
            [string]$Directory
        )
        [pscustomobject]@{
            Time = "[$(Get-Date -f "MM/dd/yyyy HH:mm:ss")]"
            Severity = "[$Severity]"
            Message = $Message
        } | Export-Csv -Path "$Directory" -Append -NoTypeInformation -Delimiter "`t"
    }

    Write-Log -Message "Let the games begin." -Severity INFO -Directory $LogFile
}
PROCESS
{
    try {
        ## Read the config file to capture the required server information.
        $SSASConfigInfo = (Get-Content -path $ConfigFile | Out-String | ConvertFrom-Json)     
        Write-Log -Message "Config File: $ConfigFile" -Severity INFO -Directory $LogFile
        Write-Log -Message "Records Read : $($SSASConfigInfo.Count)" -Severity INFO -Directory $LogFile
        Write-Log -Message "Exit when finished : $ExitWhenFinished)" -Severity INFO -Directory $LogFile
        

        ## Loop through each server
        foreach ($ServerInfo in $SSASConfigInfo)
        {
            [string]$Server = $ServerInfo.SSAS_Server
            [string]$BackupFolder = $ServerInfo.BackupFolder
            [int]$RetentionInHours = $ServerInfo.Retention

            Write-Log -Message "Server:  $Server" -Severity INFO -Directory $LogFile
            Write-Log -Message "BackupPath: $BackupFolder" -Severity INFO -Directory $LogFile
            Write-Log -Message "Retention: $RetentionInHours hours."  -Severity INFO -Directory $LogFile
            Write-Log -Message "Error Occurred : $ErrorOccurred"   -Severity INFO -Directory $LogFile

            Write-Log "Starting backups of [$Server]."  -Severity INFO -Directory $LogFile
            ## Let's get the db/cube information from the SSAS Server
            try
            {
                [xml]$AllDBInfo = Invoke-ASCmd -Server $Server -Query  "<Discover xmlns='urn:schemas-microsoft-com:xml-analysis'><RequestType>DBSCHEMA_CATALOGS</RequestType><Restrictions /><Properties /></Discover>" -ErrorAction Stop
                $DBList = $AllDBInfo.DiscoverResponse.return.root.row.Catalog_Name
                Write-Log "DB count retrieved = $($DBList.Count)"  -Severity INFO -Directory $LogFile
            }
            catch {
                $ErrorOccurred = $true
                Write-Log "$($_.Exception.Message)" -Severity EROR -Directory $LogFile
                continue
            }
           
            foreach ($db in $DBList)
            {
                ## Let's set our vairables 
                Write-Log "`n"  -Severity INFO -Directory $LogFile
                Write-Log "Starting backup of [$db]."  -Severity INFO -Directory $LogFile
                $BackupFileName = $FileNameTemplate.Replace('<ServerName>', $Server)
                $BackupFileName = $BackupFileName.Replace('<DBName>', $DB)

                $BackupPath = Join-Path -Path $BackupFolder -ChildPath $Server
                $BackupPath = Join-Path -Path $BackupPath -ChildPath $db
                $BackupPath = Join-Path -Path $BackupPath -ChildPath 'SSASBackup'

                $FullBackupName = join-path -path $BackupPath -childpath $BackupFileName
                Write-Log "Backup Path: $BackupPath"  -Severity INFO -Directory $LogFile
                Write-Log "Backup Name: $BackupFileName"  -Severity INFO -Directory $LogFile
                Write-Log "Full Path  : $FullBackupName" -Severity INFO -Directory $LogFile
                
                if (test-path -path $BackupPath)
                    {Write-Log "BackupPath validated successfully."-Severity INFO -Directory $LogFile}
                else
                    {
                        Write-Log "Created the backup path: '$BackupPath'"-Severity INFO -Directory $LogFile
                        New-Item -Path $BackupPath -ItemType Directory | out-null
                    }
                
                <##############################################     Backup SSAS Cube/DB #########################################>
                try
                {
                    write-log "Backup Command:  Backup-ASDatabase -Server $Server -BackupFile $FullBackupName -Name $db -AllowOverwrite -ApplyCompression -Verbose" -Severity INFO -Directory $LogFile
                    Write-Log "Backup Start" -Severity INFO -Directory $LogFile
                    measure-command {Backup-ASDatabase -Server $Server -BackupFile $FullBackupName -Name $db -AllowOverwrite -ApplyCompression -ErrorAction Stop} -OutVariable duration | out-null
                    Write-Log "Backup Command Completed. "  -Severity INFO -Directory $LogFile
                    Write-Log "Backup Duration: $($duration.Hours) hour(s) $($duration.Minutes) minute(s) $($duration.Seconds) seconds" -Severity INFO -Directory $LogFile
                    write-log "Results: Success." -Severity INFO -Directory $LogFile
                    
                }
                catch
                {
                    ## write the error to the log file and then continue to the next cube.  Note this will also bypass the delete of the older backup, which is intended.
                    Write-Log -Message "$($Error.exception.message)" -Severity EROR -Directory $LogFile
                    Write-Log "Backup Command Completed"  -Severity INFO -Directory $LogFile
                    Write-Log "Backup Duration: $($duration.Hours) hour(s) $($duration.Minutes) minute(s) $($duration.Seconds) seconds" -Severity INFO -Directory $LogFile
                    Write-Log -Message "Result: Fail" -Severity INFO -Directory $LogFile
                    $ErrorOccurred = $true
                    continue
                }
        
                ## Let's remove older backups
                if ($RetentionInHours -gt 0)
                    {$RemoveFilesOlderThan = (get-date).AddHours($Retentioninhours * -1)}
                else 
                    {$RemoveFilesOlderThan = (get-date).AddHours($Retentioninhours)}
        
                ## Get file list
                $filesToRemove = get-childitem -Path $BackupPath | Where-Object {$_.extension -ieq '.abf' -and $_.LastWriteTime -le $RemoveFilesOlderThan}

                try 
                    {$filesToRemove  |  Remove-Item -ErrorAction Stop }
                catch {
                    ## Write the error but contiue. Shouldn't stop taking new backups if we can't remove the old ones.  
                    Write-Log -Message "$($Error.exception.message)" -Severity EROR -Directory $LogFile
                    $ErrorOccurred = $true
                    continue
                }     
                
                Write-Log "Server: [$server] completed.`n"  -Severity INFO -Directory $LogFile
            }
        }
    }
    catch {
        Write-Log -Message 'Primary TRY/CATCH triggered.  Error below.' -Severity EROR -Directory $LogFile
        Write-Log -Message "$($Error.exception.message)" -Severity EROR -Directory $LogFile
        Write-Log "Server [$Server] completed. `n"  -Severity INFO -Directory $LogFile
        $ErrorOccurred = $true
    }
    finally {
    
        if ($ExitWhenFinished -and $ErrorOccurred) 
            {
                Write-Error  -Message "Error has occurred.  Log at $LogFile"
                #throw "Error has occurred.  Log at $LogFile"
                [System.Environment]::Exit(1)
            }
        elseif ( $ExitWhenFinished) 
            {
                Write-Host 'Process completed Successfully.'
                [System.Environment]::Exit(0)
            }
        else {
            Write-Host 'The process completed, but unable to determine if successful or not.  This is basically a catch all statement.  Review logs and code logic to figure out how we got here.'
        }
    }
}
END{
    Write-Verbose 'Got to the END segment of the code.'     
}

Accepted answer

2 additional answers

Your answer

Answer 1

Whether or not it fixes the problem, try the code below. It's basically your code minus the four scriptblocks (begin, process, finally, and end). Because your script isn't accepting pipelined input there's no need for a PROCESS block, the BEGIN block code can just be part of script body (it will still execute just once before the code in what was the PROCESS block). The code in the scriptblock FINALLY will run once the main "foreach" finishes. Removing those scriptblocks makes error handling clearer; there's no longer nested try/catch blocks.

FWIW, there's an undefined variable on line 14 ($logfile). It won't disrupt anything unless you add "Set-PSDebug -Strict" in the script (which you should do while you're developing the code). I eliminated a pipeline (or two) in your code, and I replaced the variable interpolation inside double-quoted strings with PowerShell format operators ("-f") mostly because it's cleaner and also eliminates any quoting errors. I also added some error checking in the code that processed the config file.

NOTE: I have no way to check the execution of the code -- I have no SQL server.

[CmdletBinding()]
param ()
# BEGIN
    Import-Module SQLServer     # if Import-Module fails shouldn't the script terminate????

    $ErrorActionPreference = "Stop"

    [boolean]$ErrorOccurred     = $false
    [boolean]$ExitWhenFinished  = $true
    [string]$LogFileName        = "SSAS_Backup_log_{0}.txt" -f (GET-DATE -Format 'yyyyMMdd_HHmmss')
    [string]$FileNameTemplate   = "<ServerName>_<DBName>_{0}.abf" -f (get-date -Format 'yyyyMMdd_HHmmss')
    [string]$ConfigFile         = $MyInvocation.MyCommand.Source.Replace($MyInvocation.MyCommand.Name, 'SSAS_Config.json')

    if ($LogPath){      # $LogPath is undefined! If "Set-PSDebug -Strict" was used the script would throw an error (undefined variable)
        [String]$LogFile = "{0}\{1}" -f $LogPath, $LogFileName
    }
    else {
        [String]$LogFile = $MyInvocation.MyCommand.Source.Replace($MyInvocation.MyCommand.Name, $LogFileName)  
    }
    function Write-Log {
        [CmdletBinding()]
        param(
            [Parameter()]
            [ValidateNotNullOrEmpty()]
            [string]$Message,
     
            [Parameter()]
            [ValidateNotNullOrEmpty()]
            [ValidateSet('INFO','WARN','EROR')]
            [string]$Severity = 'INFO',

            [Parameter()]
            [ValidateNotNullOrEmpty()]
            [string]$Directory
        )
        [pscustomobject]@{
            Time = "[$(Get-Date -f "MM/dd/yyyy HH:mm:ss")]"
            Severity = "[$Severity]"
            Message = $Message
        } | Export-Csv -Path "$Directory" -Append -NoTypeInformation -Delimiter "`t"
    }   # end Write-Log function

    Write-Log -Message "Let the games begin." -Severity INFO -Directory $LogFile
#PROCESS
    try {
        ## Read the config file to capture the required server information.
        $SSASConfigInfo = (Get-Content -path $ConfigFile | Out-String | ConvertFrom-Json)
        if ($SSASConfigInfo.Count -lt 1){
            Throw "Empty config file"
        }
        Write-Log -Message "Config File: $ConfigFile" -Severity INFO -Directory $LogFile
        Write-Log -Message "Records Read : $($SSASConfigInfo.Count)" -Severity INFO -Directory $LogFile
        Write-Log -Message "Exit when finished : $ExitWhenFinished)" -Severity INFO -Directory $LogFile
    }
    catch{
        Write-Log -Message "Failed to process configuration file [$ConfigFile]" -Severity "EROR" -Directory $LogFile
        $ErrorOccurred = $true
        Exit 1
    }

    ## Loop through each server
    foreach ($ServerInfo in $SSASConfigInfo)
    {
        [string]$Server = $ServerInfo.SSAS_Server
        [string]$BackupFolder = $ServerInfo.BackupFolder
        [int]$RetentionInHours = $ServerInfo.Retention

        Write-Log -Message "Server:  $Server" -Severity INFO -Directory $LogFile
        Write-Log -Message "BackupPath: $BackupFolder" -Severity INFO -Directory $LogFile
        Write-Log -Message "Retention: $RetentionInHours hours."  -Severity INFO -Directory $LogFile
        Write-Log -Message "Error Occurred : $ErrorOccurred"   -Severity INFO -Directory $LogFile

        Write-Log "Starting backups of [$Server]."  -Severity INFO -Directory $LogFile
        ## Let's get the db/cube information from the SSAS Server
        try {
            $query = "<Discover xmlns='urn:schemas-microsoft-com:xml-analysis'><RequestType>DBSCHEMA_CATALOGS</RequestType><Restrictions /><Properties /></Discover>"
            [xml]$AllDBInfo = Invoke-ASCmd -Server $Server -Query $query -ErrorAction Stop
            $DBList = $AllDBInfo.DiscoverResponse.return.root.row.Catalog_Name
            Write-Log "DB count retrieved = $($DBList.Count)"  -Severity INFO -Directory $LogFile
        }
        catch {
            $ErrorOccurred = $true
            Write-Log "$($_.Exception.Message)" -Severity EROR -Directory $LogFile
            continue    # foreach ($ServerInfo in $SSASConfigInfo)
        }
           
        foreach ($db in $DBList){
            ## Let's set our vairables 
            Write-Log "`n"  -Severity INFO -Directory $LogFile
            Write-Log "Starting backup of [$db]."  -Severity INFO -Directory $LogFile
            $BackupFileName = $FileNameTemplate.Replace('<ServerName>', $Server)
            $BackupFileName = $BackupFileName.Replace('<DBName>', $DB)

            $BackupPath = Join-Path -Path $BackupFolder -ChildPath $Server
            $BackupPath = Join-Path -Path $BackupPath -ChildPath $db
            $BackupPath = Join-Path -Path $BackupPath -ChildPath 'SSASBackup'

            $FullBackupName = join-path -path $BackupPath -childpath $BackupFileName
            Write-Log "Backup Path: $BackupPath"  -Severity INFO -Directory $LogFile
            Write-Log "Backup Name: $BackupFileName"  -Severity INFO -Directory $LogFile
            Write-Log "Full Path  : $FullBackupName" -Severity INFO -Directory $LogFile
                
            if (test-path -path $BackupPath){
                Write-Log "BackupPath validated successfully."-Severity INFO -Directory $LogFile
            }
            else{
                Write-Log "Created the backup path: '$BackupPath'"-Severity INFO -Directory $LogFile
                New-Item -Path $BackupPath -ItemType Directory | out-null
            }
                
            <##############################################     Backup SSAS Cube/DB #########################################>
            try {
                write-log "Backup Command:  Backup-ASDatabase -Server $Server -BackupFile $FullBackupName -Name $db -AllowOverwrite -ApplyCompression -Verbose" -Severity INFO -Directory $LogFile
                Write-Log "Backup Start" -Severity INFO -Directory $LogFile
                measure-command {
                        Backup-ASDatabase -Server $Server -BackupFile $FullBackupName -Name $db -AllowOverwrite -ApplyCompression -ErrorAction Stop
                        } -OutVariable duration | out-null
                Write-Log "Backup Command Completed. "  -Severity INFO -Directory $LogFile
                Write-Log "Backup Duration: $($duration.Hours) hour(s) $($duration.Minutes) minute(s) $($duration.Seconds) seconds" -Severity INFO -Directory $LogFile
                write-log "Results: Success." -Severity INFO -Directory $LogFile
            }
            catch {
                ## write the error to the log file and then continue to the next cube.  Note this will also bypass the delete of the older backup, which is intended.
                Write-Log -Message "$($Error.exception.message)" -Severity EROR -Directory $LogFile
                Write-Log "Backup Command Completed"  -Severity INFO -Directory $LogFile
                Write-Log "Backup Duration: $($duration.Hours) hour(s) $($duration.Minutes) minute(s) $($duration.Seconds) seconds" -Severity INFO -Directory $LogFile
                Write-Log -Message "Result: Fail" -Severity INFO -Directory $LogFile
                $ErrorOccurred = $true
                continue    # foreach ($db in $DBList)
            }
        
            ## Let's remove older backups
            if ($RetentionInHours -gt 0){
                $Retentioninhours *= -1
            }
            $RemoveFilesOlderThan = (get-date).AddHours($Retentioninhours)
        
            ## Get file list
            $filesToRemove = (get-childitem -Path $BackupPath | 
                                Where-Object {$_.extension -ieq '.abf' -and $_.LastWriteTime -le $RemoveFilesOlderThan}).FullName

            try {
                Remove-Item -Path $filesToRemove -ErrorAction Stop 
            }
            catch {
                ## Write the error but contiue. Shouldn't stop taking new backups if we can't remove the old ones.  
                Write-Log -Message "$($Error.exception.message)" -Severity EROR -Directory $LogFile
                $ErrorOccurred = $true
                continue    # foreach ($db in $DBList)
            }     
            Write-Log "Server: [$server] completed.`n"  -Severity INFO -Directory $LogFile
        }   # end foreach ($db in $DBList)
    }    # end foreach ($ServerInfo in $SSASConfigInfo)
# FINALLY
    if ($ExitWhenFinished -and $ErrorOccurred){
        Write-Error  -Message "Error has occurred.  Log at $LogFile"
        #throw "Error has occurred.  Log at $LogFile"
        Exit 1
    }
    elseif ($ExitWhenFinished){
        Write-Host 'Process completed Successfully.'
        Exit 0
    }
    else {  # $ExitWhenFinished is not $true
        Write-Host 'The process completed, but unable to determine if successful or not.  This is basically a catch all statement.  Review logs and code logic to figure out how we got here.'
    }

#END
    Write-Verbose 'Got to the END segment of the code.'
    # at this point the script will exit without setting exit code
    # even though $ExitWhenFinished implies the script should continue

Nathan Heaivilin 20 Reputation points

2024-08-12T21:09:48.3266667+00:00

This pretty much got me there. Couple of small changes:

First, due to the ErrorActionPreference at the top, I needed to do the following in the finally statement so that it would make it to the EXIT portion. Without it, it would exit, but not return an actual exit code.

if ($ExitWhenFinished -and $ErrorOccurred){ Write-Error -Message "Error has occurred. Log at $LogFile" -ErrorAction Continue Exit 1 }

After that, I needed to change how I was calling the PowerShell.exe from the SQL Agent Job. Unsure why this matter. Can only guess it has to do with the need for quotes around the folder path.....

powershell.exe "Set-Location 'D:\dba\dba - SSAS - Take Backups\'; .\Backup_SSAS_Databases.ps1;"

Would love to know if my guess is correct.
Rich Matheisen 47,686 Reputation points

2024-08-13T02:24:37.4266667+00:00

Without the protective single-quotes the path would be just "D:\dba\dba" (i.e., up to the 1st space). The rest of the line would be seen as positional parameters of Set-Location. E.g., "-", "SSAS", "-", "Take", and "Backups". The only positional parameter for that cmdlet is "-Path" at position 0.

The result would be an error stating that no positional parameter could be found that takes the argument "-".

Answer 2

Erick Moreno 330

Please try changing the scope for your $ErrorActionPreference variable, scope changes a bit when calling the script file. Don't forget to change it back at the end of the script.

$global:ErrorActionPreference = 'Stop'

Nathan Heaivilin 20 Reputation points

2024-08-07T20:06:23.14+00:00

No change to behavior by adding this.

Answer 3

Rich Matheisen 47,686

What is the intention of using [System.Environment]::Exit(0) (or 1)? That kills the entire PowerShell process. Using PowerShells' "Exit 0" (or 1) just exits the script or function.

If you add -Verbose to the parameters when starting the script, do you see the 'Got to the END segment of the code.'

Nathan Heaivilin 20 Reputation points

2024-08-07T20:02:55.74+00:00
The [System.Environment]::Exit() was the last testing iteration. I tried to use just EXIT and it didn't work either.

No, it doesn't get to that statement when I use -verbose.

I updated the 'finally' block to look like below, and it returns the quoted output below it. I'm clearly getting into the block as expected.

However, when I use the $LASTEXITCODE command from the PS Cmd Window, it doesn't return anything. Almost like the EXIT command isn't getting hit.

finally { Write-Host "Error Occurred = $ErrorOccurred" if ($ErrorOccurred) { write-host 'Got inside the error block' Write-Verbose 'Yes, there is an error.' Write-Error -Message "Error has occurred. Log at $LogFile" #throw "Error has occurred. Log at $LogFile" #[System.Environment]::Exit(1) EXIT 1 } else { Write-Host 'Process completed Successfully.' Write-Verbose 'Nope, these are not the errors you are looking for.' #[System.Environment]::Exit(0) EXIT 0 } }

I get the following output when I run from a PS Window.

Error Occurred = True
Got inside the error block
VERBOSE: Yes, there is an error.
D:\dba\dba - SSAS - Take Backups\Backup_SSAS_Databases.ps1 : Error has occurred. Log at D:\dba\dba - SSAS - Take Backups\SSAS_Backup_log_20240807_145616.txt
At line:1 char:1 + & 'D:\dba\dba - SSAS - Take Backups\Backup_SSAS_Databases.ps1' -Verb ... + ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + CategoryInfo : NotSpecified: (:) [Write-Error], WriteErrorException + FullyQualifiedErrorId : Microsoft.PowerShell.Commands.WriteErrorException,Backup_SSAS_Databases.ps1

Share via

SQL Agent Powershell script not erroring as expected

2 additional answers

Your answer