diff --git a/CERTInext.IntegrationTests/IntegrationTestFixture.cs b/CERTInext.IntegrationTests/IntegrationTestFixture.cs
index abebc1a..4994aed 100644
--- a/CERTInext.IntegrationTests/IntegrationTestFixture.cs
+++ b/CERTInext.IntegrationTests/IntegrationTestFixture.cs
@@ -52,6 +52,10 @@ public sealed class IntegrationTestFixture : IDisposable
"CERTINEXT_V2_LIFECYCLE_WILDCARD_DV",
"CERTINEXT_V2_LIFECYCLE_RENEW_REISSUE",
"CERTINEXT_V2_LIFECYCLE_FRESH_DCV",
+ // Issue 0090 V2 place-order latency experiment (places real sandbox orders).
+ "CERTINEXT_V2_LATENCY_EXPERIMENT",
+ // Explicit-ID V2 sandbox order cleanup (revokes/cancels the listed orders).
+ "CERTINEXT_V2_CLEANUP_ORDERS",
};
// ---------------------------------------------------------------------------
diff --git a/CERTInext.IntegrationTests/V2OrderCleanupTests.cs b/CERTInext.IntegrationTests/V2OrderCleanupTests.cs
new file mode 100644
index 0000000..6385c6f
--- /dev/null
+++ b/CERTInext.IntegrationTests/V2OrderCleanupTests.cs
@@ -0,0 +1,319 @@
+// Copyright 2026 Keyfactor
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+// http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+using System;
+using System.Collections.Generic;
+using System.Globalization;
+using System.Linq;
+using System.Text.RegularExpressions;
+using System.Threading.Tasks;
+using Keyfactor.Extensions.CAPlugin.CERTInext.API.V2;
+using Keyfactor.Extensions.CAPlugin.CERTInext.Client;
+using Xunit;
+using Xunit.Abstractions;
+
+namespace Keyfactor.Extensions.CAPlugin.CERTInext.IntegrationTests
+{
+ ///
+ /// Explicit-ID cleanup of V2 SANDBOX orders (fake credits) left behind by experiments.
+ /// Opt-in: CERTINEXT_V2_CLEANUP_ORDERS=<comma-separated order ids> as a REAL
+ /// environment variable (it is never read from an env file). Credentials come from
+ /// ~/.env_certinext_v2.
+ ///
+ /// Only the listed ids are ever acted on. For each: TrackOrder (record status) -> revoke if
+ /// issued, cancel if pending, skip if already revoked / cancelled / rejected / expired ->
+ /// TrackOrder again (verify). A narrow read-only order-report window (yesterday..tomorrow) is
+ /// read once to report each listed order's creation date and domain; no full sync is run and
+ /// nothing is acted on by pattern. Set CERTINEXT_V2_CLEANUP_DRYRUN=1 to track and report
+ /// details only (no revoke/cancel). Set
+ /// CERTINEXT_V2_CLEANUP_FORCE_CANCEL=1 (single id only) to make one raw cancel attempt instead of a revoke. Emails are scrubbed from all output.
+ ///
+ public class V2OrderCleanupTests : IClassFixture
+ {
+ private const string OptInFlag = "CERTINEXT_V2_CLEANUP_ORDERS";
+ private const int MaxOrders = 25;
+ private const string CleanupReason = "Sandbox test order cleanup (issue 0090 lab race repro).";
+
+ private readonly ITestOutputHelper _output;
+ private readonly string _apiUrl;
+ private readonly string _clientId;
+ private readonly string _clientSecret;
+ private readonly string _groupNumber;
+ private readonly bool _v2Enabled;
+
+ private static readonly Regex EmailRx =
+ new(@"[A-Za-z0-9._%+\-]+@[A-Za-z0-9.\-]+\.[A-Za-z]{2,}", RegexOptions.Compiled);
+
+ public V2OrderCleanupTests(IntegrationTestFixture fixture, ITestOutputHelper output)
+ {
+ _output = output;
+ var env = V2EnvHelper.LoadAndPromote();
+ _apiUrl = V2EnvHelper.GetEnv(env, "CERTINEXT_API_URL");
+ _clientId = V2EnvHelper.GetEnv(env, "CERTINEXT_CLIENT_ID");
+ _clientSecret = V2EnvHelper.GetEnv(env, "CERTINEXT_CLIENT_SECRET");
+ _groupNumber = V2EnvHelper.GetEnv(env, "CERTINEXT_GROUP_NUMBER", string.Empty);
+ _v2Enabled = !string.IsNullOrWhiteSpace(V2EnvHelper.GetEnv(env, "CERTINEXT_USE_V2_API"))
+ && !string.IsNullOrWhiteSpace(_apiUrl)
+ && !string.IsNullOrWhiteSpace(_clientId)
+ && !string.IsNullOrWhiteSpace(_clientSecret);
+ }
+
+ private static string Scrub(string s)
+ {
+ if (string.IsNullOrEmpty(s)) return s ?? string.Empty;
+ s = EmailRx.Replace(s, "");
+ return s.Length > 500 ? s.Substring(0, 500) + "..." : s;
+ }
+
+ private void W(string s) => _output.WriteLine(Scrub(s));
+
+ private static string Describe(Exception ex) => $"{ex.GetType().Name}: {ex.Message}";
+
+ private CERTInextConfig BuildConfig() => new CERTInextConfig
+ {
+ ApiUrl = _apiUrl,
+ UseV2Api = true,
+ OAuthClientId = _clientId,
+ OAuthClientSecret = _clientSecret,
+ RequestorName = "Keyfactor Integration Test",
+ RequestorIsdCode = "1",
+ RequestorMobileNumber = "0000000000",
+ SignerPlace = "Gateway Lab",
+ SignerIp = "127.0.0.1",
+ GroupNumber = _groupNumber,
+ PageSize = 100,
+ DcvEnabled = false
+ };
+
+ private static bool IsTerminalNoAction(string status) =>
+ string.Equals(status, Constants.ApiV2.StatusRevoked, StringComparison.OrdinalIgnoreCase)
+ || string.Equals(status, Constants.ApiV2.StatusCancelled, StringComparison.OrdinalIgnoreCase)
+ || string.Equals(status, Constants.ApiV2.StatusRejected, StringComparison.OrdinalIgnoreCase)
+ || string.Equals(status, Constants.ApiV2.StatusExpired, StringComparison.OrdinalIgnoreCase);
+
+ private static bool IsPending(string status) =>
+ !string.IsNullOrEmpty(status) && status.StartsWith("pending-", StringComparison.OrdinalIgnoreCase);
+
+ private sealed class Row
+ {
+ public string OrderId;
+ public string Before = "-";
+ public string Action = "none";
+ public string After = "-";
+ public string Notes = string.Empty;
+ }
+
+ [SkippableFact]
+ public async Task V2_CleanupExplicitOrders_RevokeOrCancelListedIdsOnly()
+ {
+ Skip.If(!_v2Enabled,
+ "V2 credentials not configured in ~/.env_certinext_v2 (CERTINEXT_USE_V2_API, API_URL, CLIENT_ID, CLIENT_SECRET).");
+ string flag = Environment.GetEnvironmentVariable(OptInFlag);
+ Skip.If(string.IsNullOrWhiteSpace(flag),
+ $"Opt-in: set {OptInFlag}= as a real environment variable.");
+
+ var ids = flag.Split(new[] { ',', ' ', ';' }, StringSplitOptions.RemoveEmptyEntries)
+ .Select(s => s.Trim()).Distinct(StringComparer.Ordinal).ToList();
+ Assert.NotEmpty(ids);
+ Assert.True(ids.Count <= MaxOrders, $"At most {MaxOrders} order ids per run.");
+ Assert.All(ids, id => Assert.Matches("^[0-9]{1,20}$", id)); // digits only: refuse anything pattern-like
+
+ var cfg = BuildConfig();
+ using var client = new CERTInextClient(cfg);
+ string family = Constants.ApiV2.FamilySsl;
+ bool dryRun = Environment.GetEnvironmentVariable("CERTINEXT_V2_CLEANUP_DRYRUN") == "1";
+ if (dryRun) W("DRY RUN: track + details only; no revoke/cancel will be sent.");
+ bool forceCancel = Environment.GetEnvironmentVariable("CERTINEXT_V2_CLEANUP_FORCE_CANCEL") == "1";
+ Assert.True(!forceCancel || ids.Count == 1, "CERTINEXT_V2_CLEANUP_FORCE_CANCEL requires exactly one order id.");
+ if (forceCancel) W("FORCE CANCEL: one raw cancel attempt (no revoke, no retry) for the single listed order.");
+
+ W($"V2 order cleanup: {ids.Count} listed order(s), family={family}");
+
+ // 1) Read-only detail lookup (creation date, domain) from a narrow order-report window.
+ // Only the listed ids are retained; nothing here drives an action.
+ var listed = new Dictionary(StringComparer.Ordinal);
+ try
+ {
+ string from = DateTime.UtcNow.AddDays(-1).ToString("yyyy-MM-dd", CultureInfo.InvariantCulture);
+ string to = DateTime.UtcNow.AddDays(1).ToString("yyyy-MM-dd", CultureInfo.InvariantCulture);
+ int scanned = 0;
+ await foreach (var e in client.ListOrdersV2Async(from, to, 100))
+ {
+ scanned++;
+ if (e?.OrderNumber != null && ids.Contains(e.OrderNumber))
+ listed[e.OrderNumber] = e;
+ }
+ W($"order-report window {from}..{to}: scanned={scanned}, matched listed ids={listed.Count}");
+ }
+ catch (Exception ex)
+ {
+ W("order-report lookup failed (details only; cleanup continues): " + Describe(ex));
+ }
+
+ foreach (var id in ids)
+ {
+ if (listed.TryGetValue(id, out var e))
+ W($"detail order={id} domain={e.DomainName} orderStatus={e.OrderStatus} certStatus={e.CertificateStatus} " +
+ $"orderDate={e.OrderDate} productCode={e.ProductCode} requestNumber={e.RequestNumber}");
+ else
+ W($"detail order={id} NOT present in order-report window");
+ }
+
+ // 2) Per-order: track -> act -> track.
+ var rows = new List();
+ foreach (var id in ids)
+ {
+ var row = new Row { OrderId = id };
+ rows.Add(row);
+
+ V2OrderStatusResponse before = null;
+ try
+ {
+ before = await client.TrackOrderV2Async(family, id);
+ row.Before = before.Status ?? "(null)";
+ W($"track-before order={id} status={before.Status} domain={before.Domain} variant={before.ProductVariant} " +
+ $"issuedAt={before.IssuedAt} expiresAt={before.ExpiresAt}");
+ }
+ catch (KeyNotFoundException)
+ {
+ row.Before = "NOT FOUND";
+ row.Action = "skipped (not found in " + family + ")";
+ W($"order={id} not found in family {family}; no action taken");
+ continue;
+ }
+ catch (Exception ex)
+ {
+ row.Before = "TRACK ERROR";
+ row.Action = "skipped";
+ row.Notes = Scrub(Describe(ex));
+ continue;
+ }
+
+ string status = before.Status;
+ if (dryRun)
+ {
+ row.Action = "dry-run (none)";
+ row.After = row.Before;
+ continue;
+ }
+ try
+ {
+ if (IsTerminalNoAction(status))
+ {
+ row.Action = "skip (already " + status + ")";
+ }
+ else if (forceCancel)
+ {
+ // Single attempt via the raw helper (same POST .../cancel endpoint as CancelOrderV2Async)
+ // so the exact HTTP status and body detail are captured; no retry, no other mutation.
+ row.Action = "force-cancel (single attempt)";
+ try
+ {
+ await V2RawHttpHelpers.CancelSslOrderRawAsync(_apiUrl, _clientId, _clientSecret, id, CleanupReason);
+ row.Action += " -> accepted (2xx)";
+ }
+ catch (Exception cex)
+ {
+ row.Action += " -> REJECTED";
+ row.Notes += "cancel response: " + Scrub(Describe(cex));
+ }
+ }
+ else if (string.Equals(status, Constants.ApiV2.StatusIssued, StringComparison.OrdinalIgnoreCase))
+ {
+ row.Action = await RevokeAsync(client, family, id, row);
+ }
+ else if (IsPending(status))
+ {
+ var outcome = await client.CancelOrderV2Async(family, id, CleanupReason);
+ row.Action = "cancel -> " + outcome;
+ }
+ else
+ {
+ row.Action = "skip (unrecognised status; not acting)";
+ }
+ }
+ catch (Exception ex)
+ {
+ row.Action += (row.Action == "none" ? "" : "; ") + "ACTION FAILED";
+ row.Notes += (row.Notes.Length > 0 ? " | " : "") + Scrub(Describe(ex));
+ }
+
+ try
+ {
+ var after = await client.TrackOrderV2Async(family, id);
+ row.After = after.Status ?? "(null)";
+ if (after.Revocation != null)
+ row.Notes += (row.Notes.Length > 0 ? " | " : "") +
+ $"revocation.reason={after.Revocation.Reason} processedAt={after.Revocation.ProcessedAt}";
+ }
+ catch (Exception ex)
+ {
+ row.After = "TRACK ERROR";
+ row.Notes += (row.Notes.Length > 0 ? " | " : "") + Scrub(Describe(ex));
+ }
+ }
+
+ if (forceCancel)
+ {
+ try
+ {
+ string from2 = DateTime.UtcNow.AddDays(-1).ToString("yyyy-MM-dd", CultureInfo.InvariantCulture);
+ string to2 = DateTime.UtcNow.AddDays(1).ToString("yyyy-MM-dd", CultureInfo.InvariantCulture);
+ bool found = false;
+ await foreach (var e2 in client.ListOrdersV2Async(from2, to2, 100))
+ if (e2?.OrderNumber != null && ids.Contains(e2.OrderNumber))
+ {
+ found = true;
+ W($"listing-after order={e2.OrderNumber} orderStatus={e2.OrderStatus} certStatus={e2.CertificateStatus} orderDate={e2.OrderDate}");
+ }
+ if (!found) W("listing-after: listed order not present in window");
+ }
+ catch (Exception lex) { W("listing-after failed: " + Describe(lex)); }
+ }
+
+ W("=== result: order | before | action | after | notes ===");
+ foreach (var r in rows)
+ W($"RESULT {r.OrderId} | {r.Before} | {r.Action} | {r.After} | {r.Notes}");
+
+ if (dryRun || forceCancel) return; // force-cancel is a probe: outcome is reported, not asserted
+
+ // Pass only when every listed order ended in a terminal non-issued state.
+ var bad = rows.Where(r => !IsTerminalNoAction(r.After)).Select(r => $"{r.OrderId}({r.After})").ToList();
+ Assert.True(bad.Count == 0, "Orders not in a terminal state after cleanup: " + string.Join(", ", bad));
+ }
+
+ ///
+ /// Revoke an issued order. Tries "superseded" (what plugin reason 4 maps to); if CERTInext
+ /// rejects it, records the exact rejection in and retries once with
+ /// "unspecified" so a spec-vs-live reason discrepancy is surfaced instead of hidden.
+ ///
+ private static async Task RevokeAsync(CERTInextClient client, string family, string id, Row row)
+ {
+ try
+ {
+ await client.RevokeOrderV2Async(family, id,
+ new V2RevokeRequest { Reason = "superseded", Note = CleanupReason });
+ return "revoke(reason=superseded)";
+ }
+ catch (Exception ex)
+ {
+ row.Notes += "revoke(superseded) rejected: " + Scrub(Describe(ex));
+ }
+
+ await client.RevokeOrderV2Async(family, id,
+ new V2RevokeRequest { Reason = "unspecified", Note = CleanupReason });
+ return "revoke(reason=unspecified, after superseded rejected)";
+ }
+ }
+}
diff --git a/CERTInext.IntegrationTests/V2PlaceOrderLatencyExperimentTests.cs b/CERTInext.IntegrationTests/V2PlaceOrderLatencyExperimentTests.cs
new file mode 100644
index 0000000..9cce56f
--- /dev/null
+++ b/CERTInext.IntegrationTests/V2PlaceOrderLatencyExperimentTests.cs
@@ -0,0 +1,707 @@
+// Copyright 2026 Keyfactor
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+// http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+using System;
+using System.Collections.Concurrent;
+using System.Collections.Generic;
+using System.Diagnostics;
+using System.Globalization;
+using System.IO;
+using System.Linq;
+using System.Reflection;
+using System.Text;
+using System.Text.RegularExpressions;
+using System.Threading;
+using System.Threading.Tasks;
+using Keyfactor.AnyGateway.Extensions;
+using Keyfactor.Extensions.CAPlugin.CERTInext.API.V2;
+using Keyfactor.Extensions.CAPlugin.CERTInext.Client;
+using Keyfactor.PKI.Enums.EJBCA;
+using Org.BouncyCastle.Asn1.X509;
+using Org.BouncyCastle.Crypto.Generators;
+using Org.BouncyCastle.Crypto;
+using Org.BouncyCastle.Pkcs;
+using Org.BouncyCastle.Security;
+using Xunit;
+using Xunit.Abstractions;
+
+namespace Keyfactor.Extensions.CAPlugin.CERTInext.IntegrationTests
+{
+ ///
+ /// Measurement experiment (issue 0090, V2 side): does the V2 API hold order placement open
+ /// the way V1 GenerateOrderSSL does in production (response returned 19 s / 100 s after
+ /// the order already exists and is issued), and how long is the window between "order visible
+ /// to a CA Sync" and "plugin Enroll returns the CARequestID to the gateway"?
+ ///
+ /// V2 order placement is three calls: POST create (returns orderId, order sits in
+ /// pending-csr), PUT /csr, then GET track (+ download / pickup poll). The plugin's real
+ /// Enroll is driven end to end; a wraps the real client
+ /// and timestamps every plugin-to-CA call, so the numbers are the plugin's own call pattern.
+ /// Two independent clients run beside it:
+ ///
+ /// - a listing poller (the call Synchronize makes: /reports/orders) every ~1.5 s,
+ /// which finds the order by its unique domain BEFORE the place response returns;
+ /// - an order tracker (GET track) every ~1 s, started the instant the place response lands.
+ ///
+ /// Opt-in: CERTINEXT_V2_LATENCY_EXPERIMENT=1 as a REAL environment variable.
+ /// Optional: CERTINEXT_V2_LATENCY_COUNT (default 7, max 12),
+ /// CERTINEXT_V2_LATENCY_SPACING_SECONDS (default 30),
+ /// CERTINEXT_V2_LATENCY_DOMAIN_MODE (unique = fresh subdomain of
+ /// CERTINEXT_DCV_DOMAIN per order [default]; reuse = CERTINEXT_DCV_DOMAIN itself).
+ /// Credentials come from ~/.env_certinext_v2. Raw CSV goes to experiment-results/.
+ /// No order numbers or timings are tied to personal data; emails are never printed.
+ ///
+ public class V2PlaceOrderLatencyExperimentTests : IClassFixture
+ {
+ private const string OptInFlag = "CERTINEXT_V2_LATENCY_EXPERIMENT";
+ private const int MaxOrders = 12;
+ private static readonly TimeSpan ListPollInterval = TimeSpan.FromSeconds(1.5);
+ private static readonly TimeSpan TrackPollInterval = TimeSpan.FromSeconds(1.0);
+ private const int MaxListPollsInFlight = 2;
+
+ private readonly IntegrationTestFixture _fixture;
+ private readonly ITestOutputHelper _output;
+ private readonly Stopwatch _clock = Stopwatch.StartNew();
+
+ private readonly string _apiUrl;
+ private readonly string _clientId;
+ private readonly string _clientSecret;
+ private readonly string _productCode;
+ private readonly string _baseDomain;
+ private readonly string _requestorName;
+ private readonly string _requestorEmail;
+ private readonly string _groupNumber;
+ private readonly bool _v2Enabled;
+
+ public V2PlaceOrderLatencyExperimentTests(IntegrationTestFixture fixture, ITestOutputHelper output)
+ {
+ _fixture = fixture;
+ _output = output;
+
+ var env = V2EnvHelper.LoadAndPromote();
+ _apiUrl = V2EnvHelper.GetEnv(env, "CERTINEXT_API_URL");
+ _clientId = V2EnvHelper.GetEnv(env, "CERTINEXT_CLIENT_ID");
+ _clientSecret = V2EnvHelper.GetEnv(env, "CERTINEXT_CLIENT_SECRET");
+ _productCode = V2EnvHelper.GetEnv(env, "CERTINEXT_PRODUCT_CODE", "842");
+ _baseDomain = V2EnvHelper.GetEnv(env, "CERTINEXT_DCV_DOMAIN", string.Empty);
+ _requestorName = V2EnvHelper.GetEnv(env, "CERTINEXT_REQUESTOR_NAME", "Keyfactor Integration Test");
+ _requestorEmail = V2EnvHelper.GetEnv(env, "CERTINEXT_REQUESTOR_EMAIL", "test@example.com");
+ _groupNumber = V2EnvHelper.GetEnv(env, "CERTINEXT_GROUP_NUMBER", string.Empty);
+ _v2Enabled = !string.IsNullOrWhiteSpace(V2EnvHelper.GetEnv(env, "CERTINEXT_USE_V2_API"))
+ && !string.IsNullOrWhiteSpace(_apiUrl)
+ && !string.IsNullOrWhiteSpace(_clientId)
+ && !string.IsNullOrWhiteSpace(_clientSecret);
+ }
+
+ private double Now => _clock.Elapsed.TotalSeconds;
+
+ private static readonly Regex EmailRx = new(@"[A-Za-z0-9._%+\-]+@[A-Za-z0-9.\-]+\.[A-Za-z]{2,}", RegexOptions.Compiled);
+
+ /// Strips anything email-shaped and caps length; used for every line that leaves the test.
+ private static string Scrub(string s)
+ {
+ if (string.IsNullOrEmpty(s)) return s ?? string.Empty;
+ s = EmailRx.Replace(s, "");
+ return s.Length > 400 ? s.Substring(0, 400) + "..." : s;
+ }
+
+ private static string Describe(Exception ex) => Scrub($"{ex.GetType().Name}: {ex.Message}");
+
+ private void W(string s) => _output.WriteLine(Scrub(s));
+
+ // ---------------------------------------------------------------------------
+ // Timing proxy: wraps the real client, timestamps every plugin-to-CA call
+ // ---------------------------------------------------------------------------
+
+ public sealed class CallRecord
+ {
+ public string Name;
+ public double Start;
+ public double End;
+ public string Error;
+ public double DurationMs => (End - Start) * 1000.0;
+ }
+
+ /// DispatchProxy over recording start/end of every async call.
+ public class TimingClientProxy : DispatchProxy
+ {
+ internal ICERTInextClient Inner;
+ internal Func Clock;
+ internal ConcurrentQueue Calls = new();
+ internal Action OnResult;
+
+ protected override object Invoke(MethodInfo targetMethod, object[] args)
+ {
+ double start = Clock();
+ object ret;
+ try
+ {
+ ret = targetMethod.Invoke(Inner, args);
+ }
+ catch (TargetInvocationException tie)
+ {
+ Calls.Enqueue(new CallRecord { Name = targetMethod.Name, Start = start, End = Clock(), Error = Describe(tie.InnerException ?? tie) });
+ throw tie.InnerException ?? tie;
+ }
+
+ if (ret is Task t)
+ {
+ Type rt = targetMethod.ReturnType;
+ if (rt.IsGenericType && rt.GetGenericTypeDefinition() == typeof(Task<>))
+ {
+ var m = typeof(TimingClientProxy).GetMethod(nameof(WrapTaskT), BindingFlags.NonPublic | BindingFlags.Instance)
+ ?.MakeGenericMethod(rt.GetGenericArguments()[0]);
+ return m?.Invoke(this, new object[] { t, targetMethod.Name, start });
+ }
+ return WrapTask(t, targetMethod.Name, start);
+ }
+ return ret; // sync members and IAsyncEnumerable pass straight through, untimed
+ }
+
+ private async Task WrapTask(Task t, string name, double start)
+ {
+ try { await t.ConfigureAwait(false); Calls.Enqueue(new CallRecord { Name = name, Start = start, End = Clock() }); }
+ catch (Exception ex) { Calls.Enqueue(new CallRecord { Name = name, Start = start, End = Clock(), Error = Describe(ex) }); throw; }
+ }
+
+ private async Task WrapTaskT(Task t, string name, double start)
+ {
+ try
+ {
+ T r = await t.ConfigureAwait(false);
+ Calls.Enqueue(new CallRecord { Name = name, Start = start, End = Clock() });
+ OnResult?.Invoke(name, r);
+ return r;
+ }
+ catch (Exception ex)
+ {
+ Calls.Enqueue(new CallRecord { Name = name, Start = start, End = Clock(), Error = Describe(ex) });
+ throw;
+ }
+ }
+ }
+
+ // ---------------------------------------------------------------------------
+ // Observations
+ // ---------------------------------------------------------------------------
+
+ private sealed class TrackObs
+ {
+ public double Sent;
+ public double Recv;
+ public string Status;
+ public string Error;
+ }
+
+ private sealed class ListObs
+ {
+ public double Start;
+ public double End;
+ public int Rows;
+ public string OrderNumber;
+ public string OrderStatus;
+ public string CertStatus;
+ public string Error;
+ public bool Matched => OrderNumber != null;
+ public string Combined => $"{OrderStatus}|{CertStatus}";
+ }
+
+ private sealed class Trial
+ {
+ public int Index;
+ public string Domain;
+ public string OrderId;
+ public DateTime T0Utc;
+ public double T0;
+ public double TPlaceResp = double.NaN;
+ public double TCsrResp = double.NaN;
+ public double TEnrollEnd = double.NaN;
+ public double PlaceMs = double.NaN, CsrMs = double.NaN, DownloadMs = double.NaN;
+ public List TrackCallMs = new();
+ public string EnrollStatus = string.Empty;
+ public bool EnrollHasCert;
+ public string EnrollMessage = string.Empty;
+ public string CreateRespStatus = string.Empty;
+ public double FirstSeenList = double.NaN, FirstSeenListLower = double.NaN;
+ public string FirstSeenListStatus = string.Empty;
+ public double TrackFirstObsRecv = double.NaN;
+ public string TrackFirstObsStatus = string.Empty;
+ public string StatusAfterCsr = string.Empty;
+ public double TIssuedTrack = double.NaN, TIssuedTrackLower = double.NaN;
+ public double TIssuedList = double.NaN;
+ public string TrackSeq = string.Empty;
+ public string ListSeq = string.Empty;
+ public int ListPolls, ListErrors, TrackPolls, TrackErrors;
+ public double ListPollMedianS = double.NaN;
+ public string CleanupNote = string.Empty;
+ public string Error = string.Empty;
+ // One extra GET /certificate fired by the tracker the first time track reports 'issued'
+ // (while the CSR PUT may still be in flight): does 'issued' mean the cert is downloadable?
+ public double DlProbeAt = double.NaN, DlProbeMs = double.NaN;
+ public string DlProbeResult = string.Empty;
+ }
+
+ // ---------------------------------------------------------------------------
+ // Helpers
+ // ---------------------------------------------------------------------------
+
+ private static string F(double x) => double.IsNaN(x) ? "" : x.ToString("0.00", CultureInfo.InvariantCulture);
+
+ private static double Median(IEnumerable xs)
+ {
+ var a = xs.Where(x => !double.IsNaN(x)).OrderBy(x => x).ToArray();
+ if (a.Length == 0) return double.NaN;
+ return a.Length % 2 == 1 ? a[a.Length / 2] : (a[a.Length / 2 - 1] + a[a.Length / 2]) / 2.0;
+ }
+
+ private static string RepoRoot()
+ {
+ var dir = new DirectoryInfo(AppContext.BaseDirectory);
+ while (dir != null && !File.Exists(Path.Combine(dir.FullName, "certinext-caplugin.sln")))
+ dir = dir.Parent;
+ return dir?.FullName ?? Directory.GetCurrentDirectory();
+ }
+
+ /// RSA-2048 PKCS#10 CSR, BouncyCastle only.
+ private static string GenerateCsrPem(string commonName)
+ {
+ var keyGen = new RsaKeyPairGenerator();
+ keyGen.Init(new KeyGenerationParameters(new SecureRandom(), 2048));
+ var keyPair = keyGen.GenerateKeyPair();
+ var csr = new Pkcs10CertificationRequest("SHA256withRSA", new X509Name($"CN={commonName}"),
+ keyPair.Public, null, keyPair.Private);
+ return "-----BEGIN CERTIFICATE REQUEST-----\n"
+ + Convert.ToBase64String(csr.GetEncoded(), Base64FormattingOptions.InsertLineBreaks)
+ + "\n-----END CERTIFICATE REQUEST-----";
+ }
+
+ private CERTInextConfig BuildConfig() => new CERTInextConfig
+ {
+ ApiUrl = _apiUrl,
+ UseV2Api = true,
+ OAuthClientId = _clientId,
+ OAuthClientSecret = _clientSecret,
+ RequestorName = _requestorName,
+ RequestorEmail = _requestorEmail,
+ RequestorIsdCode = "1",
+ RequestorMobileNumber = "0000000000",
+ SignerPlace = "Gateway Lab",
+ SignerIp = "127.0.0.1",
+ GroupNumber = _groupNumber,
+ PageSize = 100,
+ DcvEnabled = false
+ };
+
+ private static bool IsIssuedListing(ListObs o) =>
+ o.CertStatus != null &&
+ (o.CertStatus.IndexOf("Generated", StringComparison.OrdinalIgnoreCase) >= 0
+ || o.CertStatus.IndexOf("Downloaded", StringComparison.OrdinalIgnoreCase) >= 0);
+
+ private static bool IsIssuedTrack(string status) =>
+ string.Equals(status, Constants.ApiV2.StatusIssued, StringComparison.OrdinalIgnoreCase);
+
+ // ---------------------------------------------------------------------------
+ // The experiment
+ // ---------------------------------------------------------------------------
+
+ [SkippableFact]
+ public async Task V2PlaceOrder_Latency_And_ExposureWindow_Experiment()
+ {
+ Skip.If(!_v2Enabled, "V2 credentials not configured in ~/.env_certinext_v2 (CERTINEXT_USE_V2_API, API_URL, CLIENT_ID, CLIENT_SECRET).");
+ Skip.If(Environment.GetEnvironmentVariable(OptInFlag) != "1",
+ $"Opt-in: set {OptInFlag}=1 as a real environment variable (places live sandbox orders).");
+ Skip.If(string.IsNullOrWhiteSpace(_baseDomain), "CERTINEXT_DCV_DOMAIN is required (base domain for test CNs).");
+
+ int count = int.TryParse(Environment.GetEnvironmentVariable("CERTINEXT_V2_LATENCY_COUNT"), out int c) ? c : 7;
+ count = Math.Max(1, Math.Min(MaxOrders, count));
+ double spacing = double.TryParse(Environment.GetEnvironmentVariable("CERTINEXT_V2_LATENCY_SPACING_SECONDS"),
+ NumberStyles.Float, CultureInfo.InvariantCulture, out double sp) ? sp : 30;
+ bool reuse = string.Equals(Environment.GetEnvironmentVariable("CERTINEXT_V2_LATENCY_DOMAIN_MODE"),
+ "reuse", StringComparison.OrdinalIgnoreCase);
+
+ string runId = DateTime.UtcNow.ToString("MMddHHmm", CultureInfo.InvariantCulture);
+ var cfg = BuildConfig();
+
+ // Independent clients: listing poller (stands in for the sync pod) and order tracker.
+ using var listClient = new CERTInextClient(cfg);
+ using var trackClient = new CERTInextClient(cfg);
+ using var realClient = new CERTInextClient(cfg);
+ using var cleanupClient = new CERTInextClient(cfg);
+ var cleanupPlugin = new CERTInextCAPlugin(cleanupClient, cfg);
+
+ W($"V2 latency experiment run {runId}: product={_productCode}, mode={(reuse ? "reuse" : "unique")}, " +
+ $"count={count}, spacingS={F(spacing)}, pickupRetries={cfg.GetEffectivePickupRetries()}");
+
+ var trials = new List();
+ double lastT0 = double.NegativeInfinity;
+ try
+ {
+ for (int i = 0; i < count; i++)
+ {
+ var t = new Trial
+ {
+ Index = i + 1,
+ Domain = reuse ? _baseDomain : $"v2lat-{runId}-{i + 1:D2}.{_baseDomain}".ToLowerInvariant()
+ };
+ trials.Add(t);
+
+ double wait = lastT0 + spacing - Now;
+ if (wait > 0) await Task.Delay(TimeSpan.FromSeconds(wait));
+
+ try
+ {
+ await RunTrialAsync(t, cfg, realClient, listClient, trackClient, reuse);
+ lastT0 = t.T0;
+ }
+ catch (Exception ex)
+ {
+ t.Error = (t.Error.Length > 0 ? t.Error + "; " : "") + "trial: " + Describe(ex);
+ lastT0 = t.T0 > 0 ? t.T0 : Now;
+ }
+ finally
+ {
+ t.CleanupNote = await CleanupAsync(cleanupPlugin, t.OrderId);
+ }
+ LogTrial(t);
+ }
+ }
+ finally
+ {
+ WriteCsv(runId, trials);
+ WriteSummary(trials);
+ }
+ }
+
+ private async Task RunTrialAsync(Trial t, CERTInextConfig cfg, CERTInextClient realClient,
+ CERTInextClient listClient, CERTInextClient trackClient, bool reuse)
+ {
+ // Everything not under test happens before t0.
+ string csr = GenerateCsrPem(t.Domain);
+ string today = DateTime.UtcNow.ToString("yyyy-MM-dd", CultureInfo.InvariantCulture);
+ string tomorrow = DateTime.UtcNow.AddDays(1).ToString("yyyy-MM-dd", CultureInfo.InvariantCulture);
+
+ // reuse mode: orders already on the base domain today are excluded from "mine".
+ var snapshot = new HashSet(StringComparer.Ordinal);
+ if (reuse)
+ {
+ await foreach (var e in listClient.ListOrdersV2Async(today, tomorrow, 100))
+ if (string.Equals(e.DomainName, t.Domain, StringComparison.OrdinalIgnoreCase) && e.OrderNumber != null)
+ snapshot.Add(e.OrderNumber);
+ }
+ bool Mine(OrderReportEntryV2 e) =>
+ string.Equals(e.DomainName, t.Domain, StringComparison.OrdinalIgnoreCase)
+ && e.OrderNumber != null && !snapshot.Contains(e.OrderNumber);
+
+ var proxy = DispatchProxy.Create();
+ var tp = (TimingClientProxy)(object)proxy;
+ tp.Inner = realClient;
+ tp.Clock = () => Now;
+
+ var trackObs = new ConcurrentQueue();
+ var listObs = new ConcurrentQueue();
+ using var stopAll = new CancellationTokenSource();
+ Task trackerTask = Task.CompletedTask;
+ string orderIdFromCreate = null;
+
+ // The instant the place response lands, start tracking the order with the independent client.
+ tp.OnResult = (name, result) =>
+ {
+ if (name == "PlaceOrderV2Async" && result is V2CreateOrderResponse cr && orderIdFromCreate == null)
+ {
+ orderIdFromCreate = cr.OrderId;
+ t.CreateRespStatus = cr.Status ?? string.Empty;
+ trackerTask = Task.Run(async () =>
+ {
+ while (!stopAll.IsCancellationRequested)
+ {
+ var o = new TrackObs { Sent = Now };
+ try
+ {
+ var s = await trackClient.TrackOrderV2Async(Constants.ApiV2.FamilySsl, cr.OrderId);
+ o.Status = s.Status;
+ }
+ catch (Exception ex) { o.Error = Describe(ex); }
+ o.Recv = Now;
+ trackObs.Enqueue(o);
+ if (o.Error == null && IsIssuedTrack(o.Status) && double.IsNaN(t.DlProbeAt))
+ {
+ t.DlProbeAt = Now;
+ double p0 = Now;
+ try
+ {
+ var dl = await trackClient.DownloadCertificateV2Async(Constants.ApiV2.FamilySsl, cr.OrderId);
+ t.DlProbeResult = string.IsNullOrWhiteSpace(dl?.CertificatePem) ? "ok-empty" : "ok-with-certificate";
+ }
+ catch (Exception ex) { t.DlProbeResult = "error: " + Describe(ex); }
+ t.DlProbeMs = (Now - p0) * 1000.0;
+ }
+ try { await Task.Delay(TrackPollInterval, stopAll.Token); } catch (OperationCanceledException) { }
+ }
+ });
+ }
+ };
+
+ var inflight = new List();
+ var listerTask = Task.Run(async () =>
+ {
+ async Task PollOnce()
+ {
+ var o = new ListObs { Start = Now };
+ try
+ {
+ await foreach (var e in listClient.ListOrdersV2Async(today, tomorrow, 100))
+ {
+ o.Rows++;
+ if (Mine(e) && o.OrderNumber == null)
+ {
+ o.OrderNumber = e.OrderNumber;
+ o.OrderStatus = e.OrderStatus;
+ o.CertStatus = e.CertificateStatus;
+ }
+ }
+ }
+ catch (Exception ex) { o.Error = Describe(ex); }
+ o.End = Now;
+ listObs.Enqueue(o);
+ }
+ while (!stopAll.IsCancellationRequested)
+ {
+ inflight.RemoveAll(x => x.IsCompleted);
+ if (inflight.Count < MaxListPollsInFlight) inflight.Add(Task.Run(PollOnce));
+ try { await Task.Delay(ListPollInterval, stopAll.Token); } catch (OperationCanceledException) { }
+ }
+ await Task.WhenAll(inflight);
+ });
+ await Task.Delay(ListPollInterval); // listing poller is already running before t0
+
+ var plugin = new CERTInextCAPlugin(proxy, cfg);
+ var productInfo = new EnrollmentProductInfo
+ {
+ ProductID = _productCode,
+ ProductParameters = new Dictionary
+ {
+ [Constants.EnrollmentParam.ProductCode] = _productCode,
+ [Constants.EnrollmentParam.ProfileId] = _productCode,
+ }
+ };
+
+ t.T0Utc = DateTime.UtcNow;
+ t.T0 = Now;
+ EnrollmentResult result = null;
+ try
+ {
+ result = await plugin.Enroll(
+ csr: csr,
+ subject: $"CN={t.Domain}",
+ san: new Dictionary { ["dns"] = new[] { t.Domain } },
+ productInfo: productInfo,
+ requestFormat: RequestFormat.PKCS10,
+ enrollmentType: EnrollmentType.New);
+ }
+ catch (Exception ex)
+ {
+ t.Error = "Enroll: " + Describe(ex);
+ }
+ t.TEnrollEnd = Now;
+ t.OrderId = result?.CARequestID ?? orderIdFromCreate;
+ if (result != null)
+ {
+ t.EnrollStatus = ((EndEntityStatus)result.Status).ToString();
+ t.EnrollHasCert = !string.IsNullOrWhiteSpace(result.Certificate);
+ t.EnrollMessage = Scrub(result.StatusMessage ?? string.Empty);
+ }
+
+ // Keep observing: until issued is seen by tracker, or 90 s after the enroll returned.
+ double deadline = t.TEnrollEnd + 90;
+ while (Now < deadline)
+ {
+ await Task.Delay(500);
+ bool issuedSeen = trackObs.Any(o => IsIssuedTrack(o.Status));
+ if (issuedSeen && Now >= t.TEnrollEnd + 4) break;
+ if (orderIdFromCreate == null && Now >= t.TEnrollEnd + 6) break; // nothing was placed
+ }
+ stopAll.Cancel();
+ try { await Task.WhenAll(trackerTask, listerTask); } catch { /* observation only */ }
+
+ Analyze(t, tp, trackObs.OrderBy(o => o.Recv).ToList(), listObs.OrderBy(o => o.Start).ToList());
+ }
+
+ private void Analyze(Trial t, TimingClientProxy tp, List track, List lists)
+ {
+ var calls = tp.Calls.OrderBy(c => c.Start).ToList();
+ var place = calls.FirstOrDefault(c => c.Name == "PlaceOrderV2Async");
+ var csr = calls.FirstOrDefault(c => c.Name == "SubmitCsrV2Async");
+ var dl = calls.FirstOrDefault(c => c.Name == "DownloadCertificateV2Async");
+ if (place != null) { t.PlaceMs = place.DurationMs; t.TPlaceResp = place.End; if (place.Error != null) t.Error += "place: " + place.Error + "; "; }
+ if (csr != null) { t.CsrMs = csr.DurationMs; t.TCsrResp = csr.End; if (csr.Error != null) t.Error += "csr: " + csr.Error + "; "; }
+ if (dl != null) t.DownloadMs = dl.DurationMs;
+ t.TrackCallMs = calls.Where(c => c.Name == "TrackOrderV2Async").Select(c => c.DurationMs).ToList();
+
+ // Listing: first poll whose rows contained the order.
+ t.ListPolls = lists.Count;
+ t.ListErrors = lists.Count(l => l.Error != null);
+ t.ListPollMedianS = Median(lists.Select(l => l.End - l.Start));
+ var firstSeen = lists.Where(l => l.Matched).OrderBy(l => l.End).FirstOrDefault();
+ if (firstSeen != null)
+ {
+ t.FirstSeenList = firstSeen.End;
+ t.FirstSeenListLower = firstSeen.Start;
+ t.FirstSeenListStatus = Scrub(firstSeen.Combined);
+ }
+ var issuedList = lists.Where(l => l.Matched && IsIssuedListing(l)).OrderBy(l => l.End).FirstOrDefault();
+ if (issuedList != null) t.TIssuedList = issuedList.End;
+
+ var lseq = new List();
+ foreach (var l in lists.Where(l => l.Matched).OrderBy(l => l.End))
+ {
+ string s = Scrub(l.Combined);
+ if (lseq.Count == 0 || !lseq[^1].StartsWith(s + "@", StringComparison.Ordinal))
+ lseq.Add($"{s}@{F(l.End - t.T0)}");
+ }
+ t.ListSeq = string.Join("; ", lseq);
+
+ // Tracker.
+ t.TrackPolls = track.Count;
+ t.TrackErrors = track.Count(o => o.Error != null);
+ var okObs = track.Where(o => o.Error == null).ToList();
+ if (okObs.Count > 0)
+ {
+ t.TrackFirstObsRecv = okObs[0].Recv;
+ t.TrackFirstObsStatus = okObs[0].Status;
+ }
+ if (!double.IsNaN(t.TCsrResp))
+ {
+ var afterCsr = okObs.FirstOrDefault(o => o.Recv >= t.TCsrResp);
+ if (afterCsr != null) t.StatusAfterCsr = afterCsr.Status + "@" + F(afterCsr.Recv - t.T0);
+ }
+ var issuedTrack = okObs.FirstOrDefault(o => IsIssuedTrack(o.Status));
+ if (issuedTrack != null) { t.TIssuedTrack = issuedTrack.Recv; t.TIssuedTrackLower = issuedTrack.Sent; }
+
+ var tseq = new List();
+ foreach (var o in okObs)
+ if (tseq.Count == 0 || !tseq[^1].StartsWith(o.Status + "@", StringComparison.Ordinal))
+ tseq.Add($"{o.Status}@{F(o.Recv - t.T0)}");
+ t.TrackSeq = string.Join("; ", tseq);
+ foreach (var o in track.Where(o => o.Error != null).Take(2))
+ t.Error += "track: " + o.Error + "; ";
+ }
+
+ private void LogTrial(Trial t)
+ {
+ W($"trial {t.Index:D2} order={(string.IsNullOrEmpty(t.OrderId) ? "-" : t.OrderId)} " +
+ $"place={F(t.PlaceMs / 1000)}s csr={F(t.CsrMs / 1000)}s tracks=[{string.Join(",", t.TrackCallMs.Select(x => F(x / 1000)))}]s " +
+ $"download={F(t.DownloadMs / 1000)}s enrollWall={F(t.TEnrollEnd - t.T0)}s enroll={t.EnrollStatus} cert={t.EnrollHasCert} " +
+ $"createStatus={t.CreateRespStatus} firstSeenInListing={F(t.FirstSeenList - t.T0)}s({t.FirstSeenListStatus}) " +
+ $"placeResp={F(t.TPlaceResp - t.T0)}s csrResp={F(t.TCsrResp - t.T0)}s " +
+ $"dlProbe@{F(t.DlProbeAt - t.T0)}s={t.DlProbeResult} issuedTrack={F(t.TIssuedTrack - t.T0)}s issuedList={F(t.TIssuedList - t.T0)}s " +
+ $"trackSeq=[{t.TrackSeq}] listSeq=[{t.ListSeq}] cleanup={t.CleanupNote} {t.Error}");
+ }
+
+ private void WriteCsv(string runId, List trials)
+ {
+ try
+ {
+ string dir = Path.Combine(RepoRoot(), "experiment-results");
+ Directory.CreateDirectory(dir);
+ string path = Path.Combine(dir, $"v2-placeorder-latency-{runId}.csv");
+ var sb = new StringBuilder();
+ sb.AppendLine("trial,domain,order_id,t0_utc,create_resp_status,place_ms,csr_ms,track_calls_ms,download_ms," +
+ "enroll_wall_s,enroll_status,enroll_has_cert,t_place_resp_s,t_csr_resp_s,t_enroll_end_s," +
+ "first_seen_listing_s,first_seen_listing_lower_s,first_seen_listing_status," +
+ "seen_in_listing_before_place_resp,seen_in_listing_before_csr_resp,exposure_seen_to_enroll_end_s," +
+ "track_first_obs_s,track_first_obs_status,status_after_csr," +
+ "t_issued_track_s,t_issued_track_lower_s,t_issued_listing_s," +
+ "issued_before_place_resp,issued_before_csr_resp,issued_before_enroll_end," +
+ "dl_probe_at_s,dl_probe_ms,dl_probe_result,track_seq,listing_seq,list_polls,list_poll_median_s,track_polls,list_errors,track_errors,cleanup,error");
+ foreach (var t in trials)
+ {
+ string Rel(double x) => double.IsNaN(x) ? "" : F(x - t.T0);
+ string Q(string s) => "\"" + Scrub(s ?? "").Replace("\"", "'") + "\"";
+ bool seenBeforePlace = !double.IsNaN(t.FirstSeenList) && !double.IsNaN(t.TPlaceResp) && t.FirstSeenList < t.TPlaceResp;
+ bool seenBeforeCsr = !double.IsNaN(t.FirstSeenList) && !double.IsNaN(t.TCsrResp) && t.FirstSeenList < t.TCsrResp;
+ // Issued strictly before a response returned: use the observation's RECEIVE time vs that response's time.
+ bool issuedBeforePlace = !double.IsNaN(t.TIssuedList) && !double.IsNaN(t.TPlaceResp) && t.TIssuedList < t.TPlaceResp;
+ double issuedAny = double.IsNaN(t.TIssuedTrack) ? t.TIssuedList
+ : double.IsNaN(t.TIssuedList) ? t.TIssuedTrack : Math.Min(t.TIssuedTrack, t.TIssuedList);
+ bool issuedBeforeCsr = !double.IsNaN(issuedAny) && !double.IsNaN(t.TCsrResp) && issuedAny < t.TCsrResp;
+ bool issuedBeforeEnd = !double.IsNaN(issuedAny) && !double.IsNaN(t.TEnrollEnd) && issuedAny < t.TEnrollEnd;
+ double exposure = (!double.IsNaN(t.FirstSeenList) && !double.IsNaN(t.TEnrollEnd)) ? t.TEnrollEnd - t.FirstSeenList : double.NaN;
+ sb.AppendLine(string.Join(",", new[]
+ {
+ t.Index.ToString(CultureInfo.InvariantCulture), t.Domain, t.OrderId ?? "", t.T0Utc.ToString("o", CultureInfo.InvariantCulture),
+ t.CreateRespStatus, F(t.PlaceMs), F(t.CsrMs), Q(string.Join(";", t.TrackCallMs.Select(F))), F(t.DownloadMs),
+ F(t.TEnrollEnd - t.T0), t.EnrollStatus, t.EnrollHasCert ? "1" : "0", Rel(t.TPlaceResp), Rel(t.TCsrResp), Rel(t.TEnrollEnd),
+ Rel(t.FirstSeenList), Rel(t.FirstSeenListLower), Q(t.FirstSeenListStatus),
+ seenBeforePlace ? "1" : "0", seenBeforeCsr ? "1" : "0", F(exposure),
+ Rel(t.TrackFirstObsRecv), Q(t.TrackFirstObsStatus), Q(t.StatusAfterCsr),
+ Rel(t.TIssuedTrack), Rel(t.TIssuedTrackLower), Rel(t.TIssuedList),
+ issuedBeforePlace ? "1" : "0", issuedBeforeCsr ? "1" : "0", issuedBeforeEnd ? "1" : "0",
+ Rel(t.DlProbeAt), F(t.DlProbeMs), Q(t.DlProbeResult),
+ Q(t.TrackSeq), Q(t.ListSeq), t.ListPolls.ToString(CultureInfo.InvariantCulture), F(t.ListPollMedianS),
+ t.TrackPolls.ToString(CultureInfo.InvariantCulture), t.ListErrors.ToString(CultureInfo.InvariantCulture),
+ t.TrackErrors.ToString(CultureInfo.InvariantCulture), Q(t.CleanupNote), Q(t.Error)
+ }));
+ }
+ File.WriteAllText(path, sb.ToString());
+ W($"CSV written: experiment-results/{Path.GetFileName(path)}");
+ }
+ catch (Exception ex)
+ {
+ W($"CSV write failed: {Describe(ex)}");
+ }
+ }
+
+ private void WriteSummary(List trials)
+ {
+ var ok = trials.Where(t => !string.IsNullOrEmpty(t.OrderId)).ToList();
+ W($"=== summary (seconds; min / median / max; n) over {ok.Count} placed orders ===");
+ void Row(string name, Func get)
+ {
+ var xs = ok.Select(get).Where(x => !double.IsNaN(x)).ToArray();
+ W(xs.Length == 0 ? $"{name,-22} n=0"
+ : $"{name,-22} {F(xs.Min())} / {F(Median(xs))} / {F(xs.Max())} (n={xs.Length})");
+ }
+ Row("place (HTTP)", t => t.PlaceMs / 1000);
+ Row("csr submit (HTTP)", t => t.CsrMs / 1000);
+ Row("download (HTTP)", t => t.DownloadMs / 1000);
+ Row("enroll wall", t => t.TEnrollEnd - t.T0);
+ Row("first seen in listing", t => t.FirstSeenList - t.T0);
+ Row("issued (track)", t => t.TIssuedTrack - t.T0);
+ Row("issued (listing)", t => t.TIssuedList - t.T0);
+ Row("seen->enroll end", t => t.TEnrollEnd - t.FirstSeenList);
+ }
+
+ /// Revoke if issued, otherwise cancel via the raw endpoint (single attempt). Never throws.
+ private async Task CleanupAsync(CERTInextCAPlugin plugin, string orderId)
+ {
+ if (string.IsNullOrWhiteSpace(orderId)) return "no order";
+ try
+ {
+ var current = await plugin.GetSingleRecord(orderId);
+ if (current?.Status == (int)EndEntityStatus.GENERATED)
+ {
+ int r = await plugin.Revoke(orderId, hexSerialNumber: string.Empty, revocationReason: 4);
+ return $"revoked ({r})";
+ }
+ await V2RawHttpHelpers.CancelSslOrderRawAsync(_apiUrl, _clientId, _clientSecret, orderId,
+ "V2 latency experiment cleanup — order not issued, cancelling.");
+ return $"cancelled (status was {current?.Status})";
+ }
+ catch (Exception ex)
+ {
+ return "cleanup FAILED: " + Describe(ex);
+ }
+ }
+ }
+}
diff --git a/experiment-results/v2-placeorder-latency-10141548.csv b/experiment-results/v2-placeorder-latency-10141548.csv
new file mode 100644
index 0000000..f886d7b
--- /dev/null
+++ b/experiment-results/v2-placeorder-latency-10141548.csv
@@ -0,0 +1,2 @@
+trial,domain,order_id,t0_utc,create_resp_status,place_ms,csr_ms,track_calls_ms,download_ms,enroll_wall_s,enroll_status,enroll_has_cert,t_place_resp_s,t_csr_resp_s,t_enroll_end_s,first_seen_listing_s,first_seen_listing_lower_s,first_seen_listing_status,seen_in_listing_before_place_resp,seen_in_listing_before_csr_resp,exposure_seen_to_enroll_end_s,track_first_obs_s,track_first_obs_status,status_after_csr,t_issued_track_s,t_issued_track_lower_s,t_issued_listing_s,issued_before_place_resp,issued_before_csr_resp,issued_before_enroll_end,track_seq,listing_seq,list_polls,list_poll_median_s,track_polls,list_errors,track_errors,cleanup,error
+1,v2lat-10141548-01.dcv-test.scrup.org,3544182867,2026-10-14T15:48:36.3313250Z,pending-approval,4387.38,3244.75,"120.71;121.24;119.17;118.29;137.02;112.14",,64.72,EXTERNALVALIDATION,0,5.73,8.98,64.72,4.62,4.50,"Order Accepted|Pending for Approver",1,1,60.10,6.67,"pending-approval","pending-approval@10.04",,,,0,0,0,"pending-approval@6.67","Order Accepted|Pending for Approver@4.62",105,0.12,132,0,0,"cancelled (status was 90)",""
diff --git a/experiment-results/v2-placeorder-latency-10141551.csv b/experiment-results/v2-placeorder-latency-10141551.csv
new file mode 100644
index 0000000..7712774
--- /dev/null
+++ b/experiment-results/v2-placeorder-latency-10141551.csv
@@ -0,0 +1,2 @@
+trial,domain,order_id,t0_utc,create_resp_status,place_ms,csr_ms,track_calls_ms,download_ms,enroll_wall_s,enroll_status,enroll_has_cert,t_place_resp_s,t_csr_resp_s,t_enroll_end_s,first_seen_listing_s,first_seen_listing_lower_s,first_seen_listing_status,seen_in_listing_before_place_resp,seen_in_listing_before_csr_resp,exposure_seen_to_enroll_end_s,track_first_obs_s,track_first_obs_status,status_after_csr,t_issued_track_s,t_issued_track_lower_s,t_issued_listing_s,issued_before_place_resp,issued_before_csr_resp,issued_before_enroll_end,track_seq,listing_seq,list_polls,list_poll_median_s,track_polls,list_errors,track_errors,cleanup,error
+1,dcv-test.scrup.org,1226469856,2026-10-14T15:51:31.5398990Z,pending-approval,4680.93,2878.95,"125.41;121.05;120.10;130.79",2719.68,39.90,GENERATED,1,6.02,8.90,39.90,4.64,4.50,"Order Accepted|Pending for Approver",1,1,35.26,6.97,"pending-approval","pending-approval@9.22",17.27,17.14,36.15,0,0,1,"pending-approval@6.97; issued@17.27","Order Accepted|Pending for Approver@4.64; Order Accepted|Approved by System@16.63; Order Accepted|Certificate Generated@36.15; Order Fulfilled|Certificate Downloaded@40.64",31,0.12,33,0,0,"revoked (50)",""
diff --git a/experiment-results/v2-placeorder-latency-10141552.csv b/experiment-results/v2-placeorder-latency-10141552.csv
new file mode 100644
index 0000000..c8a9022
--- /dev/null
+++ b/experiment-results/v2-placeorder-latency-10141552.csv
@@ -0,0 +1,5 @@
+trial,domain,order_id,t0_utc,create_resp_status,place_ms,csr_ms,track_calls_ms,download_ms,enroll_wall_s,enroll_status,enroll_has_cert,t_place_resp_s,t_csr_resp_s,t_enroll_end_s,first_seen_listing_s,first_seen_listing_lower_s,first_seen_listing_status,seen_in_listing_before_place_resp,seen_in_listing_before_csr_resp,exposure_seen_to_enroll_end_s,track_first_obs_s,track_first_obs_status,status_after_csr,t_issued_track_s,t_issued_track_lower_s,t_issued_listing_s,issued_before_place_resp,issued_before_csr_resp,issued_before_enroll_end,track_seq,listing_seq,list_polls,list_poll_median_s,track_polls,list_errors,track_errors,cleanup,error
+1,dcv-test.scrup.org,1918886693,2026-10-14T15:52:58.5753240Z,issued,4103.53,20227.87,"113.49",2777.85,28.52,GENERATED,1,5.39,25.61,28.52,6.13,6.01,"Order Accepted|Approved by System",0,1,22.39,6.33,"issued","issued@26.73",6.33,5.39,25.63,0,1,1,"issued@6.33","Order Accepted|Approved by System@6.13; Order Accepted|Certificate Generated@25.63; Order Fulfilled|Certificate Downloaded@28.64",23,0.12,24,0,0,"revoked (50)",""
+2,dcv-test.scrup.org,7313697899,2026-10-14T15:53:55.5921110Z,pending-approval,3527.19,18789.17,"117.85",2736.23,25.58,GENERATED,1,3.93,22.72,25.58,4.64,4.50,"Order Accepted|Approved by System",0,1,20.94,4.07,"pending-approval","issued@23.17",5.18,5.07,24.14,0,1,1,"pending-approval@4.07; issued@5.18","Order Accepted|Approved by System@4.64; Order Accepted|Certificate Generated@24.14; Order Fulfilled|Certificate Downloaded@25.63",21,0.13,23,0,0,"revoked (50)",""
+3,dcv-test.scrup.org,3428572213,2026-10-14T15:54:48.6744050Z,issued,4340.89,20293.81,"119.36",2772.59,28.10,GENERATED,1,4.91,25.20,28.10,4.63,4.50,"Order Accepted|Pending for Approver",1,1,23.47,5.04,"issued","issued@25.32",5.04,4.91,25.64,0,1,1,"issued@5.04","Order Accepted|Pending for Approver@4.63; Order Accepted|Approved by System@6.13; Order Accepted|Certificate Generated@25.64; Order Fulfilled|Certificate Downloaded@28.64",23,0.13,25,0,0,"revoked (50)",""
+4,dcv-test.scrup.org,7915224579,2026-10-14T15:55:42.5126450Z,issued,3776.63,21483.81,"125.22",2740.45,28.52,GENERATED,1,4.17,25.66,28.52,4.63,4.50,"Order Accepted|Approved by System",0,1,23.89,4.37,"issued","issued@25.81",4.37,4.17,25.64,0,1,1,"issued@4.37","Order Accepted|Approved by System@4.63; Order Accepted|Certificate Generated@25.64; Order Fulfilled|Certificate Downloaded@28.64",23,0.13,26,0,0,"revoked (50)",""
diff --git a/experiment-results/v2-placeorder-latency-10141556.csv b/experiment-results/v2-placeorder-latency-10141556.csv
new file mode 100644
index 0000000..e6447e1
--- /dev/null
+++ b/experiment-results/v2-placeorder-latency-10141556.csv
@@ -0,0 +1,5 @@
+trial,domain,order_id,t0_utc,create_resp_status,place_ms,csr_ms,track_calls_ms,download_ms,enroll_wall_s,enroll_status,enroll_has_cert,t_place_resp_s,t_csr_resp_s,t_enroll_end_s,first_seen_listing_s,first_seen_listing_lower_s,first_seen_listing_status,seen_in_listing_before_place_resp,seen_in_listing_before_csr_resp,exposure_seen_to_enroll_end_s,track_first_obs_s,track_first_obs_status,status_after_csr,t_issued_track_s,t_issued_track_lower_s,t_issued_listing_s,issued_before_place_resp,issued_before_csr_resp,issued_before_enroll_end,track_seq,listing_seq,list_polls,list_poll_median_s,track_polls,list_errors,track_errors,cleanup,error
+1,dcv-test.scrup.org,8731931793,2026-10-14T15:56:53.6759880Z,issued,3730.35,18629.94,"116.12",2719.01,26.44,GENERATED,1,4.96,23.59,26.44,4.65,4.50,"Order Accepted|Pending for Approver",1,1,21.79,5.92,"issued","issued@24.13",5.92,4.96,24.13,0,1,1,"issued@5.92","Order Accepted|Pending for Approver@4.65; Order Accepted|Approved by System@6.13; Order Accepted|Certificate Generated@24.13; Order Fulfilled|Certificate Downloaded@27.14",22,0.13,22,0,0,"revoked (50)",""
+2,dcv-test.scrup.org,8487123326,2026-10-14T15:57:46.0516710Z,issued,3789.28,18738.54,"131.37",2940.75,26.04,GENERATED,1,4.23,22.97,26.04,4.64,4.50,"Order Accepted|Approved by System",0,1,21.40,4.35,"issued","issued@23.51",4.35,4.23,24.16,0,1,1,"issued@4.35","Order Accepted|Approved by System@4.64; Order Accepted|Certificate Generated@24.16; Order Fulfilled|Certificate Downloaded@27.14",22,0.13,23,0,0,"revoked (50)",""
+3,dcv-test.scrup.org,7447643132,2026-10-14T15:58:37.0139520Z,issued,3789.65,17374.89,"116.52",2850.52,24.60,GENERATED,1,4.26,21.64,24.60,4.63,4.50,"Order Accepted|Approved by System",0,1,19.97,4.39,"issued","issued@22.45",4.39,4.26,22.65,0,1,1,"issued@4.39","Order Accepted|Approved by System@4.63; Order Accepted|Certificate Generated@22.65; Order Fulfilled|Certificate Downloaded@25.63",21,0.13,22,0,0,"revoked (50)",""
+4,dcv-test.scrup.org,8595485484,2026-10-14T15:59:25.4610260Z,issued,4030.05,20343.68,"118.29",3001.09,27.90,GENERATED,1,4.44,24.78,27.90,4.63,4.50,"Order Accepted|Approved by System",0,1,23.27,4.57,"issued","issued@24.83",4.57,4.44,25.64,0,1,1,"issued@4.57","Order Accepted|Approved by System@4.63; Order Accepted|Certificate Generated@25.64; Order Fulfilled|Certificate Downloaded@28.80",23,0.13,25,0,0,"revoked (50)",""
diff --git a/experiment-results/v2-placeorder-latency-10141601.csv b/experiment-results/v2-placeorder-latency-10141601.csv
new file mode 100644
index 0000000..e95ecc1
--- /dev/null
+++ b/experiment-results/v2-placeorder-latency-10141601.csv
@@ -0,0 +1,4 @@
+trial,domain,order_id,t0_utc,create_resp_status,place_ms,csr_ms,track_calls_ms,download_ms,enroll_wall_s,enroll_status,enroll_has_cert,t_place_resp_s,t_csr_resp_s,t_enroll_end_s,first_seen_listing_s,first_seen_listing_lower_s,first_seen_listing_status,seen_in_listing_before_place_resp,seen_in_listing_before_csr_resp,exposure_seen_to_enroll_end_s,track_first_obs_s,track_first_obs_status,status_after_csr,t_issued_track_s,t_issued_track_lower_s,t_issued_listing_s,issued_before_place_resp,issued_before_csr_resp,issued_before_enroll_end,dl_probe_at_s,dl_probe_ms,dl_probe_result,track_seq,listing_seq,list_polls,list_poll_median_s,track_polls,list_errors,track_errors,cleanup,error
+1,dcv-test.scrup.org,2299934381,2026-10-14T16:01:25.5594380Z,issued,4017.95,20289.41,"114.72",2998.62,28.65,GENERATED,1,5.23,25.52,28.65,4.67,4.50,"Order Accepted|Pending for Approver",1,1,23.98,6.27,"issued","issued@25.81",6.27,5.23,25.65,0,1,1,6.27,3567.11,"error: Exception: CERTInext V2 API error during 'V2 download certificate'. HTTP 422. Unprocessable Entity: EMS-1165 Invalid request status.","issued@6.27","Order Accepted|Pending for Approver@4.67; Order Accepted|Approved by System@6.14; Order Accepted|Certificate Generated@25.65; Order Fulfilled|Certificate Downloaded@28.65",23,0.14,21,0,0,"revoked (50)",""
+2,dcv-test.scrup.org,1732815671,2026-10-14T16:02:44.5566100Z,issued,3760.70,19069.55,"118.24",2766.61,26.23,GENERATED,1,4.28,23.35,26.23,4.65,4.50,"Order Accepted|Approved by System",0,1,21.58,4.40,"issued","issued@23.95",4.40,4.28,24.15,0,1,1,4.40,3807.95,"error: Exception: CERTInext V2 API error during 'V2 download certificate'. HTTP 422. Unprocessable Entity: EMS-1165 Invalid request status.","issued@4.40","Order Accepted|Approved by System@4.65; Order Accepted|Certificate Generated@24.15; Order Fulfilled|Certificate Downloaded@27.15",22,0.14,20,0,0,"revoked (50)",""
+3,dcv-test.scrup.org,7966694779,2026-10-14T16:03:48.0246110Z,issued,3890.93,23110.25,"119.99",2794.07,30.35,GENERATED,1,4.32,27.43,30.35,5.16,4.50,"Order Accepted|Approved by System",0,1,25.19,4.51,"issued","issued@28.34",4.51,4.32,28.64,0,1,1,4.51,3557.85,"error: Exception: CERTInext V2 API error during 'V2 download certificate'. HTTP 422. Unprocessable Entity: EMS-1165 Invalid request status.","issued@4.51","Order Accepted|Approved by System@5.16; Order Accepted|Certificate Generated@28.64; Order Fulfilled|Certificate Downloaded@31.65",24,0.14,24,0,0,"revoked (50)",""
diff --git a/experiment-results/v2-placeorder-latency-summary.md b/experiment-results/v2-placeorder-latency-summary.md
new file mode 100644
index 0000000..ae5b66a
--- /dev/null
+++ b/experiment-results/v2-placeorder-latency-summary.md
@@ -0,0 +1,49 @@
+# V2 place-order latency vs. issue 0090 (2026-10-14, CERTInext sandbox)
+
+Test: `CERTInext.IntegrationTests/V2PlaceOrderLatencyExperimentTests.cs` (opt-in `CERTINEXT_V2_LATENCY_EXPERIMENT=1`).
+The plugin's real `Enroll` (V2, DV SSL 842, DCV off, default pickup 5 x 10 s) runs through a timing proxy over
+`ICERTInextClient`. Beside it, an independent client lists `/reports/orders` every 1.5 s (what Synchronize calls) and
+another tracks the order every 1 s from the moment the create response lands. Times are seconds after Enroll start (t0).
+Raw data: `v2-placeorder-latency-*.csv` (13 orders: 12 on the verified base domain, 1 on a fresh unverified subdomain).
+All 13 orders were revoked or cancelled by the test.
+
+## V2 order placement is three calls, and the hold moved to the second one
+1. `POST create` returns the orderId after 3.5-4.7 s (median 3.9 s). It does NOT hold for ~19 s.
+2. `PUT /csr` blocks 17.4-23.1 s (median 20.2 s) in 11 of 12 base-domain orders (the 12th, the first base-domain order of the day, took 2.9 s and issued ~17 s after t0 instead). The certificate is generated inside this call.
+3. `GET track` + `GET certificate` + pickup: ~0.12 s + ~2.8 s. Total `Enroll` wall time: 24.6-30.4 s (median 27.9 s) for
+ the 11 held orders; 39.9 s for the anomalous one.
+
+## Per-order table (base domain `reuse` orders; seconds after t0 unless noted)
+| order | create-resp status | place HTTP | csr HTTP | track 'issued' first seen | listing 'Certificate Generated' | csr resp | Enroll wall | listing-first-seen -> Enroll end |
+|---|---|---|---|---|---|---|---|---|
+| 1226469856 | pending-approval | 4.7 | 2.9 | 17.3 | 36.2 | 8.9 | 39.9 | 35.3 |
+| 1918886693 | issued | 4.1 | 20.2 | 6.3 | 25.6 | 25.6 | 28.5 | 22.4 |
+| 7313697899 | pending-approval | 3.5 | 18.8 | 5.2 | 24.1 | 22.7 | 25.6 | 20.9 |
+| 3428572213 | issued | 4.3 | 20.3 | 5.0 | 25.6 | 25.2 | 28.1 | 23.5 |
+| 7915224579 | issued | 3.8 | 21.5 | 4.4 | 25.6 | 25.7 | 28.5 | 23.9 |
+| 8731931793 | issued | 3.7 | 18.6 | 5.9 | 24.1 | 23.6 | 26.4 | 21.8 |
+| 8487123326 | issued | 3.8 | 18.7 | 4.4 | 24.2 | 23.0 | 26.0 | 21.4 |
+| 7447643132 | issued | 3.8 | 17.4 | 4.4 | 22.7 | 21.6 | 24.6 | 20.0 |
+| 8595485484 | issued | 4.0 | 20.3 | 4.6 | 25.6 | 24.8 | 27.9 | 23.3 |
+| 2299934381 | issued | 4.0 | 20.3 | 6.3 | 25.7 | 25.5 | 28.7 | 24.0 |
+| 1732815671 | issued | 3.8 | 19.1 | 4.4 | 24.2 | 23.4 | 26.2 | 21.6 |
+| 7966694779 | issued | 3.9 | 23.1 | 4.5 | 28.6 | 27.4 | 30.4 | 25.2 |
+
+Unverified fresh subdomain (3544182867): create `pending-approval`, place 4.4 s, csr 3.2 s, still `pending-approval`
+>150 s later (no DCV in this run); Enroll returned EXTERNALVALIDATION after 64.7 s.
+
+## Key datum
+- In 11 of 12 base-domain orders the order is already `issued` (per the V2 track endpoint) **before the CSR PUT returns**,
+ by ~17-21 s; in 10 of 12 the create response itself already says `issued`. This is the production V1 pattern (order
+ already issued while the response is held), moved to `PUT /csr`.
+- The sync-visible window (first sighting in `/reports/orders`, within ~1.5 s of the create response (before it in 5 of 13 orders), to Enroll return, when
+ the gateway learns the CARequestID) is 20.0-25.2 s (median 22.4 s) for held orders; 35.3 s for the anomalous one.
+ The listing shows `Order Accepted | Pending for Approver` or `Approved by System` for the whole window and flips to
+ `Certificate Generated` only about when the CSR PUT returns.
+
+## Caveats
+- V1 sandbox did NOT reproduce production's hold, so these are suggestive, not proof, for production V2. The V2 sandbox
+ does reproduce the shape (issued before response, ~20 s hold), which V1 sandbox did not.
+- One account, one ~25 minute window, 13 orders; first-sighting resolution is the 1.5 s poll interval.
+- Phase 1 orders share the sandbox account with the kfclab gateway, whose own sync imported at least one of them
+ (gateway row 1826, order 8595485484).