Skip to content

Commit 6c2e0cb

Browse files
committed
fix(sync): materialize cert bodies + bound DCV-during-sync (issues 0001, 0002)
0001 — Synchronize emitted issued/revoked records with no certificate body (the order-report listing carries no PEM), so CERTInext-issued certs never reached Command. Refetch the full cert via GetCertificateAsync for GENERATED/REVOKED records whose body is missing, mirroring GetSingleRecord. Regression tests cover issued + revoked refetch and the no-over-fetch boundary. 0002 — DCV-during-sync attempted every pending order on every pass, making a full scan O(pending) and pathologically slow with a large/abandoned backlog. Bound it: - DcvSyncMaxOrderAgeHours (default 24): only recently-placed pending orders are DCV-eligible during sync; old ones age out instead of being retried every pass. - DcvSyncMaxPerPass (default 50): cap DCV attempts per pass. - fastSync short propagation delay on the sync path (Enroll keeps the full wait). Gate is a pure helper (EvaluateDcvSyncEligibility) with exhaustive unit tests. Emit-side observability — completion summary now reports GeneratedWithBody / GeneratedNoBody / Revoked / Pending plus the DCV gate counts, with a per-record Debug line. Carries OrderDate from the order report onto the sync model for stateless age filtering. 195/195 unit tests green; full scan validated bounded (~3 min).
1 parent 49d1281 commit 6c2e0cb

9 files changed

Lines changed: 597 additions & 37 deletions

File tree

CERTInext.IntegrationTests/DcvLifecycleTests.cs

Lines changed: 137 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -345,23 +345,23 @@ public async Task EnrollWithDcvOn_OrderIssuedEndToEnd_AndAppearsInSync()
345345
// worth noting but not a hard failure (the next sync will pick it up).
346346
record.Status.Should().BeOneOf((int)EndEntityStatus.GENERATED, (int)EndEntityStatus.EXTERNALVALIDATION);
347347

348-
// Sync is summary-only by design: it iterates ListCertificatesAsync, which
349-
// returns the order-report metadata (no cert PEM). The PEM is materialised
350-
// per-record via GetSingleRecord / DownloadCertificateAsync when Command
351-
// actually needs the cert. So even GENERATED records typically have empty
352-
// Certificate in the sync output — that is correct behaviour, not a bug.
353-
// Confirm the cert is retrievable by issuing the same per-record fetch the
354-
// gateway would do for inventory.
348+
// Issue 0001: Synchronize now materialises the PEM for issued certs.
349+
// ListCertificatesAsync returns order-report metadata (no body), so the plugin
350+
// refetches the full certificate for GENERATED/REVOKED records during sync.
355351
if (record.Status == (int)EndEntityStatus.GENERATED)
356352
{
353+
record.Certificate.Should().NotBeNullOrWhiteSpace(
354+
"Synchronize must populate the cert body for issued orders (issue 0001) — " +
355+
"the order-report listing carries none, so the plugin refetches it.");
356+
357+
// GetSingleRecord is the same on-demand fetch the gateway uses for inventory.
357358
var fetched = await plugin.GetSingleRecord(enrollResult.CARequestID);
358359
fetched.Should().NotBeNull();
359360
fetched.Status.Should().Be((int)EndEntityStatus.GENERATED);
360361
fetched.Certificate.Should().NotBeNullOrWhiteSpace(
361-
"GetSingleRecord must populate the PEM for a GENERATED order — sync is " +
362-
"summary-only, but the per-record download path is the contract the gateway " +
363-
"uses to materialise the cert.");
364-
_output.WriteLine($" Fetched cert PEM length: {fetched.Certificate.Length}");
362+
"GetSingleRecord must populate the PEM for a GENERATED order.");
363+
_output.WriteLine($" Sync cert PEM length: {record.Certificate.Length}; " +
364+
$"GetSingleRecord PEM length: {fetched.Certificate.Length}");
365365
}
366366

