Logging fixes

backupmult.ps1

@@ -167,20 +167,49 @@ EXECUTE [dbo].[DatabaseBackup]
 Write-Log "SQL Query: $query"
 
 # Function to execute backup job with message capture
-function Start-BackupJob($jobId, $sqlInstance, $query, $baseLogFile) {    
+function Start-BackupJob {
+    param(
+        [int]$jobId,
+        [string]$sqlInstance,
+        [string]$query,
+        [string]$baseLogFile
+    )    
     $scriptBlock = {
         param($JobId, $SqlInstance, $Query, $BaseLogFile)
         
-        # Create job-specific log file path
-        $jobLogFile = $BaseLogFile -replace '\.log$', "-job$JobId.log"
+        # Debug the base log file parameter
+        Write-Output "DEBUG: BaseLogFile parameter = '$BaseLogFile'"
         
-        function Write-JobLog($message) {
+        # Create job-specific log file path with fallback
+        if ($BaseLogFile -and $BaseLogFile.Trim() -ne "") {
+            $jobLogFile = $BaseLogFile -replace '\.log$', "-job$JobId.log"
+        } else {
+            # Fallback log file path
+            $jobLogFile = "C:\Rubrik\backup-multi-job$JobId.log"
+        }
+        
+        Write-Output "DEBUG: Job log file will be: '$jobLogFile'"
+        
+        function Write-JobLog($message, $suppressConsole = $false) {
             $timestamp = Get-Date -Format "yyyy-MM-dd HH:mm:ss"
             $logEntry = "$timestamp [JOB-$JobId] $message"
             if ($jobLogFile -and $jobLogFile.Trim() -ne "") {
-                Add-Content -Path $jobLogFile -Value $logEntry -Encoding UTF8
+                try {
+                    Add-Content -Path $jobLogFile -Value $logEntry -Encoding UTF8
+                    # Output to console for debugging (unless suppressed)
+                    if (-not $suppressConsole) {
+                        Write-Output "LOGGED TO $jobLogFile : $logEntry"
+                    }
+                } catch {
+                    Write-Output "LOG ERROR: $($_.Exception.Message) - File: $jobLogFile"
+                }
+            } else {
+                Write-Output "NO LOG FILE: jobLogFile is empty or null"
+            }
+            # Always output to console for job monitoring (unless suppressed)
+            if (-not $suppressConsole) {
+                Write-Output $logEntry
             }
-            Write-Output $logEntry
         }
         
         try {
@@ -198,13 +227,14 @@ function Start-BackupJob($jobId, $sqlInstance, $query, $baseLogFile) {
                 $message = $e.Message
                 if ($message -and $message.Trim() -ne "") {
                     $script:infoMessages += $message
-                    Write-JobLog "SQL INFO: $message"
+                    Write-JobLog "SQL INFO: $message" $true  # Suppress console output for verbose messages
                 }
             })
             
             try {
+                Write-JobLog "Attempting to connect to SQL Server: $SqlInstance"
                 $connection.Open()
-                Write-JobLog "Connected to SQL Server"
+                Write-JobLog "Connected to SQL Server successfully"
                 
                 $command = New-Object System.Data.SqlClient.SqlCommand
                 $command.Connection = $connection
@@ -223,13 +253,26 @@ function Start-BackupJob($jobId, $sqlInstance, $query, $baseLogFile) {
                         $rowData += "$($reader.GetName($i)): $($reader.GetValue($i))"
                     }
                     if ($rowData.Count -gt 0) {
-                        Write-JobLog "SQL RESULT: $($rowData -join ', ')"
+                        $resultLine = "SQL RESULT: $($rowData -join ', ')"
+                        Write-JobLog $resultLine
+                        Write-Output $resultLine  # Also output for Receive-Job
                     }
                 }
                 
                 $reader.Close()
-                Write-JobLog "Backup completed successfully. Captured $($infoMessages.Count) messages."
-                return @{ Success = $true; JobId = $JobId }
+                $summaryMessage = "Backup completed successfully. Captured $($infoMessages.Count) messages."
+                Write-JobLog $summaryMessage
+                Write-Output $summaryMessage  # Also output for Receive-Job
+                
+                # Output all captured SQL messages for debugging (only to log file, not console)
+                Write-JobLog "=== SQL MESSAGES START ===" $true
+                foreach ($msg in $infoMessages) {
+                    Write-JobLog "SQL: $msg" $true
+                }
+                Write-JobLog "=== SQL MESSAGES END ===" $true
+                
+                # Don't return hashtable - just output success message
+                Write-Output "JOB-${JobId}: SUCCESS"
             }
             finally {
                 if ($connection.State -eq [System.Data.ConnectionState]::Open) {
@@ -239,21 +282,53 @@ function Start-BackupJob($jobId, $sqlInstance, $query, $baseLogFile) {
             }
         }
         catch {
-            Write-JobLog "ERROR: Backup failed - $($_.Exception.Message)"
+            $errorMessage = "ERROR: Backup failed - $($_.Exception.Message)"
+            Write-JobLog $errorMessage
+            Write-Output $errorMessage  # Also output for Receive-Job
+            
+            # Check for specific connection errors
+            if ($_.Exception.Message -like "*server*not found*" -or 
+                $_.Exception.Message -like "*network-related*" -or
+                $_.Exception.Message -like "*instance*" -or
+                $_.Exception.Message -like "*login*failed*") {
+                $connError = "ERROR: CONNECTION FAILURE - Check SQL Server instance name and connectivity"
+                Write-JobLog $connError
+                Write-Output $connError
+            }
             
             # Log SQL Server specific errors
             if ($_.Exception -is [System.Data.SqlClient.SqlException]) {
                 Write-JobLog "ERROR: SQL Server Error Details:"
+                Write-Output "ERROR: SQL Server Error Details:"
                 foreach ($sqlError in $_.Exception.Errors) {
-                    Write-JobLog "ERROR: Severity: $($sqlError.Class), State: $($sqlError.State), Number: $($sqlError.Number)"
-                    Write-JobLog "ERROR: Message: $($sqlError.Message)"
+                    $errorDetail = "ERROR: Severity: $($sqlError.Class), State: $($sqlError.State), Number: $($sqlError.Number)"
+                    Write-JobLog $errorDetail
+                    Write-Output $errorDetail
+                    
+                    $errorMsg = "ERROR: Message: $($sqlError.Message)"
+                    Write-JobLog $errorMsg
+                    Write-Output $errorMsg
+                    
                     if ($sqlError.Procedure) {
-                        Write-JobLog "ERROR: Procedure: $($sqlError.Procedure), Line: $($sqlError.LineNumber)"
+                        $procError = "ERROR: Procedure: $($sqlError.Procedure), Line: $($sqlError.LineNumber)"
+                        Write-JobLog $procError
+                        Write-Output $procError
                     }
                 }
             }
             
-            return @{ Success = $false; JobId = $JobId; ErrorMessage = $_.Exception.Message }
+            # Log full exception details for debugging
+            $fullError = "ERROR: Full Exception Type: $($_.Exception.GetType().Name)"
+            Write-JobLog $fullError
+            Write-Output $fullError
+            
+            if ($_.Exception.InnerException) {
+                $innerError = "ERROR: Inner Exception: $($_.Exception.InnerException.Message)"
+                Write-JobLog $innerError
+                Write-Output $innerError
+            }
+            
+            Write-Output "JOB-${JobId}: FAILED"
         }
     }
     
@@ -265,7 +340,7 @@ Write-Log "Starting $Jobs parallel backup jobs using DatabasesInParallel feature
 [System.Collections.ArrayList]$jobList = @()
 
 for ($i = 1; $i -le $Jobs; $i++) {
-    $job = Start-BackupJob -jobId $i -sqlInstance $SqlInstance -query $query -logFile $logFile
+    $job = Start-BackupJob -jobId $i -sqlInstance $SqlInstance -query $query -baseLogFile $logFile
     $null = $jobList.Add($job)
     Write-Log "Started backup job $i (Job ID: $($job.Id))"
     Start-Sleep -Milliseconds 100  # Small delay to stagger job starts
@@ -280,28 +355,36 @@ while (-not $allJobsCompleted) {
     Start-Sleep -Seconds 5
     
     foreach ($job in $jobList) {
-        if ($job.Id -notin $completedJobs -and $job.State -ne "Running") {
-            $null = $completedJobs.Add($job.Id)
+        if ($job.Id -notin $completedJobs) {
+            # Check if job is no longer running
+            if ($job.State -eq "Completed" -or $job.State -eq "Failed" -or $job.State -eq "Stopped") {
+                $null = $completedJobs.Add($job.Id)
                 
-            if ($job.State -eq "Completed") {
-                $result = Receive-Job -Job $job
-                if ($result) {
-                    foreach ($line in $result) {
-                        Write-Host $line
+                # Get all job output
+                $jobOutput = Receive-Job -Job $job -Keep  # Use -Keep to preserve output
+                
+                if ($job.State -eq "Completed") {
+                    Write-Log "Job $($job.Id) completed successfully"
+                    
+                    # Log all job output to main log
+                    if ($jobOutput) {
+                        Write-Log "=== Job $($job.Id) Output ==="
+                        foreach ($line in $jobOutput) {
+                            Write-Log "$line"
+                        }
+                        Write-Log "=== End Job $($job.Id) Output ==="
                     }
-                }
-                Write-Log "Job $($job.Id) completed successfully"
-            } else {
-                $jobError = Receive-Job -Job $job
-                Write-Log "ERROR: Job $($job.Id) failed with state: $($job.State)"
-                if ($jobError) {
-                    foreach ($line in $jobError) {
-                        Write-Log "ERROR: $line"
+                } else {
+                    Write-Log "ERROR: Job $($job.Id) failed with state: $($job.State)"
+                    if ($jobOutput) {
+                        Write-Log "=== Job $($job.Id) Error Output ==="
+                        foreach ($line in $jobOutput) {
+                            Write-Log "ERROR: $line"
+                        }
+                        Write-Log "=== End Job $($job.Id) Error Output ==="
                     }
                 }
             }
-            
-            Remove-Job -Job $job
         }
     }
     
@@ -316,13 +399,53 @@ while (-not $allJobsCompleted) {
 
 Write-Log "All backup jobs completed"
 
+# Collect job states and outputs before cleanup for final status check
+$jobResults = @{}
+foreach ($job in $jobList) {
+    $jobOutput = Receive-Job -Job $job -Keep -ErrorAction SilentlyContinue
+    $hasFailed = $false
+    
+    # Check if job output contains failure indicator
+    if ($jobOutput) {
+        foreach ($line in $jobOutput) {
+            if ($line -like "*JOB-*: FAILED") {
+                $hasFailed = $true
+                break
+            }
+        }
+    }
+    
+    $jobResults[$job.Id] = @{
+        State = $job.State
+        Failed = $hasFailed
+    }
+}
+
+# Clean up jobs
+Write-Log "Cleaning up completed jobs..."
+foreach ($job in $jobList) {
+    try {
+        if ($job.State -eq "Running") {
+            Write-Log "WARNING: Job $($job.Id) still running, stopping it..."
+            Stop-Job -Job $job -Force
+            Start-Sleep -Seconds 2
+        }
+        Remove-Job -Job $job -Force -ErrorAction SilentlyContinue
+        Write-Log "Cleaned up job $($job.Id)"
+    } catch {
+        Write-Log "WARNING: Could not clean up job $($job.Id): $($_.Exception.Message)"
+    }
+}
+
 # Consolidate job logs into main log file
 Write-Log "Consolidating job logs..."
 for ($i = 1; $i -le $Jobs; $i++) {
     $jobLogFile = $logFile -replace '\.log$', "-job$i.log"
+    Write-Log "Checking for job log file: $jobLogFile"
     if (Test-Path $jobLogFile) {
         try {
             $jobContent = Get-Content $jobLogFile -ErrorAction Stop
+            Write-Log "Found $($jobContent.Count) lines in job $i log"
             foreach ($line in $jobContent) {
                 Add-Content -Path $logFile -Value $line -Encoding UTF8
             }
@@ -331,14 +454,21 @@ for ($i = 1; $i -le $Jobs; $i++) {
         } catch {
             Write-Log "WARNING: Could not consolidate log from job $i : $($_.Exception.Message)"
         }
+    } else {
+        Write-Log "WARNING: Job log file not found for job $i"
     }
 }
 
-# Final status check
-$failedJobs = $jobList | Where-Object { $_.State -ne "Completed" }
-if ($failedJobs.Count -gt 0) {
-    Write-Log "ERROR: $($failedJobs.Count) jobs failed"
+# Final status check using job output analysis
+$failedJobIds = $jobResults.Keys | Where-Object { $jobResults[$_].Failed -eq $true }
+
+if ($failedJobIds.Count -gt 0) {
+    Write-Log "ERROR: $($failedJobIds.Count) out of $($jobResults.Count) backup jobs failed"
+    foreach ($jobId in $failedJobIds) {
+        Write-Log "ERROR: Job ID $jobId failed"
+    }
+    Write-Log "CRITICAL: Backup operation failed - check errors above"
     exit 1
 } else {
-    Write-Log "SUCCESS: All $($jobList.Count) backup jobs completed successfully"
+    Write-Log "SUCCESS: All $($jobResults.Count) backup jobs completed successfully"
 }