Florian Schmidt
5a6f34a467
ci / build-test (push) Successful in 2m34s
Three things the 1,000-meter x 10-year measurement found, each proved by EXPLAIN or a statement count before and after. No tally moves. Freshness had two jobs in one unbounded query. The mark -- when a meter last delivered -- is now stored on meter_rollup_state and maintained by every recompute, with a one-pass backfill in the migration, so an import-only meter keeps its years-old last activity without reading a single raw row. The rhythm that decides stale versus live is sampled inside a 90-day window and only for meters that actually have a live source; a source silent for longer than that is re-read unbounded, so it is still called stale by its own rhythm rather than by a default. The portfolio query went from 13.8 ms planning plus 36.1 ms execution across all 123 reading chunks to 0.58 plus 0.44 ms across four. Window sums took their time bounds only from the unnest join, so the planner could not exclude chunks: a 1,960-window case scanned 1.39 M rows in parallel and spilled a 45 MB sort. Repeating the overall min and max as constants makes it five chunks and nested-loop index scans, 121.5 ms to 8.7 ms. The Overview read the catalog three times, once for the quantities and once for each of its two bills. One context and one catalog snapshot now feed all three: 31 statements per load to 23. The final timings on an idle machine are in docs/ANALYSIS_REPORT.md: the brief's target request (100 meters, ten years, monthly) is 286 ms against two seconds, and a startup rebuild of 1,000 meters is 279 s.
588 lines
36 KiB
C#
588 lines
36 KiB
C#
using System.Diagnostics;
|
||
using System.Globalization;
|
||
using System.Text;
|
||
using System.Text.Json;
|
||
using MeterVault.Core.Analysis;
|
||
using MeterVault.Core.Analysis.Rollups;
|
||
using MeterVault.Core.Normalization;
|
||
using MeterVault.Infrastructure.Analysis;
|
||
using MeterVault.Infrastructure.Costing;
|
||
using MeterVault.Infrastructure.Options;
|
||
using Npgsql;
|
||
using static MeterVault.Integration.Tests.Performance.PerfReport;
|
||
using Xunit.Abstractions;
|
||
|
||
namespace MeterVault.Integration.Tests.Performance;
|
||
|
||
/// <summary>
|
||
/// Reader and cost timings on the synthetic 1,000-meter decade (brief §9.10, D-56): the brief's target (cached metadata
|
||
/// plus a ten-year monthly request for 100 meters within two seconds), portfolio, energy-type, meter, virtual and bill
|
||
/// requests, the refusals a 1,000-meter selection meets before any SQL, the SQL each request sends, and the plans of
|
||
/// the reader's main queries. Writes <c>results-<label>.md</c> (and <c>.json</c>) to the output directory.
|
||
/// </summary>
|
||
/// <remarks>
|
||
/// Skipped unless <c>METERVAULT_PERF=1</c> (see <see cref="PerfSettings"/>). Run it alone, in Release, on a quiet machine:
|
||
/// <c>dotnet test tests/Integration.Tests -c Release --filter "FullyQualifiedName~Performance.ReaderTimingTests"</c>.
|
||
/// The numbers are measured, not asserted; only correctness of the measured requests (and the zero-SQL refusals) is.
|
||
/// </remarks>
|
||
[Trait("Category", "Performance")]
|
||
public sealed class ReaderTimingTests(ITestOutputHelper output)
|
||
{
|
||
/// <summary>The brief's proposed review target for (a).</summary>
|
||
private const double TargetMilliseconds = 2000;
|
||
|
||
[PerfFact]
|
||
public async Task Reader_and_cost_timings_on_a_synthetic_1000_meter_decade()
|
||
{
|
||
var settings = PerfSettings.Current;
|
||
using var log = new PerfLog(settings, "reader", output);
|
||
var loadBefore = await HostLoadAsync(TimeSpan.FromSeconds(3));
|
||
log.Write($"Host load before: {loadBefore}");
|
||
|
||
await using var database = await PerfDatabase.OpenAsync(settings, log);
|
||
var prepared = await database.PrepareAsync(settings, log);
|
||
var manifest = prepared.Manifest;
|
||
|
||
var zone = TimeZoneInfo.FindSystemTimeZoneById(manifest.Zone);
|
||
var options = Microsoft.Extensions.Options.Options.Create(new MeterVaultOptions { TimeZone = manifest.Zone, Currency = "EUR" });
|
||
var reader = new AnalysisReader(database, options);
|
||
var costs = new CostReader(database, reader, options);
|
||
var now = manifest.Now;
|
||
var today = DateOnly.FromDateTime(TimeZoneInfo.ConvertTime(now, zone).DateTime);
|
||
var currentMonth = new DateOnly(today.Year, today.Month, 1);
|
||
var firstMonth = currentMonth.AddMonths(-119);
|
||
|
||
ResolvedPeriod Custom(DateOnly first, DateOnly last) => PeriodResolver.Resolve(PeriodPreset.Custom, first, last, now, zone);
|
||
ResolvedPeriod Preset(PeriodPreset preset) => PeriodResolver.Resolve(preset, null, null, now, zone);
|
||
|
||
var tenYears = Custom(firstMonth, currentMonth.AddMonths(1).AddDays(-1));
|
||
var lastYearByDay = Custom(today.AddDays(-364), today);
|
||
var last12 = Preset(PeriodPreset.Last12Months);
|
||
var selection = manifest.Selection100;
|
||
var all = manifest.AllMeterIds;
|
||
var electricity = manifest.EnergyTypes["electricity"];
|
||
var samples = manifest.Samples;
|
||
|
||
// The catalog is the metadata a page holds for its lifetime: loaded once, then every request reads data only.
|
||
var catalog = await reader.LoadCatalogAsync();
|
||
var invalid = catalog.Meters.Values.Where(m => m.IsVirtual && m.VirtualStatus != VirtualMeterStatus.Valid).Select(m => $"{m.Name}: {m.VirtualStatus}").ToList();
|
||
log.Write(invalid.Count == 0 ? "All virtual meters validate" : "Virtual meters that do not validate: " + string.Join("; ", invalid));
|
||
|
||
async Task<AnalysisResult> Cached(AnalysisRequest request)
|
||
{
|
||
await using var db = database.CreateDbContext();
|
||
return await reader.ReadAsync(db, catalog, request, CancellationToken.None);
|
||
}
|
||
|
||
var scenarios = new List<(string Id, string Description, Func<Task<string>> Run)>
|
||
{
|
||
("a", "100 selected meters (60 monthly, 25 daily, 10 live, 5 virtual), 10 years by month, catalog cached — the brief's target",
|
||
async () => Describe(await Cached(new AnalysisRequest(AnalysisScope.ForMeters(selection), tenYears) { Bucket = BucketSize.Month, MaxSeries = selection.Length }))),
|
||
("a'", "Same through the public API (catalog loaded by the request)",
|
||
async () => Describe(await reader.ReadAsync(new AnalysisRequest(AnalysisScope.ForMeters(selection), tenYears) { Bucket = BucketSize.Month, MaxSeries = selection.Length }))),
|
||
("b", "Portfolio, last 12 months by month (measures only, as the overview)",
|
||
async () => Describe(await reader.ReadAsync(new AnalysisRequest(AnalysisScope.Portfolio, last12) { Bucket = BucketSize.Month }))),
|
||
("b'", "Portfolio, last 12 months by month, with one series per meter",
|
||
async () => Describe(await reader.ReadAsync(new AnalysisRequest(AnalysisScope.Portfolio, last12) { Bucket = BucketSize.Month, IncludeMeterSeries = true }))),
|
||
("b''", "Portfolio, last 12 months by month, compared with the previous year",
|
||
async () => Describe(await reader.ReadAsync(new AnalysisRequest(AnalysisScope.Portfolio, last12)
|
||
{
|
||
Bucket = BucketSize.Month,
|
||
Comparison = new ComparisonRequest(ComparisonKind.PreviousYear),
|
||
}))),
|
||
("c", "Electricity type (≈420 meters), 10 years by month (measures only)",
|
||
async () => Describe(await reader.ReadAsync(new AnalysisRequest(AnalysisScope.ForEnergyType(electricity), tenYears) { Bucket = BucketSize.Month }))),
|
||
("c'", "Electricity type, 10 years by month, with one series per meter (the type page's table)",
|
||
async () => Describe(await reader.ReadAsync(new AnalysisRequest(AnalysisScope.ForEnergyType(electricity), tenYears) { Bucket = BucketSize.Month, IncludeMeterSeries = true }))),
|
||
("d", "One daily meter, 10 years by week (point limit raised to 600)",
|
||
async () => Describe(await reader.ReadAsync(new AnalysisRequest(AnalysisScope.ForMeter(samples["dailyMeter"]), tenYears) { Bucket = BucketSize.Week, MaxPoints = 600 }))),
|
||
("d'", "One monthly meter, 10 years by week (point limit raised to 600)",
|
||
async () => Describe(await reader.ReadAsync(new AnalysisRequest(AnalysisScope.ForMeter(samples["monthlyMeter"]), tenYears) { Bucket = BucketSize.Week, MaxPoints = 600 }))),
|
||
("d''", "One daily meter, the last 365 days by day",
|
||
async () => Describe(await reader.ReadAsync(new AnalysisRequest(AnalysisScope.ForMeter(samples["dailyMeter"]), lastYearByDay) { Bucket = BucketSize.Day }))),
|
||
("d'''", "One live (hourly) meter, the last 365 days by day",
|
||
async () => Describe(await reader.ReadAsync(new AnalysisRequest(AnalysisScope.ForMeter(samples["liveMeter"]), lastYearByDay) { Bucket = BucketSize.Day }))),
|
||
("e", "Portfolio bill, last 12 months by month, with categories",
|
||
async () => Describe(await costs.ReadAsync(new CostAnalysisRequest(CostScope.Portfolio, last12) { Bucket = BucketSize.Month, IncludeCategories = true }))),
|
||
("e'", "Portfolio bill, 10 years by month",
|
||
async () => Describe(await costs.ReadAsync(new CostAnalysisRequest(CostScope.Portfolio, tenYears) { Bucket = BucketSize.Month }))),
|
||
("f", "Virtual meter nested three levels (over 15 monthly, 10 daily, 2 differenced sources), 10 years by month",
|
||
async () => Describe(await reader.ReadAsync(new AnalysisRequest(AnalysisScope.ForMeter(samples["virtualNested"]), tenYears) { Bucket = BucketSize.Month }))),
|
||
("f'", "Virtual difference of a 40-meter sum and an 8-meter live sum, 10 years by month",
|
||
async () => Describe(await reader.ReadAsync(new AnalysisRequest(AnalysisScope.ForMeter(samples["virtualBigDifference"]), tenYears) { Bucket = BucketSize.Month }))),
|
||
("g", "1,000-meter selection with the chart limit (6 series): refused",
|
||
async () => Describe(await reader.ReadAsync(new AnalysisRequest(AnalysisScope.ForMeters(all), last12) { Bucket = BucketSize.Month }))),
|
||
("g'", "Portfolio by day over 10 years: refused (point limit)",
|
||
async () => Describe(await reader.ReadAsync(new AnalysisRequest(AnalysisScope.Portfolio, tenYears) { Bucket = BucketSize.Day }))),
|
||
("g''", "Portfolio bill by day over 10 years: refused (point limit)",
|
||
async () => Describe(await costs.ReadAsync(new CostAnalysisRequest(CostScope.Portfolio, tenYears) { Bucket = BucketSize.Day }))),
|
||
("g'''", "Catalog load: 1,000 meters, tanks, links, rollup states; virtual definitions validated, totals classified",
|
||
async () => $"{(await reader.LoadCatalogAsync()).Meters.Count} meters"),
|
||
("g''''", "1,000-meter selection with the limit raised (as an export may), last 12 months by month",
|
||
async () => Describe(await reader.ReadAsync(new AnalysisRequest(AnalysisScope.ForMeters(all), last12) { Bucket = BucketSize.Month, MaxSeries = int.MaxValue }))),
|
||
};
|
||
|
||
var loadDuring = HostLoadAsync(TimeSpan.FromSeconds(3));
|
||
var timings = new List<ScenarioTiming>();
|
||
foreach (var (id, description, run) in scenarios)
|
||
{
|
||
timings.Add(await MeasureAsync(id, description, run, settings, log));
|
||
}
|
||
|
||
// What the measured requests must hold, whatever they took.
|
||
var target = timings.Single(t => t.Id == "a");
|
||
Assert.True(target.Commands > 0, "The command counter saw no SQL for a request that reads data; Npgsql tracing did not reach it.");
|
||
foreach (var refused in timings.Where(t => t.Id.StartsWith('g') && t.Shape.StartsWith("refused", StringComparison.Ordinal)))
|
||
{
|
||
if (refused.Commands != 0)
|
||
{
|
||
Assert.Fail($"{refused.Id} was refused but sent {refused.Commands} SQL command(s): {string.Join(" / ", refused.Statements)}");
|
||
}
|
||
}
|
||
|
||
Assert.StartsWith("refused", timings.Single(t => t.Id == "g").Shape, StringComparison.Ordinal);
|
||
Assert.StartsWith("refused", timings.Single(t => t.Id == "g'").Shape, StringComparison.Ordinal);
|
||
Assert.StartsWith("refused", timings.Single(t => t.Id == "g''").Shape, StringComparison.Ordinal);
|
||
Assert.Contains($"{selection.Length} series", target.Shape, StringComparison.Ordinal);
|
||
|
||
var recomputes = await RecomputeTimingsAsync(database, manifest, log);
|
||
var plans = await PlansAsync(database, catalog, manifest, zone, firstMonth, currentMonth, today, log);
|
||
|
||
await using var connection = new NpgsqlConnection(database.ConnectionString);
|
||
await connection.OpenAsync();
|
||
var markdown = await WriteReportAsync(
|
||
settings, database, connection, prepared, timings, recomputes, plans, invalid, loadBefore, await loadDuring, catalog.Meters.Count);
|
||
log.Write($"Results written to {markdown}");
|
||
}
|
||
|
||
// ------------------------------------------------------------------------------------------------ measuring
|
||
|
||
private static async Task<ScenarioTiming> MeasureAsync(string id, string description, Func<Task<string>> run, PerfSettings settings, PerfLog log)
|
||
{
|
||
for (var i = 0; i < settings.Warmup; i++)
|
||
{
|
||
await run();
|
||
}
|
||
|
||
// One counted run, untimed: the listener is only attached while counting.
|
||
int commands;
|
||
IReadOnlyList<string> statements;
|
||
string shape;
|
||
double sql;
|
||
using (var counter = CommandCounter.Start())
|
||
{
|
||
shape = await run();
|
||
commands = counter.Count;
|
||
statements = counter.Statements;
|
||
sql = counter.Duration.TotalMilliseconds;
|
||
}
|
||
|
||
var times = new List<double>();
|
||
for (var i = 0; i < settings.Runs; i++)
|
||
{
|
||
var watch = Stopwatch.StartNew();
|
||
await run();
|
||
times.Add(watch.Elapsed.TotalMilliseconds);
|
||
}
|
||
|
||
var timing = new ScenarioTiming(id, description, times, commands, statements, shape) { SqlMilliseconds = sql };
|
||
log.Write($"({id}) median {F(timing.Median)} ms, p95 {F(timing.P95)} ms, {commands} SQL taking {F(sql)} ms — {shape}");
|
||
return timing;
|
||
}
|
||
|
||
private static string Describe(AnalysisResult result)
|
||
{
|
||
if (result.Refusal != AnalysisRefusal.None)
|
||
{
|
||
return $"refused ({result.Refusal})";
|
||
}
|
||
|
||
var values = result.Series.Concat(result.Measures).SelectMany(s => s.Values).ToList();
|
||
var statuses = values.GroupBy(v => v.Status).OrderBy(g => g.Key).Select(g => string.Create(CultureInfo.InvariantCulture, $"{g.Key} {g.Count()}"));
|
||
return string.Create(
|
||
CultureInfo.InvariantCulture,
|
||
$"{result.Series.Count} series · {result.Measures.Count} measures · {result.Plan.Buckets.Count} {result.Plan.Size} buckets · {string.Join(", ", statuses)}");
|
||
}
|
||
|
||
private static string Describe(CostAnalysis bill)
|
||
{
|
||
if (bill.Refusal != CostRefusal.None)
|
||
{
|
||
return $"refused ({bill.Refusal})";
|
||
}
|
||
|
||
return string.Create(
|
||
CultureInfo.InvariantCulture,
|
||
$"{bill.Plan.Buckets.Count} {bill.Plan.Size} buckets · total {bill.Total.Cost ?? double.NaN:N0} {bill.Currency} ({bill.Total.Status}) · {bill.Lines.Count} lines · {bill.EnergyTypes.Count} types · categories {(bill.Composition is null ? "no" : "yes")}");
|
||
}
|
||
|
||
/// <summary>
|
||
/// How long one meter's full recompute takes (D-57: it still runs per live reading): delete and rewrite its
|
||
/// consumption, diff its rollups and coverage — as <c>IngestionService</c> does after each reading.
|
||
/// </summary>
|
||
private static async Task<List<(string Meter, int Readings, ScenarioTiming Timing)>> RecomputeTimingsAsync(
|
||
PerfDatabase database, DatasetManifest manifest, PerfLog log)
|
||
{
|
||
var result = new List<(string, int, ScenarioTiming)>();
|
||
(string Name, int Id)[] meters =
|
||
[
|
||
("monthly counter", manifest.Samples["monthlyMeter"]),
|
||
("imported month labels", manifest.Samples["labelMeter"]),
|
||
("daily counter", manifest.Samples["dailyMeter"]),
|
||
("live meter (hourly for a year)", manifest.Samples["liveMeter"]),
|
||
("tank", manifest.Samples["tankMeter"]),
|
||
("virtual (purge + state only)", manifest.Samples["virtualNested"]),
|
||
];
|
||
|
||
await using var connection = new NpgsqlConnection(database.ConnectionString);
|
||
await connection.OpenAsync();
|
||
foreach (var (name, id) in meters)
|
||
{
|
||
var readings = Convert.ToInt32(
|
||
await PerfDatabase.ScalarAsync(connection, string.Create(CultureInfo.InvariantCulture, $"SELECT count(*) FROM reading WHERE meter_id = {id}")),
|
||
CultureInfo.InvariantCulture);
|
||
var times = new List<double>();
|
||
for (var i = 0; i < 4; i++)
|
||
{
|
||
await using var db = database.CreateDbContext();
|
||
await using var tx = await db.Database.BeginTransactionAsync();
|
||
var watch = Stopwatch.StartNew();
|
||
await PerfDatabase.Normalization(db, manifest).RecomputeMeterAsync(id, batchId: null);
|
||
await db.SaveChangesAsync();
|
||
await tx.CommitAsync();
|
||
if (i > 0)
|
||
{
|
||
times.Add(watch.Elapsed.TotalMilliseconds);
|
||
}
|
||
}
|
||
|
||
var timing = new ScenarioTiming(name, name, times, 0, [], string.Empty);
|
||
log.Write($"Recompute {name} ({readings} readings): median {F(timing.Median)} ms");
|
||
result.Add((name, readings, timing));
|
||
}
|
||
|
||
return result;
|
||
}
|
||
|
||
// ------------------------------------------------------------------------------------------------ query plans
|
||
|
||
/// <summary>
|
||
/// EXPLAIN (ANALYZE, BUFFERS) of the reader's queries (copied from <c>AnalysisQueries</c>) with the parameters request
|
||
/// (a) — and, for the portfolio and day cases, (b) and (d'') — would send.
|
||
/// </summary>
|
||
private static async Task<List<(string Title, string Sql, string Plan)>> PlansAsync(
|
||
PerfDatabase database, AnalysisCatalog catalog, DatasetManifest manifest, TimeZoneInfo zone,
|
||
DateOnly firstMonth, DateOnly currentMonth, DateOnly today, PerfLog log)
|
||
{
|
||
var plans = new List<(string, string, string)>();
|
||
await using var connection = new NpgsqlConnection(database.ConnectionString);
|
||
await connection.OpenAsync();
|
||
|
||
var leaves = catalog.PhysicalLeaves(manifest.Selection100).Order().ToArray();
|
||
var virtualSources = manifest.Selection100.Where(id => catalog.Find(id)?.IsVirtual == true)
|
||
.SelectMany(id => catalog.PhysicalLeaves([id])).ToHashSet();
|
||
var portfolio = catalog.Meters.Values.Where(m => !m.IsVirtual).Select(m => m.Id).Order().ToArray();
|
||
var now = manifest.Now.UtcDateTime;
|
||
DateTime Midnight(DateOnly day) => GapAttribution.LocalMidnight(day, zone).UtcDateTime;
|
||
|
||
const string month = """
|
||
SELECT r.meter_id, r.month, r.kind, r.amount, r.measured, r.manual, r.imported, r.estimated, r.rows, r.flags,
|
||
r.max_interval_end
|
||
FROM unnest(@ids, @froms, @tos) AS w(meter_id, from_month, to_month)
|
||
JOIN consumption_rollup_month r ON r.meter_id = w.meter_id AND r.month >= w.from_month AND r.month < w.to_month
|
||
""";
|
||
const string day = """
|
||
SELECT r.meter_id, r.day, r.kind, r.amount, r.measured, r.manual, r.imported, r.estimated, r.rows, r.flags,
|
||
r.max_interval_end, false AS after_now
|
||
FROM unnest(@ids, @froms, @tos) AS w(meter_id, from_day, to_day)
|
||
JOIN consumption_rollup r ON r.meter_id = w.meter_id AND r.day >= w.from_day AND r.day < w.to_day
|
||
UNION ALL
|
||
SELECT r.meter_id, r.day, r.kind, r.amount, r.measured, r.manual, r.imported, r.estimated, r.rows, r.flags,
|
||
r.max_interval_end, true AS after_now
|
||
FROM consumption_rollup r
|
||
WHERE r.meter_id = ANY(@after_ids) AND r.day >= @after_from AND r.day < @after_to AND r.max_interval_end > @now
|
||
""";
|
||
const string raw = "SELECT meter_id, time, amount, quality FROM consumption WHERE meter_id = ANY(@i0) AND time >= @f0 AND time < @t0";
|
||
const string windows = """
|
||
SELECT w.idx, count(*)::int, sum(c.amount),
|
||
coalesce(sum(c.amount) FILTER (WHERE c.quality = 0), 0),
|
||
coalesce(sum(c.amount) FILTER (WHERE c.quality = 2), 0),
|
||
coalesce(sum(c.amount) FILTER (WHERE c.quality = 3), 0),
|
||
coalesce(sum(c.amount) FILTER (WHERE c.quality NOT IN (0, 2, 3)), 0)
|
||
FROM unnest(@ids, @froms, @tos) WITH ORDINALITY AS w(meter_id, from_time, to_time, idx)
|
||
JOIN consumption c ON c.meter_id = w.meter_id AND c.time >= w.from_time AND c.time < w.to_time
|
||
WHERE c.time >= @min_from AND c.time < @max_to
|
||
GROUP BY w.idx
|
||
""";
|
||
|
||
// Not the reader's SQL any more (A-40): the same statement without the overall bounds, to show what plan-time
|
||
// chunk exclusion saves.
|
||
const string windowsUnbounded = """
|
||
SELECT w.idx, count(*)::int, sum(c.amount),
|
||
coalesce(sum(c.amount) FILTER (WHERE c.quality = 0), 0),
|
||
coalesce(sum(c.amount) FILTER (WHERE c.quality = 2), 0),
|
||
coalesce(sum(c.amount) FILTER (WHERE c.quality = 3), 0),
|
||
coalesce(sum(c.amount) FILTER (WHERE c.quality NOT IN (0, 2, 3)), 0)
|
||
FROM unnest(@ids, @froms, @tos) WITH ORDINALITY AS w(meter_id, from_time, to_time, idx)
|
||
JOIN consumption c ON c.meter_id = w.meter_id AND c.time >= w.from_time AND c.time < w.to_time
|
||
GROUP BY w.idx
|
||
""";
|
||
const string coverage = """
|
||
SELECT meter_id, span_from, span_to, resolution_class, divided_at_months, gap_reason, last_interval_start
|
||
FROM meter_coverage
|
||
WHERE meter_id = ANY(@ids)
|
||
ORDER BY meter_id, span_from
|
||
""";
|
||
const string opening = """
|
||
SELECT m.id, c.time
|
||
FROM unnest(@ids) AS m(id)
|
||
CROSS JOIN LATERAL (
|
||
SELECT r.flags FROM consumption_rollup r WHERE r.meter_id = m.id ORDER BY r.day LIMIT 1) f
|
||
CROSS JOIN LATERAL (
|
||
SELECT c.time FROM consumption c WHERE c.meter_id = m.id ORDER BY c.time LIMIT 1) c
|
||
WHERE (f.flags & @flag) <> 0
|
||
""";
|
||
const string recent = """
|
||
SELECT m.id, r.time
|
||
FROM unnest(@ids) AS m(id)
|
||
CROSS JOIN LATERAL (
|
||
SELECT time FROM reading WHERE meter_id = m.id AND time >= @since ORDER BY time DESC LIMIT @count) r
|
||
""";
|
||
|
||
// Not the reader's SQL any more (A-40): the same statement without the window bound, which is what made every
|
||
// non-quantities-only request plan across every raw chunk.
|
||
const string recentUnbounded = """
|
||
SELECT m.id, r.time
|
||
FROM unnest(@ids) AS m(id)
|
||
CROSS JOIN LATERAL (
|
||
SELECT time FROM reading WHERE meter_id = m.id ORDER BY time DESC LIMIT @count) r
|
||
""";
|
||
const string events = "SELECT meter_id, max(time) FROM meter_event WHERE meter_id = ANY(@ids) GROUP BY meter_id";
|
||
|
||
async Task PlanAsync(string title, string sql, params (string Name, object Value)[] parameters)
|
||
{
|
||
try
|
||
{
|
||
await using var command = new NpgsqlCommand("EXPLAIN (ANALYZE, BUFFERS, SETTINGS) " + sql, connection) { CommandTimeout = 0 };
|
||
foreach (var (name, value) in parameters)
|
||
{
|
||
command.Parameters.AddWithValue(name, value);
|
||
}
|
||
|
||
var lines = new List<string>();
|
||
await using var reader = await command.ExecuteReaderAsync();
|
||
while (await reader.ReadAsync())
|
||
{
|
||
lines.Add(reader.GetString(0));
|
||
}
|
||
|
||
plans.Add((title, sql, string.Join('\n', lines)));
|
||
}
|
||
catch (PostgresException ex)
|
||
{
|
||
plans.Add((title, sql, "EXPLAIN failed: " + ex.MessageText));
|
||
}
|
||
}
|
||
|
||
var dayFroms = leaves.Select(id => virtualSources.Contains(id) ? firstMonth : currentMonth).ToArray();
|
||
var afterTo = currentMonth.AddMonths(1);
|
||
log.Write("Capturing query plans…");
|
||
|
||
await PlanAsync($"(a) month rollups — {leaves.Length} physical leaves × {firstMonth:yyyy-MM} … {currentMonth.AddMonths(-1):yyyy-MM}", month,
|
||
("ids", leaves), ("froms", leaves.Select(_ => firstMonth).ToArray()), ("tos", leaves.Select(_ => currentMonth).ToArray()));
|
||
await PlanAsync($"(a) day rollups — the current month's complete days for every leaf, every day for virtual sources ({virtualSources.Count}), plus the after-now block", day,
|
||
("ids", leaves), ("froms", dayFroms), ("tos", leaves.Select(_ => today).ToArray()),
|
||
("after_ids", leaves), ("after_from", today.AddDays(1)), ("after_to", afterTo), ("now", now));
|
||
await PlanAsync($"(a) partial edge day — today ({today:yyyy-MM-dd}) from consumption", raw,
|
||
("i0", leaves), ("f0", Midnight(today)), ("t0", Midnight(today.AddDays(1))));
|
||
await PlanAsync("(a) coverage runs", coverage, ("ids", leaves));
|
||
await PlanAsync("(a) opening balances", opening, ("ids", leaves), ("flag", (int)RollupFlags.OpeningBalance));
|
||
var since = now.AddDays(-FreshnessRules.RecentWindow.TotalDays);
|
||
var liveMeters = manifest.Groups["live"];
|
||
await PlanAsync(
|
||
$"(a) freshness — the rhythm of the live meters among the leaves, {FreshnessRules.RecentWindow.TotalDays:F0} days back (reading is compressed after 30 days)",
|
||
recent, ("ids", leaves.Where(liveMeters.Contains).ToArray()), ("since", since), ("count", FreshnessRules.RecentReadingCount));
|
||
await PlanAsync("(a) freshness — the latest event per meter", events, ("ids", leaves));
|
||
await PlanAsync($"(b) freshness — the rhythm of every live meter ({liveMeters.Length}), as a portfolio request loads it", recent,
|
||
("ids", liveMeters), ("since", since), ("count", FreshnessRules.RecentReadingCount));
|
||
await PlanAsync(
|
||
$"(comparison, not the reader's SQL) the same statement unbounded for every physical meter ({portfolio.Length}), as it was sent before A-40",
|
||
recentUnbounded, ("ids", portfolio), ("count", FreshnessRules.RecentReadingCount));
|
||
|
||
var daily = manifest.Samples["dailyMeter"];
|
||
await PlanAsync("(d) freshness — one live meter, as a single-meter request sends it", recent,
|
||
("ids", new[] { manifest.Samples["liveMeter"] }), ("since", since), ("count", FreshnessRules.RecentReadingCount));
|
||
await PlanAsync("(comparison, not the reader's SQL) the same for one daily meter, unbounded, as it was sent before A-40", recentUnbounded,
|
||
("ids", new[] { daily }), ("count", FreshnessRules.RecentReadingCount));
|
||
await PlanAsync($"(b) month rollups — portfolio, {portfolio.Length} physical meters × the 11 complete months of the last 12", month,
|
||
("ids", portfolio), ("froms", portfolio.Select(_ => currentMonth.AddMonths(-11)).ToArray()), ("tos", portfolio.Select(_ => currentMonth).ToArray()));
|
||
|
||
var yearAgo = today.AddYears(-1);
|
||
var nowLocal = TimeZoneInfo.ConvertTimeFromUtc(now, zone);
|
||
var yearAgoCut = TimeZoneInfo.ConvertTimeToUtc(yearAgo.ToDateTime(TimeOnly.FromDateTime(nowLocal)), zone);
|
||
var single = manifest.Samples["monthlyMeter"];
|
||
await PlanAsync("(b'') window sums — one meter's two partial days (today, and its image a year ago): the small case", windows,
|
||
("ids", new[] { single, single }),
|
||
("froms", new[] { Midnight(today), Midnight(yearAgo) }),
|
||
("tos", new[] { now, yearAgoCut }),
|
||
("min_from", Midnight(yearAgo)), ("max_to", now));
|
||
|
||
var stressIds = portfolio.Concat(portfolio).ToArray();
|
||
var stressFroms = portfolio.Select(_ => Midnight(today)).Concat(portfolio.Select(_ => Midnight(yearAgo))).ToArray();
|
||
var stressTos = portfolio.Select(_ => now).Concat(portfolio.Select(_ => yearAgoCut)).ToArray();
|
||
await PlanAsync(
|
||
$"(b'') window sums — stress case, not what (b'') sends (see its SQL list): today's partial day and its image a year ago for all {portfolio.Length} meters",
|
||
windows,
|
||
("ids", stressIds), ("froms", stressFroms), ("tos", stressTos),
|
||
("min_from", stressFroms.Min()), ("max_to", stressTos.Max()));
|
||
await PlanAsync(
|
||
"(comparison, not the reader's SQL) the same stress case without the overall bounds, as it was sent before A-40",
|
||
windowsUnbounded, ("ids", stressIds), ("froms", stressFroms), ("tos", stressTos));
|
||
|
||
await PlanAsync("(d'') day rollups — one daily meter, the last 365 days", day,
|
||
("ids", new[] { daily }), ("froms", new[] { today.AddDays(-364) }), ("tos", new[] { today }),
|
||
("after_ids", new[] { daily }), ("after_from", today.AddDays(1)), ("after_to", today.AddDays(1)), ("now", now));
|
||
return plans;
|
||
}
|
||
|
||
// ------------------------------------------------------------------------------------------------ report
|
||
|
||
private static async Task<string> WriteReportAsync(
|
||
PerfSettings settings,
|
||
PerfDatabase database,
|
||
NpgsqlConnection connection,
|
||
PreparedDatabase prepared,
|
||
List<ScenarioTiming> timings,
|
||
List<(string Meter, int Readings, ScenarioTiming Timing)> recomputes,
|
||
List<(string Title, string Sql, string Plan)> plans,
|
||
List<string> invalidVirtuals,
|
||
string loadBefore,
|
||
string loadDuring,
|
||
int catalogMeters)
|
||
{
|
||
var manifest = prepared.Manifest;
|
||
var md = new StringBuilder();
|
||
md.AppendLine(CultureInfo.InvariantCulture, $"# Analysis reader performance — {settings.Label}");
|
||
md.AppendLine();
|
||
md.AppendLine(CultureInfo.InvariantCulture, $"Measured {DateTimeOffset.Now:yyyy-MM-dd HH:mm zzz}. Brief §9.10 / D-56. Dataset \"now\": {manifest.Now:O} ({manifest.Zone}).");
|
||
md.AppendLine(CultureInfo.InvariantCulture, $"{settings.Warmup} warm-up run(s), then {settings.Runs} measured runs per scenario; the SQL count comes from one extra untimed run.");
|
||
if (settings.Note is { } note)
|
||
{
|
||
md.AppendLine().AppendLine(CultureInfo.InvariantCulture, $"> Note: {note}");
|
||
}
|
||
|
||
md.AppendLine();
|
||
md.AppendLine("## Machine");
|
||
md.AppendLine();
|
||
var machine = Machine().Select(m => (IReadOnlyList<string>)[m.Name, m.Value]).ToList();
|
||
machine.Add(["Host load before the run", loadBefore]);
|
||
machine.Add(["Host load while measuring", loadDuring]);
|
||
machine.Add(["Database", database.Origin]);
|
||
foreach (var (name, value) in await DatabaseAsync(connection))
|
||
{
|
||
machine.Add([name, value]);
|
||
}
|
||
|
||
Table(md, ["", "Value"], machine);
|
||
|
||
md.AppendLine("## Dataset");
|
||
md.AppendLine();
|
||
md.AppendLine(CultureInfo.InvariantCulture,
|
||
$"{manifest.MeterCount} meters (scale {F(manifest.Scale, 2)}): {string.Join(", ", manifest.Groups.Select(g => $"{g.Value.Length} {g.Key}"))}. " +
|
||
$"{manifest.EnergyTypes.Count} energy types, {manifest.Links} links, {manifest.Tariffs} tariff rows, {manifest.CategoryMembers} category members, {manifest.ManualCosts} manual costs, {N(manifest.Events)} events.");
|
||
md.AppendLine();
|
||
md.AppendLine("Monthly counters mix readings at local midnight on the 1st, imported month labels (00:00 UTC, flagged) and irregular manual readings " +
|
||
"(divided at month ends); some have no install date (opening balance), start late, retire in 2022, or have a register swap. Daily counters read at 06:xx, " +
|
||
"live meters hourly for the last year (monthly before), generation counters in the evening; the electricity type and two extra sites have grid import/export roles. " +
|
||
"Twenty virtual meters are sums and differences, nested up to three levels. The cost setup has yearly unit-price changes (a mid-2022 spike for electricity and gas), " +
|
||
"standing charges, feed-in, five meter prices on linked subsections, four categories (one overlapping) and manual costs.");
|
||
md.AppendLine();
|
||
Table(md, ["Table", "Rows", "Size", "Chunks"], (await TablesAsync(connection)).Select(t => (IReadOnlyList<string>)[t.Table, N(t.Rows), t.Size, t.Note]));
|
||
|
||
md.AppendLine("## Loading and rebuild");
|
||
md.AppendLine();
|
||
var steps = new List<IReadOnlyList<string>>();
|
||
steps.Add(prepared.Loaded
|
||
? ["Raw load (binary COPY of readings, plus configuration)", F(manifest.LoadSeconds) + " s", $"{N(manifest.Readings)} readings; COPY itself {F(manifest.CopySeconds)} s"]
|
||
: ["Raw load", "reused", $"{N(manifest.Readings)} readings loaded earlier (COPY {F(manifest.CopySeconds)} s, total {F(manifest.LoadSeconds)} s)"]);
|
||
if (prepared.Rebuild is { } rebuild)
|
||
{
|
||
steps.Add([
|
||
"Startup rebuild (NormalizationUpgrade: consumption, rollups, coverage, state)",
|
||
F(rebuild.Seconds) + " s",
|
||
$"{rebuild.Rebuilt} of {rebuild.Meters} meters, {F(rebuild.Meters / rebuild.Seconds)} meters/s{(rebuild.MeasuredInThisRun ? string.Empty : " (measured when the dataset was loaded)")}",
|
||
]);
|
||
}
|
||
|
||
steps.Add(prepared.CompressSeconds is { } compress
|
||
? ["Compression of raw chunks older than 30 days", F(compress) + " s", $"{prepared.CompressedChunks} chunks"]
|
||
: ["Compression of raw chunks older than 30 days", "—", "already compressed"]);
|
||
Table(md, ["Step", "Time", "Detail"], steps);
|
||
|
||
md.AppendLine("One meter's full recompute (what every ingested reading triggers, D-57), median of 3 after a warm-up:");
|
||
md.AppendLine();
|
||
Table(md, ["Meter", "Readings", "Median ms", "Min ms", "Max ms"],
|
||
recomputes.Select(r => (IReadOnlyList<string>)[r.Meter, N(r.Readings), F(r.Timing.Median), F(r.Timing.Min), F(r.Timing.Max)]));
|
||
|
||
md.AppendLine("## Reader and cost timings");
|
||
md.AppendLine();
|
||
md.AppendLine(CultureInfo.InvariantCulture, $"Catalog: {catalogMeters} meters. {(invalidVirtuals.Count == 0 ? "All virtual meters validate." : "Virtual meters that do not validate: " + string.Join("; ", invalidVirtuals))}");
|
||
md.AppendLine();
|
||
md.AppendLine("*SQL* is the number of commands one extra, untimed run sent, and *SQL ms* their summed duration (Npgsql activity: execution " +
|
||
"until the reader is closed, so row materialization is included); the rest of the median is in-process work.");
|
||
md.AppendLine();
|
||
Table(md, ["", "Request", "Median ms", "p95 ms", "Min ms", "Max ms", "SQL", "SQL ms", "Result"],
|
||
timings.Select(t => (IReadOnlyList<string>)[
|
||
t.Id, t.Description, F(t.Median), F(t.P95), F(t.Min), F(t.Max), t.Commands.ToString(CultureInfo.InvariantCulture), F(t.SqlMilliseconds), t.Shape]));
|
||
|
||
var target = timings.Single(t => t.Id == "a");
|
||
md.AppendLine(CultureInfo.InvariantCulture,
|
||
$"**Target (a):** median {F(target.Median)} ms, p95 {F(target.P95)} ms against {F(TargetMilliseconds, 0)} ms — {(target.P95 < TargetMilliseconds ? "met" : target.Median < TargetMilliseconds ? "met at the median, not at p95" : "not met")}.");
|
||
md.AppendLine();
|
||
md.AppendLine("**Limits:** the refused requests (g, g', g'') sent " +
|
||
string.Join(", ", timings.Where(t => t.Shape.StartsWith("refused", StringComparison.Ordinal)).Select(t => $"{t.Id}: {t.Commands}")) +
|
||
" SQL commands — the limits are checked before any SQL runs.");
|
||
md.AppendLine();
|
||
|
||
md.AppendLine("### SQL sent per request");
|
||
md.AppendLine();
|
||
foreach (var timing in timings.Where(t => t.Commands > 0))
|
||
{
|
||
md.AppendLine(CultureInfo.InvariantCulture, $"<details><summary>({timing.Id}) {timing.Commands} commands, {F(timing.SqlMilliseconds)} ms</summary>");
|
||
md.AppendLine();
|
||
md.AppendLine("```sql");
|
||
foreach (var statement in timing.Statements)
|
||
{
|
||
md.AppendLine(statement);
|
||
}
|
||
|
||
md.AppendLine("```");
|
||
md.AppendLine("</details>");
|
||
md.AppendLine();
|
||
}
|
||
|
||
md.AppendLine("## Query plans");
|
||
md.AppendLine();
|
||
md.AppendLine("EXPLAIN (ANALYZE, BUFFERS, SETTINGS) of the reader's statements (copied from `AnalysisQueries`) with the parameters of the request named.");
|
||
md.AppendLine();
|
||
foreach (var (title, sql, plan) in plans)
|
||
{
|
||
md.AppendLine(CultureInfo.InvariantCulture, $"### {title}");
|
||
md.AppendLine();
|
||
md.AppendLine("```sql").AppendLine(sql.Trim()).AppendLine("```");
|
||
md.AppendLine("```").AppendLine(plan).AppendLine("```");
|
||
md.AppendLine();
|
||
}
|
||
|
||
Directory.CreateDirectory(settings.OutputDirectory);
|
||
var path = Path.Combine(settings.OutputDirectory, $"results-{settings.Label}.md");
|
||
await File.WriteAllTextAsync(path, md.ToString());
|
||
await File.WriteAllTextAsync(
|
||
Path.Combine(settings.OutputDirectory, $"results-{settings.Label}.json"),
|
||
JsonSerializer.Serialize(
|
||
new { settings.Label, manifest.Now, prepared.Rebuild, Timings = timings.Select(t => new { t.Id, t.Description, t.Median, t.P95, t.Min, t.Max, t.Commands, t.SqlMilliseconds, t.Shape, t.Milliseconds }) },
|
||
DatasetManifest.Json));
|
||
return path;
|
||
}
|
||
}
|