Review 1.4: AX batch rules: one finding per job, stuck jobs only once, no crash without a start

- Axapta 3.0/4.0 keep a BATCH row per recurrence, so a failed run and the
  next waiting run share a job key and gave two SQLI-AX-001 findings with the
  same subject (the repository kept the last, the hub the first). The batch
  rules now keep one finding per subject, the most severe.
- SQLI-AX-004 treated a single earlier 10-hour run as "normally that long"
  and stayed silent; it now needs BatchHistoryMinimumRuns runs, like
  SQLI-AX-002. A stuck job is SQLI-AX-004's finding only, not also -002's.
- Running(now)!.Value threw for an executing job with neither a start time
  nor a first-seen time (and a negative duration meant clock skew); such jobs
  are skipped.
- SQLI-AX-010 no longer calls every session in an AX database "from Dynamics
  AX", and shows the raw CONTEXT_INFO as sensitive evidence.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
This commit is contained in:
Søren Eggert Lundsteen Olsen 2026-10-02 14:29:35 +02:00
parent 8365ba5357
commit 13f22c7541
2 changed files with 82 additions and 7 deletions

View file

@ -57,11 +57,33 @@ public abstract class DynamicsAxBatchRule : DynamicsAxRule
ArgumentNullException.ThrowIfNull(context);
var snapshot = context.Data.Get<AxBatchSnapshot>();
var (measured, outcome) = Measured(snapshot.Databases, d => d.Database, d => d.NotMeasurable);
return outcome ?? Result(measured.SelectMany(d => Check(d, snapshot.Thresholds, context.Now).Take(MaxFindingsPerDatabase)));
// One finding per subject: Axapta 3.0/4.0 keep a BATCH row per recurrence, so several rows share a job key (e.g. the
// failed run and the next waiting one). The most severe wins, then the first (the newest), so the finding the hub
// and the repository keep is the same.
return outcome ?? Result(measured.SelectMany(d => Check(d, snapshot.Thresholds, context.Now)
.GroupBy(f => f.Subject, StringComparer.Ordinal)
.Select(g => g.OrderByDescending(f => f.Severity).First())
.Take(MaxFindingsPerDatabase)));
}
protected abstract IEnumerable<Finding> Check(AxBatchDatabase database, AxThresholds thresholds, DateTimeOffset now);
/// <summary>How long an executing job has run, or null when unknown (or negative: clocks or time zones disagree).</summary>
protected static TimeSpan? RunningFor(AxBatchJob job, DateTimeOffset now) =>
job.Status == AxBatchStatus.Executing && job.Running(now) is { } running && running >= TimeSpan.Zero ? running : null;
/// <summary>
/// SQLI-AX-004's condition: executing at least BatchStuckHours and not normally that long by the job's own history
/// (which needs BatchHistoryMinimumRuns runs, as for SQLI-AX-002).
/// </summary>
protected static bool IsStuck(AxBatchJob job, TimeSpan running, AxThresholds thresholds)
{
var normallyLong = job.HistoryRuns >= thresholds.BatchHistoryMinimumRuns && job.P90Seconds is { } p90
&& running.TotalSeconds <= p90 * thresholds.BatchLongRunningFactor;
return running >= TimeSpan.FromHours(thresholds.BatchStuckHours) && !normallyLong;
}
protected Finding JobFinding(AxBatchDatabase database, AxBatchJob job, Severity severity, string title, string explanation, string recommendation,
IEnumerable<Evidence> evidence) =>
CreateFinding(severity, title, explanation, recommendation,
@ -125,7 +147,12 @@ public sealed class AxBatchLongRunningRule : DynamicsAxBatchRule
{
foreach (var job in database.Jobs.Where(j => j.Status == AxBatchStatus.Executing && j.HistoryRuns >= thresholds.BatchHistoryMinimumRuns && j.P90Seconds is not null))
{
var running = job.Running(now)!.Value;
// A job that hangs is SQLI-AX-004's finding, not also this one.
if (RunningFor(job, now) is not { } running || IsStuck(job, running, thresholds))
{
continue;
}
var limit = TimeSpan.FromSeconds(Math.Max(job.P90Seconds!.Value * thresholds.BatchLongRunningFactor, thresholds.BatchLongRunningMinimumMinutes * 60.0));
if (running < limit)
{
@ -195,9 +222,7 @@ public sealed class AxBatchStuckRule : DynamicsAxBatchRule
{
foreach (var job in database.Jobs.Where(j => j.Status == AxBatchStatus.Executing))
{
var running = job.Running(now)!.Value;
var normallyLong = job.P90Seconds is { } p90 && running.TotalSeconds <= p90 * thresholds.BatchLongRunningFactor;
if (running < TimeSpan.FromHours(thresholds.BatchStuckHours) || normallyLong)
if (RunningFor(job, now) is not { } running || !IsStuck(job, running, thresholds))
{
continue;
}
@ -464,8 +489,9 @@ public sealed class AxBlockingUserRule : DynamicsAxRule
findings.Add(CreateFinding(longest >= 300_000 || victims.Count >= 10 ? Severity.High : Severity.Medium,
who.Known
? $"AX-brugeren bag session {head.SessionId} blokerer {victims.Count} session(er) i {database.Database}"
: $"En AX-session ({head.SessionId}) blokerer {victims.Count} session(er) i {database.Database}",
"En session fra Dynamics AX holder låse, som andre AX-brugere eller batchjob venter på. I AX går alle brugere gennem AOS'ens login, "
: $"Session {head.SessionId} i AX-databasen blokerer {victims.Count} session(er) i {database.Database}",
"En session i Dynamics AX-databasen holder låse, som andre AX-brugere eller batchjob venter på (er det ikke AX selv, ses det af "
+ "programmet under målingerne). I AX går alle brugere gennem AOS'ens login, "
+ "så SQL Server-login'et siger ikke, hvem det er. " + who.Explanation,
who.Known
? "Kontakt brugeren (se AX-bruger under målinger) og find ud af, hvad de er i gang med – typisk en stor bogføring, en rapport eller en "
@ -478,6 +504,7 @@ public sealed class AxBlockingUserRule : DynamicsAxRule
new Evidence("Kilde", who.Source),
new Evidence("SQL-session", $"{head.SessionId} ({head.Status}), {head.OpenTransactionCount} åbne transaktioner"),
new Evidence("Vært / program", $"{head.HostName} / {head.ProgramName}", Sensitive: true),
new Evidence("CONTEXT_INFO (rå)", who.RawContext ?? "–", Sensitive: true),
new Evidence("Blokerede sessioner", victims.Count.ToString(CultureInfo.InvariantCulture)),
new Evidence("Længste ventetid", $"{Format.Number(longest / 1000.0)} s"),
new Evidence("Sætning", head.SqlText is { Length: > 500 } s ? s[..500] + " …" : head.SqlText ?? "–", Sensitive: true),

View file

@ -296,4 +296,52 @@ public class DynamicsAxRuleTests
Assert.Contains("sætter ikke CONTEXT_INFO", finding.Explanation, StringComparison.Ordinal);
Assert.Equal(RuleOutcome.Passed, Run(new AxBlockingUserRule(), With(AxDatabases(AxVersion.Axapta30), Blocking(null, waitMs: 5_000))).Outcome);
}
[Fact]
public void Ax010_ax30_keeps_host_and_program_out_of_the_explanation_which_may_reach_the_hub()
{
var finding = Assert.Single(Run(new AxBlockingUserRule(), With(AxDatabases(AxVersion.Axapta30), Blocking(null))).Findings);
Assert.DoesNotContain("AOS01", finding.Explanation + finding.Title + finding.Subject, StringComparison.Ordinal);
Assert.DoesNotContain("Microsoft Dynamics AX", finding.Explanation, StringComparison.Ordinal);
Assert.True(finding.Evidence.Single(e => e.Name == "Vært / program").Sensitive);
Assert.True(finding.Evidence.Single(e => e.Name == "CONTEXT_INFO (rå)").Sensitive);
}
[Fact]
public void Ax001_ax30_rows_of_one_recurring_job_give_one_finding_with_the_highest_severity()
{
// AX 3.0 keeps a BATCH row per recurrence: the failed run and the next waiting one share the job key.
var history = new AxBatchHistory();
history.Add("AX30", new AxBatchRun("4711|dat|NAT", "R1", "Lagerafslutning", "dat", Utc.AddHours(-3), Utc.AddHours(-2), AxBatchStatus.Error));
var failed = Job30(Batch30(50, 2, Utc.AddHours(-3)), history) with { EndedUtc = Utc.AddHours(-2) };
var waiting = Job30(Batch30(51, 0, Utc.AddHours(1)), history);
var finding = Assert.Single(Run(new AxBatchFailedRule(), With(Batch(failed, waiting))).Findings);
Assert.Equal(Severity.High, finding.Severity);
Assert.Equal("database: AX30 · batch: 4711|dat|NAT", finding.Subject);
}
[Fact]
public void Ax004_one_long_earlier_run_does_not_hide_a_stuck_job_and_ax002_leaves_a_stuck_job_to_ax004()
{
var row = Batch30(60, 1, Utc.AddHours(-9));
var oneLongRun = Job30(row, History("4711|dat|NAT", 1, TimeSpan.FromHours(10)), Utc.AddHours(-7));
Assert.Single(Run(new AxBatchStuckRule(), With(Batch(oneLongRun))).Findings);
var stuckWithHistory = Job30(row, History("4711|dat|NAT", 10, TimeSpan.FromMinutes(20)), Utc.AddHours(-7));
Assert.Single(Run(new AxBatchStuckRule(), With(Batch(stuckWithHistory))).Findings);
Assert.Equal(RuleOutcome.Passed, Run(new AxBatchLongRunningRule(), With(Batch(stuckWithHistory))).Outcome);
}
[Fact]
public void An_executing_job_without_any_start_time_is_skipped_not_an_error()
{
var unknown = Job30(Batch30(70, 1, Utc.AddHours(-9)), History("4711|dat|NAT", 10, TimeSpan.FromMinutes(20)));
Assert.Null(unknown.Running(Now));
Assert.Equal(RuleOutcome.Passed, Run(new AxBatchStuckRule(), With(Batch(unknown))).Outcome);
Assert.Equal(RuleOutcome.Passed, Run(new AxBatchLongRunningRule(), With(Batch(unknown))).Outcome);
}
}