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 <[email protected]>

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
 

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 `<SERVER> - Azure Backup` by default.
 
-> **Not yet checked against a real MARS agent.** The cmdlets are the agent's own (`Get-OBJob`,
+> **Checked against:** MARS agent 2.0.9274, a Files & Folders policy with completed backups only.
-> `Get-OBPolicy`, `Get-OBSchedule`), but the property names of the objects they return aren't
+> Not yet seen on a real agent: a failed backup, a backup in progress, or a System State policy.
-> documented. Before installing on the first server, run `Get-MarsCollectorDiagnostics.ps1` and
+> Those paths are written to the same object model, but if one looks wrong, run
-> the collector with `-DryRun` (see below) to confirm what it reads.
+> `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:<computer name>`, 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

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') |
+    # TimeSpans (time of day, local) on real agents; accept DateTimes too
-        ForEach-Object { ([datetime]$_).TimeOfDay } | Sort-Object)
+    $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 {
+    $datasources = @(Get-DatasourceStatuses $Job | ForEach-Object { Get-DatasourceName $_ })
-        [string](Get-FirstValue $_ @('Datasource', 'DataSource', 'DatasourceName', 'Name'))
-    } | Where-Object { $_ })
 
     $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')
+        $start = Get-JobTimeUtc $job 'StartTime'
-        if (-not $start -or [datetime]$start -lt $since) { continue }
+        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 {

collectors/mars/tests/MockMars.ps1

@@ -1,56 +1,78 @@
-# Stand-ins for the MARS agent cmdlets, shaped like the properties the collector reads.
+# Stand-ins for the MARS agent cmdlets. Object shapes follow Get-MarsCollectorDiagnostics.ps1
-# Property names are best guesses until checked against Get-MarsCollectorDiagnostics.ps1 output.
+# 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]@{ Changed = $Done; Failed = $FailedBytes; Progress = $Done; Total = 2TB }
-        ByteProgress = [pscustomobject]@{ Total = $Done + $Failed; Progress = $Done; Failed = $Failed }
+        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]@{
+        IsRetried   = $false
         JobId       = New-StableGuid "$Type|$($Start.Ticks)"
         JobType     = $Type
+        DisplayTime = $Start  # the only local time on the object
         JobStatus   = [pscustomobject]@{
-            JobState = $State; StartTime = $Start; EndTime = $End
+            DatasourceStatus = $Datasources
-            DatasourceStatus = $Datasources; ErrorInfo = $ErrorInfo
+            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-MockJob 'Backup' $now.AddHours(-12) $now.AddHours(-11.5) 'Completed' @((New-MockDatasource 'E:\' 523407872))),
-        (New-MockDatasource 'D:\Shares' 12GB), (New-MockDatasource 'System State' 8GB))),
+    # 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
+# Every day at 21:00 local, as on the real server
-$global:MockMarsPolicy = [pscustomobject]@{ PolicyName = 'Files' }
 $global:MockMarsSchedule = [pscustomobject]@{
-    ScheduleRunDays         = @([DayOfWeek]::Monday, [DayOfWeek]::Tuesday, [DayOfWeek]::Wednesday, [DayOfWeek]::Thursday, [DayOfWeek]::Friday)
+    ScheduleRunDays         = [DayOfWeek[]](0..6)
-    ScheduleRunTimes        = @($now.Date.AddHours(21), $now.Date.AddHours(3))
+    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