367367
_output.WriteLine($"--- Verdict: DCV-on enroll for {cn} drove DCV end-to-end via plugin, " +
@@ -576,6 +576,132 @@ public async Task BulkDvEnrollment_AllOrdersIssue_AndPaginationWorks()
576576
_output.WriteLine($"--- SUCCESS: {count}/{count} DV orders enrolled, synced, and issued in {passesUsed} sync pass(es). " +
577577
$"Enroll={sw.Elapsed:mm\\:ss} SyncPhase={syncPhaseSw.Elapsed:mm\\:ss} Total={(sw.Elapsed + syncPhaseSw.Elapsed):mm\\:ss} ---");
578578
}
579+
580+
/// <summary>
581+
/// Operational task: drive every <em>existing</em> pending-DV order to completion.
582+
///
583+
/// Unlike <see cref="BulkDvEnrollment_AllOrdersIssue_AndPaginationWorks"/>, this enrolls
584+
/// nothing — it just runs the plugin's full <c>Synchronize</c> with DCV enabled, which
585+
/// invokes <c>TryRunDcvDuringSyncAsync</c> for every order sitting at
586+
/// <see cref="EndEntityStatus.EXTERNALVALIDATION"/> (Cloudflare TXT publish → VerifyDcv →
587+
/// wait → cleanup). It repeats the sync until no order remains pending or the pass budget
588+
/// is exhausted, reporting which orders transitioned to <see cref="EndEntityStatus.GENERATED"/>.
589+
///
590+
/// Opt-in (it mutates real CA orders and publishes real DNS records): set
591+
/// <c>CERTINEXT_COMPLETE_PENDING=1</c>. Requires Cloudflare DCV credentials.
592+
/// </summary>
593+
[SkippableFact]
594+
public async Task CompleteAllPendingDvOrders()
595+
{
596+
IntegrationSkip.IfNotConfigured(_fixture);
597+
Skip.If(System.Environment.GetEnvironmentVariable("CERTINEXT_COMPLETE_PENDING") != "1",
598+
"Opt-in: set CERTINEXT_COMPLETE_PENDING=1 to drive all pending DV orders to completion.");
599+
Skip.If(!_fixture.IsCloudflareConfigured,
600+
"CERTINEXT_CF_API_TOKEN + CERTINEXT_CF_ZONE_ID required — completing DCV must publish real TXT records.");
601+
602+
var plugin = BuildPlugin(dcvEnabled: true);
603+
604+
const int maxSyncPasses = 8;
605+
const int delayBetweenPassesSeconds = 30;
606+
607+
List<AnyCAPluginCertificate> synced = null;
608+
int passesUsed = 0;
609+
var phaseSw = System.Diagnostics.Stopwatch.StartNew();
610+
611+
for (int pass = 1; pass <= maxSyncPasses; pass++)
612+
{
613+
passesUsed = pass;
614+
var passSw = System.Diagnostics.Stopwatch.StartNew();
615+
synced = await RunSyncAsync(plugin);
616+
passSw.Stop();
617+
618+
var pending = synced.Where(r => r.Status == (int)EndEntityStatus.EXTERNALVALIDATION).ToList();
619+
int generated = synced.Count(r => r.Status == (int)EndEntityStatus.GENERATED);
620+
621+
_output.WriteLine(
622+
$"--- Sync pass #{pass}: {synced.Count} records, {generated} GENERATED, " +
623+
$"{pending.Count} still pending DV, elapsed={passSw.Elapsed:mm\\:ss} ---");
624+
foreach (var r in pending.Take(20))
625+
_output.WriteLine($" pending: {r.CARequestID}");
626+
627+
if (pending.Count == 0)
628+
break;
629+
630+
if (pass < maxSyncPasses)
631+
{
632+
_output.WriteLine($" Waiting {delayBetweenPassesSeconds}s before next sync pass…");
633+
await Task.Delay(TimeSpan.FromSeconds(delayBetweenPassesSeconds));
634+
}
635+
}
636+
phaseSw.Stop();
637+
638+
synced.Should().NotBeNull("Synchronize must have run at least once");
639+
var stillPending = synced!.Where(r => r.Status == (int)EndEntityStatus.EXTERNALVALIDATION).ToList();
640+
641+
_output.WriteLine(
642+
$"--- Done after {passesUsed} pass(es) in {phaseSw.Elapsed:mm\\:ss}: " +
643+
$"{synced!.Count(r => r.Status == (int)EndEntityStatus.GENERATED)} GENERATED, " +
644+
$"{stillPending.Count} still pending DV. ---");
645+
646+
// Orders may legitimately remain pending if CERTInext is still working server-side or
647+
// a domain isn't in the configured Cloudflare zone — surface that rather than failing.
648+
stillPending.Should().BeEmpty(
649+
$"all pending DV orders should reach GENERATED after {maxSyncPasses} passes; " +
650+
$"{stillPending.Count} remain (e.g. {string.Join(", ", stillPending.Take(5).Select(r => r.CARequestID))}). " +
651+
"These likely have domains outside the configured Cloudflare zone or are still validating server-side.");
652+
}
653+
654+
// Regression for issue 0001 — a full Synchronize must return every issued cert WITH
655+
// its PEM body. The order-report listing carries no body, so the plugin must refetch
656+
// the full certificate; before the fix, issued certs synced with a null body and
657+
// never appeared in Command. This is the end-to-end "issued certs fill in" check.
658+
[SkippableFact]
659+
public async Task FullSync_AllIssuedCerts_CarryParseableCertificateBody()
660+
{
661+
IntegrationSkip.IfNotConfigured(_fixture);
662+
663+
var plugin = BuildPlugin(dcvEnabled: false);
664+
665+
var sw = System.Diagnostics.Stopwatch.StartNew();
666+
var synced = await RunSyncAsync(plugin);
667+
sw.Stop();
668+
669+
var issued = synced.Where(r => r.Status == (int)EndEntityStatus.GENERATED).ToList();
670+
_output.WriteLine(
671+
$"Synchronize returned {synced.Count} records in {sw.Elapsed:mm\\:ss} ({issued.Count} GENERATED).");
672+
673+
issued.Should().NotBeEmpty(
674+
"the account has known issued certs (e.g. scrup.org) that a full sync must surface");
675+
676+
var parser = new Org.BouncyCastle.X509.X509CertificateParser();
677+
var bad = new System.Collections.Generic.List<string>();
678+
foreach (var r in issued)
679+
{
680+
if (string.IsNullOrWhiteSpace(r.Certificate))
681+
{
682+
bad.Add($"{r.CARequestID} (empty body)");
683+
continue;
684+
}
685+
try
686+
{
687+
var b64 = r.Certificate
688+
.Replace("-----BEGIN CERTIFICATE-----", string.Empty)
689+
.Replace("-----END CERTIFICATE-----", string.Empty)
690+
.Replace("\r", string.Empty).Replace("\n", string.Empty).Trim();
691+
if (parser.ReadCertificate(Convert.FromBase64String(b64)) == null)
692+
bad.Add($"{r.CARequestID} (unparseable)");
693+
}
694+
catch (Exception ex)
695+
{
696+
bad.Add($"{r.CARequestID} ({ex.GetType().Name})");
697+
}
698+
}
699+
700+
bad.Should().BeEmpty(
701+
"every issued cert must carry a parseable certificate body after sync; " +
702+
$"offenders: {string.Join(", ", bad.Take(10))}");
703+
_output.WriteLine($"--- Verdict: all {issued.Count} issued certs carry a valid certificate body. ---");
704+
}
579705
}
580706

