From 5982fc94342d3acfe4a65fe7007ff3378b2f3b3f Mon Sep 17 00:00:00 2001 From: kyle Date: Wed, 7 Oct 2026 15:40:08 -0600 Subject: [PATCH] Fix MARS collector against a real agent's object model Checked with Get-MarsCollectorDiagnostics.ps1 output from MARS agent 2.0.9274 (VA-FS-01): - JobStatus.StartTime/EndTime are UTC values not marked as UTC (DisplayTime is the local one); they were read as local, putting runs 6 hours off. Lookback filtering now compares in UTC too - ErrorInfo is always present with ErrorCode 0 on success; every completed backup would have been a warning. Only non-zero error codes count - Schedule times are TimeSpans; casting them to DateTime failed, so next_run_at was always empty - DatasourceStatus.Datasource is an object; use its DataSourceName - Also report FileProgress.Failed file counts and FailedFileLog - Mock rebuilt on the real shapes; diagnostics handle no System State policy Co-Authored-By: Claude Opus 5.5 --- .../mars/Get-MarsCollectorDiagnostics.ps1 | 5 +- collectors/mars/README.md | 12 +-- collectors/mars/Send-MarsBackupStatus.ps1 | 86 ++++++++++++++----- collectors/mars/tests/MockMars.ps1 | 64 +++++++++----- 4 files changed, 118 insertions(+), 49 deletions(-) diff --git a/collectors/mars/Get-MarsCollectorDiagnostics.ps1 b/collectors/mars/Get-MarsCollectorDiagnostics.ps1 index f918a8e..35593db 100644 --- a/collectors/mars/Get-MarsCollectorDiagnostics.ps1 +++ b/collectors/mars/Get-MarsCollectorDiagnostics.ps1 @@ -90,7 +90,10 @@ $report = & { Show-Section 'Get-OBPolicy' { Get-OBPolicy } Show-Section 'Get-OBPolicy | Get-OBSchedule' { Get-OBSchedule -Policy (Get-OBPolicy) } if (Get-Command Get-OBSystemStatePolicy -ErrorAction SilentlyContinue) { - Show-Section 'Get-OBSystemStatePolicy | Get-OBSchedule' { Get-OBSchedule -Policy (Get-OBSystemStatePolicy) } + Show-Section 'Get-OBSystemStatePolicy | Get-OBSchedule' { + $ssPolicy = Get-OBSystemStatePolicy + if ($ssPolicy) { Get-OBSchedule -Policy $ssPolicy } else { '(no System State policy configured)' } + } } } | Out-String -Width 300 diff --git a/collectors/mars/README.md b/collectors/mars/README.md index 3ac6f15..9134852 100644 --- a/collectors/mars/README.md +++ b/collectors/mars/README.md @@ -4,10 +4,10 @@ A PowerShell script that runs on each server with the Microsoft Azure Recovery S agent and reports its backups to the dashboard. Each server appears as one job, named ` - Azure Backup` by default. -> **Not yet checked against a real MARS agent.** The cmdlets are the agent's own (`Get-OBJob`, -> `Get-OBPolicy`, `Get-OBSchedule`), but the property names of the objects they return aren't -> documented. Before installing on the first server, run `Get-MarsCollectorDiagnostics.ps1` and -> the collector with `-DryRun` (see below) to confirm what it reads. +> **Checked against:** MARS agent 2.0.9274, a Files & Folders policy with completed backups only. +> Not yet seen on a real agent: a failed backup, a backup in progress, or a System State policy. +> Those paths are written to the same object model, but if one looks wrong, run +> `Get-MarsCollectorDiagnostics.ps1` while it's in that state and send the output. ## Install (on the server, as an administrator) @@ -43,9 +43,9 @@ Re-run the installer to change settings or update the script. | Company | `Tenant` from the config | | Job | One per server, ID `mars:`, so changing `JobName` renames rather than duplicates it | | Status | Backup job state: Failed → **Failed**. Completed with failed bytes or an error → **Warning**. Aborted/cancelled or unrecognised → **Warning**. In progress → **Running**. Restore jobs are ignored | -| Started / finished | Job start / end time | +| Started / finished | Job start / end time. MARS reports these in UTC without marking them as UTC; the collector handles that | | Next scheduled | Next slot from the backup policy schedule, or the System State policy's if that's sooner. Empty (so never Overdue) for schedules that run every 2+ weeks, since which week is next can't be told | -| Message | Job and per-datasource errors, and datasources with failed bytes | +| Message | Job and per-datasource errors (non-zero error codes), failed file counts, and the failed-file log path | | Size | Bytes transferred, summed across datasources | Each run covers the last 48 hours (`LookbackHours`). Jobs already delivered are recorded in diff --git a/collectors/mars/Send-MarsBackupStatus.ps1 b/collectors/mars/Send-MarsBackupStatus.ps1 index a58caa9..8ebaeb8 100644 --- a/collectors/mars/Send-MarsBackupStatus.ps1 +++ b/collectors/mars/Send-MarsBackupStatus.ps1 @@ -67,11 +67,12 @@ function Get-ErrorText($ErrorRecord) { return $ErrorRecord.Exception.Message } -# The API needs an explicit UTC offset. MARS returns local times, which DateTimeOffset keeps as local. +# The API needs an explicit UTC offset. DateTimeOffset keeps a Local/Unspecified time as local and a +# Utc time as +00:00. function ConvertTo-IsoTime($Value) { if ($null -eq $Value) { return $null } $dt = [datetime]$Value - if ($dt.Year -le 1900) { return $null } # "not set" + if ($dt.Year -le 1900) { return $null } # "not set" (MARS uses 1601-01-01) return ([DateTimeOffset]$dt).ToString("yyyy-MM-dd'T'HH:mm:sszzz", $Invariant) } @@ -116,8 +117,10 @@ function Get-NextSlot($Schedule, [datetime]$After) { if ($weeks -and [int]$weeks -gt 1) { return $null } $days = @(Get-FirstValue $Schedule @('ScheduleRunDays', 'DaysOfWeek') | ForEach-Object { [string]$_ }) - $times = @(Get-FirstValue $Schedule @('ScheduleRunTimes', 'TimesOfDay') | - ForEach-Object { ([datetime]$_).TimeOfDay } | Sort-Object) + # TimeSpans (time of day, local) on real agents; accept DateTimes too + $times = @(Get-FirstValue $Schedule @('ScheduleRunTimes', 'TimesOfDay') | ForEach-Object { + if ($_ -is [timespan]) { $_ } else { ([datetime]$_).TimeOfDay } + } | Sort-Object) if ($days.Count -eq 0 -or $times.Count -eq 0) { return $null } for ($offset = 0; $offset -le 7; $offset++) { @@ -153,18 +156,55 @@ function Get-NextRun { # ---------- Jobs ---------- +# A job's StartTime/EndTime are UTC values, though not necessarily marked as UTC: on a real agent +# StartTime matched the "StartTimeUTC" in the status text, while DisplayTime held local time. +# Returns $null for "not set" (1601-01-01), e.g. EndTime while a backup is running. +function Get-JobTimeUtc($Job, [string]$Field) { + $value = Get-FirstValue $Job.JobStatus @($Field) + if ($null -eq $value) { return $null } + $dt = [datetime]$value + if ($dt.Year -le 1900) { return $null } + return [datetime]::SpecifyKind($dt, [DateTimeKind]::Utc) +} + +# MARS always includes an ErrorInfo; ErrorCode 0 means no error +function Test-HasError($ErrorInfo) { + if (-not $ErrorInfo) { return $false } + $code = Get-FirstValue $ErrorInfo @('ErrorCode') + $detailed = Get-FirstValue $ErrorInfo @('DetailedErrorCode') + return ($code -and [long]$code -ne 0) -or ($detailed -and [long]$detailed -ne 0) +} + +# DatasourceStatus.Datasource is an object whose DataSourceName is e.g. "E:\" or "System State" +function Get-DatasourceName($DatasourceStatus) { + $ds = Get-FirstValue $DatasourceStatus @('Datasource', 'DataSource') + $name = Get-FirstValue $ds @('DataSourceName', 'FriendlyNameDSPS', 'Name') + if ($name) { return [string]$name } + if ($ds -is [string]) { return $ds } + return 'Datasource' +} + +function Get-FailedFiles($Job) { + $sum = [long]0 + foreach ($ds in Get-DatasourceStatuses $Job) { + $value = Get-FirstValue (Get-FirstValue $ds @('FileProgress')) @('Failed') + if ($value) { $sum += [long]$value } + } + return $sum +} + function Get-JobStatus($Job) { $status = $Job.JobStatus - $end = Get-FirstValue $status @('EndTime') $state = [string](Get-FirstValue $status @('JobState', 'State')) - if (-not (ConvertTo-IsoTime $end) -and $state -notmatch 'Fail|Abort|Cancel|Complete|Success|Succeed|Warn') { + if (-not (Get-JobTimeUtc $Job 'EndTime') -and $state -notmatch 'Fail|Abort|Cancel|Complete|Success|Succeed|Warn') { return 'running' } if ($state -match 'Fail') { return 'failed' } if ($state -match 'Warn|Abort|Cancel|Stop') { return 'warning' } if ($state -match 'Complete|Success|Succeed') { # MARS can report Completed while individual files failed or an error was recorded - if ((Get-FailedBytes $Job) -gt 0 -or (Get-FirstValue $status @('ErrorInfo'))) { return 'warning' } + if ((Get-FailedBytes $Job) -gt 0 -or (Get-FailedFiles $Job) -gt 0 -or + (Test-HasError (Get-FirstValue $status @('ErrorInfo')))) { return 'warning' } return 'success' } return 'warning' # finished in a state we don't recognise: surface it rather than hide it @@ -187,7 +227,7 @@ function Get-ByteTotal($Job, [string]$Field) { function Get-FailedBytes($Job) { return Get-ByteTotal $Job 'Failed' } function Format-ErrorInfo($ErrorInfo) { - if (-not $ErrorInfo) { return $null } + if (-not (Test-HasError $ErrorInfo)) { return $null } $text = Get-FirstValue $ErrorInfo @('ErrorMessage', 'Message', 'Description') if ($text) { return ([string]$text).Trim() } $code = Get-FirstValue $ErrorInfo @('ErrorCode', 'DetailedErrorCode') @@ -208,12 +248,16 @@ function Get-RunMessage($Job, [string]$Status) { if ($jobError) { $lines.Add($jobError) } foreach ($ds in Get-DatasourceStatuses $Job) { - $name = Get-FirstValue $ds @('Datasource', 'DataSource', 'DatasourceName', 'Name') + $name = Get-DatasourceName $ds $dsError = Format-ErrorInfo (Get-FirstValue $ds @('ErrorInfo')) - $failed = Get-FirstValue (Get-FirstValue $ds @('ByteProgress')) @('Failed') + $failedFiles = Get-FirstValue (Get-FirstValue $ds @('FileProgress')) @('Failed') + $failedBytes = Get-FirstValue (Get-FirstValue $ds @('ByteProgress')) @('Failed') if ($dsError) { $lines.Add("${name}: $dsError") } - elseif ($failed -and [long]$failed -gt 0) { $lines.Add("${name}: $failed bytes failed to back up") } + if ($failedFiles -and [long]$failedFiles -gt 0) { $lines.Add("${name}: $failedFiles file(s) failed to back up") } + elseif ($failedBytes -and [long]$failedBytes -gt 0) { $lines.Add("${name}: $failedBytes bytes failed to back up") } } + $failedLog = Get-FirstValue $Job.JobStatus @('FailedFileLog') + if ($failedLog -and $lines.Count) { $lines.Add("Failed file log: $failedLog") } if ($lines.Count -eq 0) { switch ($Status) { @@ -228,9 +272,7 @@ function Get-RunMessage($Job, [string]$Status) { function ConvertTo-Run($Job) { $status = Get-JobStatus $Job - $datasources = @(Get-DatasourceStatuses $Job | ForEach-Object { - [string](Get-FirstValue $_ @('Datasource', 'DataSource', 'DatasourceName', 'Name')) - } | Where-Object { $_ }) + $datasources = @(Get-DatasourceStatuses $Job | ForEach-Object { Get-DatasourceName $_ }) $details = [ordered]@{ server = $env:COMPUTERNAME } if ($datasources.Count) { $details.datasources = $datasources } @@ -240,17 +282,19 @@ function ConvertTo-Run($Job) { $run = [ordered]@{ external_id = [string]$Job.JobId status = $status - started_at = ConvertTo-IsoTime (Get-FirstValue $Job.JobStatus @('StartTime')) + started_at = ConvertTo-IsoTime (Get-JobTimeUtc $Job 'StartTime') message = Get-RunMessage $Job $status details = $details } if ($status -ne 'running') { - $finished = ConvertTo-IsoTime (Get-FirstValue $Job.JobStatus @('EndTime')) + $finished = ConvertTo-IsoTime (Get-JobTimeUtc $Job 'EndTime') if ($finished) { $run.finished_at = $finished } # otherwise the API uses receipt time $transferred = Get-ByteTotal $Job 'Progress' if ($transferred -gt 0) { $run.size_bytes = $transferred } $failedBytes = Get-FailedBytes $Job if ($failedBytes -gt 0) { $details.failed_bytes = $failedBytes } + $failedFiles = Get-FailedFiles $Job + if ($failedFiles -gt 0) { $details.failed_files = $failedFiles } } return $run } @@ -304,20 +348,20 @@ try { if ($saved) { foreach ($p in $saved.PSObject.Properties) { $sent[$p.Name] = [long]$p.Value } } } - $since = (Get-Date).AddHours(-$LookbackHours) + $sinceUtc = (Get-Date).ToUniversalTime().AddHours(-$LookbackHours) # Get-OBJob with no arguments lists jobs in progress; -Previous lists finished ones $jobs = @(@(Get-OBJob) + @(Get-OBJob -Previous $MaxPreviousJobs) | Where-Object { $_ -and (Test-IsBackupJob $_) }) $byId = [ordered]@{} foreach ($job in $jobs) { - $start = Get-FirstValue $job.JobStatus @('StartTime') - if (-not $start -or [datetime]$start -lt $since) { continue } + $start = Get-JobTimeUtc $job 'StartTime' + if (-not $start -or $start -lt $sinceUtc) { continue } $byId[[string]$job.JobId] = $job # a job in both lists: the finished entry (later) wins } $pending = @($byId.Values | Where-Object { -not $sent.ContainsKey([string]$_.JobId) } | - Sort-Object { [datetime](Get-FirstValue $_.JobStatus @('StartTime')) }) + Sort-Object { Get-JobTimeUtc $_ 'StartTime' }) $jobInfo = [ordered]@{ # Stable per server, so renaming the dashboard job via JobName doesn't create a new one @@ -343,7 +387,7 @@ try { Send-Report ([ordered]@{ tenant = $Config.Tenant; source_system = $SourceSystem; job = $jobInfo; run = $run }) $runsSent++ if ($run.status -ne 'running') { - $sent[$run.external_id] = ([DateTimeOffset][datetime](Get-FirstValue $job.JobStatus @('StartTime'))).ToUnixTimeSeconds() + $sent[$run.external_id] = ([DateTimeOffset](Get-JobTimeUtc $job 'StartTime')).ToUnixTimeSeconds() } } } catch { diff --git a/collectors/mars/tests/MockMars.ps1 b/collectors/mars/tests/MockMars.ps1 index 06edade..4578ced 100644 --- a/collectors/mars/tests/MockMars.ps1 +++ b/collectors/mars/tests/MockMars.ps1 @@ -1,56 +1,78 @@ -# Stand-ins for the MARS agent cmdlets, shaped like the properties the collector reads. -# Property names are best guesses until checked against Get-MarsCollectorDiagnostics.ps1 output. +# Stand-ins for the MARS agent cmdlets. Object shapes follow Get-MarsCollectorDiagnostics.ps1 +# output from a real agent (2.0.9274): job times are UTC values with no UTC marking, "not set" is +# 1601-01-01, ErrorInfo is always present (ErrorCode 0 = no error), Datasource is an object, and +# schedule times are TimeSpans. # # . ./tests/MockMars.ps1 # ./Send-MarsBackupStatus.ps1 -ConfigPath ./my-test-config.json -DryRun # Fixed to the top of the hour, and IDs derived from times, so repeated runs see the same jobs $now = Get-Date -Minute 0 -Second 0 -Millisecond 0 +$notSet = [datetime]::new(1601, 1, 1) function New-StableGuid([string]$Seed) { [guid]::new([Security.Cryptography.MD5]::Create().ComputeHash([Text.Encoding]::UTF8.GetBytes($Seed))) } -function New-MockDatasource($Name, [long]$Done, [long]$Failed = 0, $ErrorInfo = $null) { +# Local time -> the UTC value MARS reports, with Kind Unspecified like the real objects +function ConvertTo-MarsTime([datetime]$Local) { + [datetime]::SpecifyKind($Local.ToUniversalTime(), [DateTimeKind]::Unspecified) +} + +function New-MockErrorInfo([int]$Code = 0, $Params = @()) { + [pscustomobject]@{ DetailedErrorCode = 0; DetailedErrorSource = $null; ErrorCode = $Code; ErrorParamList = $Params } +} + +function New-MockDatasource($Name, [uint64]$Done, [uint64]$FailedBytes = 0, [uint64]$FailedFiles = 0, $ErrorInfo = (New-MockErrorInfo)) { [pscustomobject]@{ - Datasource = $Name - ByteProgress = [pscustomobject]@{ Total = $Done + $Failed; Progress = $Done; Failed = $Failed } + ByteProgress = [pscustomobject]@{ Changed = $Done; Failed = $FailedBytes; Progress = $Done; Total = 2TB } + Datasource = [pscustomobject]@{ DataSourceName = $Name; DataSourceId = 6310158806455554328 } ErrorInfo = $ErrorInfo + FileProgress = [pscustomobject]@{ Changed = 100; CurrentFile = ''; Failed = $FailedFiles; Progress = 100; Total = 100 } + JobState = 'Completed' } } -function New-MockJob($Type, $Start, $End, $State, $Datasources = @(), $ErrorInfo = $null) { +function New-MockJob($Type, [datetime]$Start, $End, $State, $Datasources = @(), $ErrorInfo = (New-MockErrorInfo), $FailedFileLog = '') { + $endValue = if ($End) { ConvertTo-MarsTime $End } else { $notSet } [pscustomobject]@{ - JobId = New-StableGuid "$Type|$($Start.Ticks)" - JobType = $Type - JobStatus = [pscustomobject]@{ - JobState = $State; StartTime = $Start; EndTime = $End - DatasourceStatus = $Datasources; ErrorInfo = $ErrorInfo + IsRetried = $false + JobId = New-StableGuid "$Type|$($Start.Ticks)" + JobType = $Type + DisplayTime = $Start # the only local time on the object + JobStatus = [pscustomobject]@{ + DatasourceStatus = $Datasources + EndTime = $endValue + ErrorInfo = $ErrorInfo + FailedFileLog = $FailedFileLog + JobState = $State + StartTime = ConvertTo-MarsTime $Start } } } $global:MockMarsRunning = @( - (New-MockJob 'Backup' $now.AddMinutes(-10) $null 'InProgress' @((New-MockDatasource 'D:\Shares' 2GB))) + (New-MockJob 'Backup' $now.AddMinutes(-10) $null 'InProgress' @((New-MockDatasource 'E:\' 2GB))) ) $global:MockMarsPrevious = @( - (New-MockJob 'Backup' $now.AddHours(-12) $now.AddHours(-11) 'Completed' @( - (New-MockDatasource 'D:\Shares' 12GB), (New-MockDatasource 'System State' 8GB))), + (New-MockJob 'Backup' $now.AddHours(-12) $now.AddHours(-11.5) 'Completed' @((New-MockDatasource 'E:\' 523407872))), + # Completed, but some files failed (New-MockJob 'Backup' $now.AddHours(-36) $now.AddHours(-35) 'Completed' @( - (New-MockDatasource 'D:\Shares' 3GB 40MB))), # completed, but some files failed + (New-MockDatasource 'E:\' 3GB 40MB 12)) -FailedFileLog 'C:\Program Files\Microsoft Azure Recovery Services Agent\Temp\Errors.log'), (New-MockJob 'Backup' $now.AddHours(-30) $now.AddHours(-29.5) 'Failed' @() ` - ([pscustomobject]@{ ErrorCode = 100050; ErrorParamList = @([pscustomobject]@{ Name = 'Volume'; Value = 'D:' }) })), + (New-MockErrorInfo 100050 @([pscustomobject]@{ Name = 'Volume'; Value = 'E:' }))), (New-MockJob 'Recovery' $now.AddHours(-5) $now.AddHours(-4) 'Completed'), # a restore: must be ignored (New-MockJob 'Backup' $now.AddDays(-5) $now.AddDays(-5).AddHours(1) 'Completed') # outside 48h lookback ) -# Daily at 21:00 and 03:00, weekdays only -$global:MockMarsPolicy = [pscustomobject]@{ PolicyName = 'Files' } +# Every day at 21:00 local, as on the real server $global:MockMarsSchedule = [pscustomobject]@{ - ScheduleRunDays = @([DayOfWeek]::Monday, [DayOfWeek]::Tuesday, [DayOfWeek]::Wednesday, [DayOfWeek]::Thursday, [DayOfWeek]::Friday) - ScheduleRunTimes = @($now.Date.AddHours(21), $now.Date.AddHours(3)) + ScheduleRunDays = [DayOfWeek[]](0..6) + ScheduleRunTimes = [timespan[]]@([timespan]::FromHours(21)) ScheduleWeeklyFrequency = 1 + TypeOfBackupSchedule = 'Daily' } function Get-OBJob { param([int]$Previous) if ($PSBoundParameters.ContainsKey('Previous')) { $global:MockMarsPrevious } else { $global:MockMarsRunning } } -function Get-OBPolicy { $global:MockMarsPolicy } +function Get-OBPolicy { [pscustomobject]@{ PolicyName = 'policy'; BackupSchedule = $global:MockMarsSchedule } } function Get-OBSchedule { param($Policy) $global:MockMarsSchedule } +function Get-OBSystemStatePolicy { $null } # none configured, as on the real server