581707
/// <summary>
Lines changed: 124 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,124 @@
1+
using System;
2+
using FluentAssertions;
3+
using Xunit;
4+
using static Keyfactor.Extensions.CAPlugin.CERTInext.CERTInextCAPlugin;
5+
6+
namespace Keyfactor.Extensions.CAPlugin.CERTInext.Tests
7+
{
8+
/// <summary>
9+
/// Issue 0002 — unit tests for the DCV-during-sync gate (EvaluateDcvSyncEligibility).
10+
/// Pure decision logic that bounds DCV work per sync pass so a large pending backlog
11+
/// can't make a pass slow. No DCV machinery / network needed.
12+
/// </summary>
13+
public class BoundedDcvSyncTests
14+
{
15+
private static readonly DateTime Now = new DateTime(2026, 6, 10, 12, 0, 0, DateTimeKind.Utc);
16+
17+
// --- Age window ---------------------------------------------------------
18+
19+
[Fact]
20+
public void RecentOrder_WithinAgeWindow_IsAttempted()
21+
{
22+
var orderDate = Now.AddHours(-1); // 1h old, window 24h
23+
EvaluateDcvSyncEligibility(orderDate, Now, ageWindowHours: 24, attemptedSoFar: 0, perPassCap: 50)
24+
.Should().Be(DcvSyncDecision.Attempt);
25+
}
26+
27+
[Fact]
28+
public void OldOrder_BeyondAgeWindow_IsSkippedByAge()
29+
{
30+
var orderDate = Now.AddHours(-48); // 48h old, window 24h
31+
EvaluateDcvSyncEligibility(orderDate, Now, ageWindowHours: 24, attemptedSoFar: 0, perPassCap: 50)
32+
.Should().Be(DcvSyncDecision.SkipByAge);
33+
}
34+
35+
[Fact]
36+
public void OrderExactlyAtAgeBoundary_IsAttempted()
37+
{
38+
var orderDate = Now.AddHours(-24); // exactly 24h, window 24h → still eligible (<=)
39+
EvaluateDcvSyncEligibility(orderDate, Now, ageWindowHours: 24, attemptedSoFar: 0, perPassCap: 50)
40+
.Should().Be(DcvSyncDecision.Attempt);
41+
}
42+
43+
[Fact]
44+
public void UnknownOrderDate_IsAttempted_NotStarved()
45+
{
46+
EvaluateDcvSyncEligibility(orderDateUtc: null, Now, ageWindowHours: 24, attemptedSoFar: 0, perPassCap: 50)
47+
.Should().Be(DcvSyncDecision.Attempt);
48+
}
49+
50+
[Fact]
51+
public void AgeWindowDisabled_OldOrderStillAttempted()
52+
{
53+
var orderDate = Now.AddDays(-30);
54+
EvaluateDcvSyncEligibility(orderDate, Now, ageWindowHours: 0, attemptedSoFar: 0, perPassCap: 50)
55+
.Should().Be(DcvSyncDecision.Attempt);
56+
}
57+
58+
// --- Per-pass cap -------------------------------------------------------
59+
60+
[Fact]
61+
public void UnderCap_IsAttempted()
62+
{
63+
EvaluateDcvSyncEligibility(Now, Now, ageWindowHours: 24, attemptedSoFar: 4, perPassCap: 5)
64+
.Should().Be(DcvSyncDecision.Attempt);
65+
}
66+
67+
[Fact]
68+
public void AtCap_IsSkippedByCap()
69+
{
70+
EvaluateDcvSyncEligibility(Now, Now, ageWindowHours: 24, attemptedSoFar: 5, perPassCap: 5)
71+
.Should().Be(DcvSyncDecision.SkipByCap);
72+
}
73+
74+
[Fact]
75+
public void CapDisabled_AlwaysAttemptedRegardlessOfCount()
76+
{
77+
EvaluateDcvSyncEligibility(Now, Now, ageWindowHours: 24, attemptedSoFar: 10_000, perPassCap: 0)
78+
.Should().Be(DcvSyncDecision.Attempt);
79+
}
80+
81+
// --- Precedence ---------------------------------------------------------
82+
83+
[Fact]
84+
public void AgeSkip_TakesPrecedenceOverCap()
85+
{
86+
// Old order AND at cap → reported as age skip (age checked first).
87+
var orderDate = Now.AddHours(-48);
88+
EvaluateDcvSyncEligibility(orderDate, Now, ageWindowHours: 24, attemptedSoFar: 5, perPassCap: 5)
89+
.Should().Be(DcvSyncDecision.SkipByAge);
90+
}
91+
92+
// --- Simulated pass: a backlog of old + a few recent, with a small cap ---
93+
94+
[Fact]
95+
public void SimulatedPass_OnlyRecentOrdersAttempted_AndCapped()
96+
{
97+
// 100 old (out-of-window) + 10 recent; cap 5. Mirrors the Synchronize loop's
98+
// use of the gate: only recent orders are eligible, and at most `cap` are attempted.
99+
const int ageWindow = 24, cap = 5;
100+
int attempted = 0, skippedAge = 0, skippedCap = 0;
101+
102+
for (int i = 0; i < 100; i++) // old backlog
103+
Tally(EvaluateDcvSyncEligibility(Now.AddHours(-48), Now, ageWindow, attempted, cap),
104+
ref attempted, ref skippedAge, ref skippedCap);
105+
for (int i = 0; i < 10; i++) // recent
106+
Tally(EvaluateDcvSyncEligibility(Now.AddMinutes(-5), Now, ageWindow, attempted, cap),
107+
ref attempted, ref skippedAge, ref skippedCap);
108+
109+
attempted.Should().Be(5, "only up to the cap of recent orders are attempted");
110+
skippedAge.Should().Be(100, "the entire old backlog is skipped by the age window");
111+
skippedCap.Should().Be(5, "recent orders beyond the cap are deferred to a later pass");
112+
}
113+
114+
private static void Tally(DcvSyncDecision d, ref int attempted, ref int skippedAge, ref int skippedCap)
115+
{
116+
switch (d)
117+
{
118+
case DcvSyncDecision.Attempt: attempted++; break;
119+
case DcvSyncDecision.SkipByAge: skippedAge++; break;
120+
case DcvSyncDecision.SkipByCap: skippedCap++; break;
121+
}
122+
}
123+
}
124+
}

0 commit comments

Comments
 (0)