From 3e3d5815b96bc9a34faea51440beac5167079923 Mon Sep 17 00:00:00 2001 From: spbsoluble <1661003+spbsoluble@users.noreply.github.com> Date: Fri, 31 Jul 2026 10:11:23 -0700 Subject: [PATCH 1/5] =?UTF-8?q?feat(enroll):=20synchronous=20certificate?= =?UTF-8?q?=20pickup=20(Sectigo=20parity)=20=E2=80=94=20v1.0.1?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit After submitting an order, Enroll() polls GetCertificate up to PickupRetries times (default 5), PickupDelay seconds apart (default 10), after a 5s initial delay, so a fast-issuing order returns the certificate in the same enrollment call instead of waiting for the next sync. Mirrors the legacy Sectigo connector's PickUpEnrolledCertificate (~55s max worker-thread occupancy by default). Applied to the new, reissue, and renew paths; both build flavors. PickupRetries=0 disables. Orders not issued within the window are returned pending and imported by a later sync (unchanged). OV/EV are issued asynchronously by the CA and typically exhaust the window; DV / already-approved orders return in-call. --- CERTInext/CERTInextCAPlugin.cs | 136 ++++++++++++++++++++++++++- CERTInext/CERTInextCAPluginConfig.cs | 57 +++++++++++ CERTInext/Constants.cs | 30 ++++++ CHANGELOG.md | 5 + 4 files changed, 227 insertions(+), 1 deletion(-) diff --git a/CERTInext/CERTInextCAPlugin.cs b/CERTInext/CERTInextCAPlugin.cs index 231f611..df51796 100644 --- a/CERTInext/CERTInextCAPlugin.cs +++ b/CERTInext/CERTInextCAPlugin.cs @@ -1170,8 +1170,15 @@ private async Task EnrollNewAsync( } #endif + // Synchronous certificate pickup (Sectigo-parity): poll for the issued certificate so + // a fast-issuing order returns GENERATED + PEM in this same call. No-op for the + // already-issued/failed case and for OV/EV orders that CERTInext issues asynchronously + // — those fall back to the pending result and are imported by the next sync. + var newResult = BuildEnrollmentResult(enrollResp, ep.AutoApprove); + newResult = await PickUpEnrolledCertificateAsync(newResult, enrollResp.Id); + _logger.MethodExit(LogLevel.Debug); - return BuildEnrollmentResult(enrollResp, ep.AutoApprove); + return newResult; } /// @@ -1297,6 +1304,9 @@ private async Task RenewOrReissueAsync( "PriorCARequestID={PriorId}, NewCARequestID={NewId}, Status={Status}", priorCaRequestId, renewResult.CARequestID, renewResult.Status); + // Synchronous certificate pickup (Sectigo-parity), same as the new-enrollment path. + renewResult = await PickUpEnrolledCertificateAsync(renewResult, renewResp.Id); + return renewResult; } else @@ -1868,6 +1878,130 @@ private async Task WaitForDcvVerificationAsync(string orderNumber, IReadOnlyList } } + /// + /// Synchronous certificate pickup — parity with the legacy Sectigo connector's + /// PickUpEnrolledCertificate. After an order is submitted, polls + /// GetCertificate up to PickupRetries times, PickupDelay seconds + /// apart (after a fixed initial delay), so an order that issues quickly is returned + /// GENERATED + PEM in the same enrollment call instead of waiting for the next + /// synchronization. If the certificate has not issued within the budget, the original + /// pending result is returned unchanged and the order is imported by a later sync — + /// behaviour identical to before this feature. + /// + /// Applies to ALL products. CERTInext issues OV/EV asynchronously (organization + /// verification, minutes to hours; confirmed by CERTInext support ticket #162763), so + /// those typically exhaust the budget and fall back to pending; only DV / already-approved + /// orders return in-call. Never throws — any polling error degrades to the pending result. + /// + private async Task PickUpEnrolledCertificateAsync( + EnrollmentResult pendingResult, string orderNumber) + { + // Only a still-pending (external-validation) result can benefit from a pickup poll. + // An already issued/failed/revoked result, or a missing order number, is returned as-is. + if (pendingResult == null + || pendingResult.Status != (int)EndEntityStatus.EXTERNALVALIDATION + || string.IsNullOrWhiteSpace(orderNumber)) + return pendingResult; + + int retries = _config.GetEffectivePickupRetries(); + if (retries <= 0) + { + _logger.LogInformation( + "Synchronous certificate pickup disabled (PickupRetries<=0). Order {OrderNumber} " + + "will be picked up on the next synchronization.", orderNumber); + return pendingResult; + } + + int delaySeconds = _config.GetEffectivePickupDelaySeconds(); + _logger.LogInformation( + "Starting synchronous certificate pickup. OrderNumber={OrderNumber}, PickupRetries={Retries}, " + + "PickupDelaySeconds={Delay} (max ~{Max}s including a {Initial}s initial delay).", + orderNumber, retries, delaySeconds, + Constants.Pickup.InitialDelaySeconds + retries * delaySeconds, Constants.Pickup.InitialDelaySeconds); + + try + { + // Small static delay before the first poll — mirrors the Sectigo connector's + // attempt to let a fast order finish issuing before we start polling at all. + await Task.Delay(TimeSpan.FromSeconds(Constants.Pickup.InitialDelaySeconds)); + + for (int attempt = 1; attempt <= retries; attempt++) + { + try + { + var cert = await _client.GetCertificateAsync(orderNumber); + int disposition = StatusMapper.ToRequestDisposition(cert.Status); + + // Issued: only surface GENERATED when the PEM is actually present — never + // hand Command a body-less "issued" record. A body-less issued state keeps + // polling until the body appears or the budget runs out. + if (disposition == (int)EndEntityStatus.GENERATED + && !string.IsNullOrWhiteSpace(cert.Certificate)) + { + _logger.LogInformation( + "Synchronous pickup complete. OrderNumber={OrderNumber}, SerialNumber={Serial}, " + + "Attempt={Attempt}/{Retries}.", + orderNumber, + string.IsNullOrWhiteSpace(cert.SerialNumber) ? "(none)" : cert.SerialNumber, + attempt, retries); + return new EnrollmentResult + { + CARequestID = string.IsNullOrWhiteSpace(cert.Id) ? orderNumber : cert.Id, + Certificate = cert.Certificate, + Status = (int)EndEntityStatus.GENERATED, + StatusMessage = $"Certificate issued successfully. CERTInext ID: {orderNumber}." + }; + } + + // Terminal non-issued outcomes carry no body and are surfaced immediately. + if (disposition == (int)EndEntityStatus.REVOKED + || disposition == (int)EndEntityStatus.FAILED) + { + _logger.LogInformation( + "Order {OrderNumber} reached terminal status '{Status}' during synchronous pickup.", + orderNumber, cert.Status); + return new EnrollmentResult + { + CARequestID = string.IsNullOrWhiteSpace(cert.Id) ? orderNumber : cert.Id, + Certificate = cert.Certificate, + Status = disposition, + StatusMessage = $"Order {orderNumber} reached status '{cert.Status}' during enrollment pickup." + }; + } + } + catch (Exception ex) + { + // A transient fetch failure consumes an attempt rather than aborting the + // wait; if it never recovers the pending result is returned below. + _logger.LogWarning(ex, + "Pickup GetCertificate failed for order {OrderNumber} (attempt {Attempt}/{Retries}).", + orderNumber, attempt, retries); + } + + // Delay after every attempt (including the last), matching the Sectigo + // connector's pickup cadence so the max-occupancy ceiling is identical. + await Task.Delay(TimeSpan.FromSeconds(delaySeconds)); + } + + _logger.LogInformation( + "Synchronous pickup did not complete within {Retries} attempts for order {OrderNumber}. " + + "Returning pending result; the certificate will be imported by the next synchronization. " + + "CERTInext issues OV/EV asynchronously by design (support ticket #162763).", + retries, orderNumber); + pendingResult.StatusMessage = + $"{pendingResult.StatusMessage} The certificate was not issued within the enrollment-pickup " + + "window; it will be imported by a later synchronization."; + } + catch (Exception ex) + { + _logger.LogWarning(ex, + "Synchronous pickup failed for order {OrderNumber}. Returning pending result; " + + "sync will pick up the certificate later.", orderNumber); + } + + return pendingResult; + } + /// /// Converts a CERTInext API enrollment/renewal response into the /// expected by the AnyCA gateway. diff --git a/CERTInext/CERTInextCAPluginConfig.cs b/CERTInext/CERTInextCAPluginConfig.cs index 43d0537..baf86c9 100644 --- a/CERTInext/CERTInextCAPluginConfig.cs +++ b/CERTInext/CERTInextCAPluginConfig.cs @@ -272,6 +272,29 @@ public static Dictionary GetCAConnectorAnnotations() DefaultValue = true, Type = "Boolean" }, + [Constants.Config.PickupRetries] = new PropertyConfigInfo + { + Comments = "OPTIONAL: Number of times Enroll() will poll CERTInext to download the certificate after a " + + "successful order submission. If the certificate has not issued within this window it is " + + "picked up during the next synchronization instead. Set to 0 to disable the wait. " + + $"Default: {Constants.Pickup.DefaultRetries}. NOTE: CERTInext issues OV/EV certificates " + + "asynchronously (organization verification, minutes to hours), so those typically exhaust " + + "the wait and are returned pending regardless of this value.", + Hidden = false, + DefaultValue = Constants.Pickup.DefaultRetries, + Type = "Number" + }, + [Constants.Config.PickupDelay] = new PropertyConfigInfo + { + Comments = "OPTIONAL: Number of seconds between certificate-pickup retries. The total number of retries " + + "times this delay (plus a short initial delay) is the maximum time an enrollment call " + + "occupies a Command worker thread. If the duration is too long the request may time out, so " + + $"keep the total well under ~90s. Default: {Constants.Pickup.DefaultDelaySeconds} " + + $"(with default retries this yields a ~{Constants.Pickup.InitialDelaySeconds + Constants.Pickup.DefaultRetries * Constants.Pickup.DefaultDelaySeconds}s ceiling).", + Hidden = false, + DefaultValue = Constants.Pickup.DefaultDelaySeconds, + Type = "Number" + }, [Constants.Config.DcvEnabled] = new PropertyConfigInfo { Comments = "OPTIONAL: When true, the gateway will perform DNS-based Domain Control Validation (DCV) " + @@ -695,6 +718,23 @@ public class CERTInextConfig /// Seconds to wait after publishing the DNS TXT record before calling VerifyDcv. /// Default: 30. /// + /// + /// Number of GetCertificate poll attempts inside Enroll() after an order is + /// submitted, before falling back to a pending result (picked up by the next sync). + /// Mirrors the legacy Sectigo connector's PickupRetries. Set to 0 to disable. + /// Default: 5. + /// + [JsonPropertyName("PickupRetries")] + public int PickupRetries { get; set; } = Constants.Pickup.DefaultRetries; + + /// + /// Seconds between certificate-pickup retries. PickupRetries * PickupDelay (plus a + /// short initial delay) bounds the time an enrollment call occupies a Command worker + /// thread. Mirrors the legacy Sectigo connector's PickupDelay. Default: 10. + /// + [JsonPropertyName("PickupDelay")] + public int PickupDelayInSeconds { get; set; } = Constants.Pickup.DefaultDelaySeconds; + [JsonPropertyName("DcvPropagationDelaySeconds")] public int DcvPropagationDelaySeconds { get; set; } = 30; @@ -782,5 +822,22 @@ public int GetEffectiveDcvWaitForIssuanceSeconds() return envVal; return DcvWaitForIssuanceSeconds >= 0 ? DcvWaitForIssuanceSeconds : 60; } + + /// + /// Effective number of certificate-pickup retries, clamped to + /// [0, ]. 0 disables the synchronous pickup. + /// + public int GetEffectivePickupRetries() + => System.Math.Max(0, System.Math.Min(PickupRetries, Constants.Pickup.MaxRetries)); + + /// + /// Effective seconds between pickup retries, clamped to + /// [1, ]. A non-positive configured value + /// falls back to the default rather than producing a tight busy-loop. + /// + public int GetEffectivePickupDelaySeconds() + => System.Math.Max(1, System.Math.Min( + PickupDelayInSeconds > 0 ? PickupDelayInSeconds : Constants.Pickup.DefaultDelaySeconds, + Constants.Pickup.MaxDelaySeconds)); } } diff --git a/CERTInext/Constants.cs b/CERTInext/Constants.cs index 83e6929..abf5188 100644 --- a/CERTInext/Constants.cs +++ b/CERTInext/Constants.cs @@ -21,6 +21,16 @@ public static class Config public const string Enabled = "Enabled"; public const string IgnoreExpired = "IgnoreExpired"; public const string PageSize = "PageSize"; + + // Synchronous certificate pickup (parity with the legacy Sectigo connector). + // After submitting an order, Enroll() polls GetCertificate up to PickupRetries + // times, PickupDelay seconds apart (after a fixed initial delay), so a fast-issuing + // order returns the issued certificate in the same enrollment call instead of + // waiting for the next synchronization. On timeout the order is returned pending and + // imported by a later sync — behaviour identical to before this feature. + public const string PickupRetries = "PickupRetries"; + public const string PickupDelay = "PickupDelay"; + public const string RequestorName = "RequestorName"; public const string RequestorEmail = "RequestorEmail"; public const string RequestorIsdCode = "RequestorIsdCode"; @@ -268,6 +278,26 @@ public static class RevocationReasonId public const int Default = KeyCompromise; } + public static class Pickup + { + // Defaults mirror the legacy Sectigo connector's PickUpEnrolledCertificate: + // a 5-second initial delay, then up to 5 poll attempts 10 seconds apart, so the + // maximum time an enrollment call occupies a Command worker thread is + // InitialDelaySeconds + DefaultRetries * DefaultDelaySeconds = 5 + 5*10 = 55 seconds. + // Set PickupRetries to 0 to disable the wait entirely (immediate pending return). + public const int DefaultRetries = 5; + public const int DefaultDelaySeconds = 10; + + // Small static delay before the first poll — gives a fast order a chance to finish + // issuing before we poll at all, avoiding a guaranteed-miss first attempt. + public const int InitialDelaySeconds = 5; + + // Safety clamps so a mis-configured connector cannot orphan a worker thread. Command + // abandons enrollment calls well before these bounds; they only backstop absurd input. + public const int MaxRetries = 30; + public const int MaxDelaySeconds = 60; + } + public static class Dcv { // CERTInext dcvMethod values (dcvDetails.dcvMethod in GetDcv / VerifyDcv) diff --git a/CHANGELOG.md b/CHANGELOG.md index 6065cb2..44022a4 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,8 @@ +# 1.0.1 + +## Features +- feat(enroll): `Enroll()` now polls for the issued certificate after submitting an order, so fast-issuing (DV / already-approved) orders return in the same call instead of waiting for the next sync. Tunable via `PickupRetries` (default 5, `0` disables) and `PickupDelay` (default 10s); ~55s default ceiling. Orders not issued within the window are returned pending and imported by a later sync, as before. + # 1.0.0 Initial release of the CERTInext (emSign Hub) AnyCA REST Gateway plugin. From 77fe123b6ffc445efa4227294b052978cdf91ffc Mon Sep 17 00:00:00 2001 From: spbsoluble <1661003+spbsoluble@users.noreply.github.com> Date: Fri, 31 Jul 2026 10:27:27 -0700 Subject: [PATCH 2/5] chore(enroll): log RequestFormat on the enrollment-start line MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit RequestFormat is received by Enroll() but was never logged, so logs could not show what Command passes for CSR vs PFX enrollments. Add it to the enrollment-start Information line for diagnostics. Behavior unchanged — the value is still not used for any decision (the gateway treats every enrollment as a CSR-based request). --- CERTInext/CERTInextCAPlugin.cs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/CERTInext/CERTInextCAPlugin.cs b/CERTInext/CERTInextCAPlugin.cs index df51796..52fc364 100644 --- a/CERTInext/CERTInextCAPlugin.cs +++ b/CERTInext/CERTInextCAPlugin.cs @@ -573,10 +573,10 @@ public async Task Enroll( _logger.LogInformation( "Enrollment attempt started. " + - "EnrollmentType={EnrollmentType}, Subject={Subject}, " + + "EnrollmentType={EnrollmentType}, RequestFormat={RequestFormat}, Subject={Subject}, " + "ProfileId={ProfileId}, SANs={SANs}, " + "RequesterName={RequesterName}, RequesterEmail={RequesterEmail}", - enrollmentType, subject, + enrollmentType, requestFormat, subject, ep.ProfileId, sanSummary, ep.RequesterName, ep.RequesterEmail); From 49616cc83e640385c9731ff3da8e5ca4f269fc6b Mon Sep 17 00:00:00 2001 From: spbsoluble <1661003+spbsoluble@users.noreply.github.com> Date: Fri, 31 Jul 2026 13:14:46 -0700 Subject: [PATCH 3/5] fix(client): don't retry non-idempotent order/CSR submits on a network timeout MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A network-level timeout on GenerateOrderSSL / SubmitCSR can occur after CERTInext has already received and created the order. The inner HTTP retry re-sent the same request body (same requestTxn), which CERTInext rejected as EMS-947 "Duplicate requestTxn" — failing the enrollment while orphaning the created order. ExecuteWithRetryAsync gains an `idempotent` flag; PlaceOrderAsync and SubmitCsrAsync now submit once (idempotent:false). A transient submit failure and an EMS-947 duplicate are each logged as an explicit no-retry decision and surfaced with a clear, conditional message (if an order was created it is imported by the next sync). Idempotent read calls are unchanged and still retry. --- CERTInext/Client/CERTInextClient.cs | 80 ++++++++++++++++++++++++++--- CHANGELOG.md | 4 ++ 2 files changed, 78 insertions(+), 6 deletions(-) diff --git a/CERTInext/Client/CERTInextClient.cs b/CERTInext/Client/CERTInextClient.cs index 255b65a..edc9970 100644 --- a/CERTInext/Client/CERTInextClient.cs +++ b/CERTInext/Client/CERTInextClient.cs @@ -216,7 +216,11 @@ public async Task PlaceOrderAsync( req.AddJsonBody(JsonSerializer.Serialize(request, GetJsonOptions())); var sw = System.Diagnostics.Stopwatch.StartNew(); - resp = await ExecuteWithRetryAsync(req, ct); + // idempotent:false — order submission is non-idempotent. A network-level + // timeout may occur after CERTInext already created the order, so re-sending the + // same requestTxn would be rejected as EMS-947 and orphan the created order + // Rate-limit retries are still handled below (with a fresh txn). + resp = await ExecuteWithRetryAsync(req, ct, idempotent: false); sw.Stop(); Logger.LogInformation( @@ -232,6 +236,25 @@ public async Task PlaceOrderAsync( $"Authentication failure during certificate order. HTTP {(int)resp.StatusCode}. See gateway logs for details."); } + // Transient/network failure (5xx or no HTTP status) on a non-idempotent submit: + // CERTInext may have already created the order (the response just didn't reach us). + // We deliberately did not retry (see idempotent:false above). Fail clearly instead + // of deserializing an empty body; if the order was created, the next sync imports it. + bool transientFailure = !resp.IsSuccessful + && !((int)resp.StatusCode >= 400 && (int)resp.StatusCode < 500); + if (transientFailure) + { + Logger.LogWarning( + "PlaceOrder received no usable response (HttpStatus={Status}, LatencyMs={Latency}). " + + "Not retrying to avoid a duplicate order (EMS-947). If CERTInext created the order it " + + "will be imported by the next synchronization.", + (int)resp.StatusCode, sw.ElapsedMilliseconds); + throw new Exception( + "CERTInext did not return a usable response to the order submission. If the order was " + + "created it will be imported by the next synchronization — do not resubmit immediately. " + + "See gateway logs for details."); + } + result = DeserializeOrThrow(resp, "place order"); if (result.Meta != null && !result.Meta.IsSuccess) @@ -259,6 +282,29 @@ public async Task PlaceOrderAsync( continue; // retry } + // EMS-947 "Duplicate requestTxn": CERTInext already received an order for this + // transaction. With the non-idempotent-retry fix above this should no longer be + // caused by our own retry, but if it still surfaces the order exists on the CA + // side and will be imported by the next sync — say so, not a generic failure. + bool isDuplicateTxn = + string.Equals(result.Meta.ErrorCode, "EMS-947", StringComparison.OrdinalIgnoreCase) + || (result.Meta.ErrorMessage?.IndexOf("Duplicate requestTxn", StringComparison.OrdinalIgnoreCase) >= 0); + if (isDuplicateTxn) + { + // Log the classification decision itself (parity with the transient-failure + // branch above) so an auditor sees the plugin deliberately treated this as a + // benign duplicate rather than a hard failure. + Logger.LogWarning( + "PlaceOrder classified {ErrorCode} as a duplicate transaction (not a hard failure). " + + "Path={Path}, HttpStatus={Status}, LatencyMs={Latency}. If an order exists for this " + + "transaction it will be imported by the next synchronization.", + result.Meta.ErrorCode, Constants.Api.GenerateOrderSslPath, (int)resp.StatusCode, sw.ElapsedMilliseconds); + throw new Exception( + "CERTInext reported a duplicate order transaction (EMS-947). If an order was created " + + "for this transaction it will be imported by the next synchronization — do not resubmit " + + "immediately. See gateway logs for details."); + } + throw new Exception( $"CERTInext order failed: {result.Meta.ErrorMessage ?? result.Meta.ErrorCode}. " + "See gateway logs for details."); @@ -300,7 +346,9 @@ public async Task SubmitCsrAsync(SubmitCsrRequest request, CancellationToken ct req.AddJsonBody(JsonSerializer.Serialize(request, GetJsonOptions())); var sw = System.Diagnostics.Stopwatch.StartNew(); - var resp = await ExecuteWithRetryAsync(req, ct); + // idempotent:false — submitting a CSR is non-idempotent; do not resend on a network + // timeout (the first attempt may have been received). See PlaceOrderAsync. + var resp = await ExecuteWithRetryAsync(req, ct, idempotent: false); sw.Stop(); Logger.LogInformation( @@ -310,6 +358,17 @@ public async Task SubmitCsrAsync(SubmitCsrRequest request, CancellationToken ct if (!resp.IsSuccessful) { LogApiFailure(Constants.Api.SubmitCsrPath, resp); + // Parity with PlaceOrderAsync: a transient/network failure on this non-idempotent + // submit was NOT retried, so record that decision (the CSR may already have been + // received). 4xx client errors fall through to the generic failure below. + bool transientFailure = !((int)resp.StatusCode >= 400 && (int)resp.StatusCode < 500); + if (transientFailure) + { + Logger.LogWarning( + "SubmitCSR received no usable response (HttpStatus={Status}, LatencyMs={Latency}); not retrying " + + "(non-idempotent). If CERTInext already received the CSR, do not resubmit immediately.", + (int)resp.StatusCode, sw.ElapsedMilliseconds); + } throw new Exception($"CERTInext SubmitCSR failed. HTTP {(int)resp.StatusCode}. See gateway logs for details."); } @@ -1213,14 +1272,23 @@ private async Task GetOrRefreshTokenAsync(CancellationToken ct) /// attempts, retrying on HTTP 5xx and network-level failures (no status code). /// 4xx responses are returned immediately — client errors will not be resolved /// by retrying. + /// + /// When is false the request is sent exactly + /// once and transient failures are NOT retried. This is required for non-idempotent + /// order-submission calls: a network-level timeout can occur *after* CERTInext has + /// already received and created the order, so re-sending the same body (same + /// requestTxn) is rejected as "Duplicate requestTxn" (EMS-947) and orphans the + /// order the first attempt actually created. /// private async Task ExecuteWithRetryAsync( RestRequest req, CancellationToken ct, - int maxAttempts = 3) + int maxAttempts = 3, + bool idempotent = true) { + int attempts = idempotent ? maxAttempts : 1; RestResponse resp = null; - for (int attempt = 1; attempt <= maxAttempts; attempt++) + for (int attempt = 1; attempt <= attempts; attempt++) { resp = await _http.ExecuteAsync(req, ct); @@ -1229,11 +1297,11 @@ private async Task ExecuteWithRetryAsync( if (resp.IsSuccessful || isClientError) return resp; - if (attempt < maxAttempts) + if (attempt < attempts) { Logger.LogWarning( "CERTInext API returned {Status} on attempt {Attempt}/{Max} — retrying...", - (int)resp.StatusCode, attempt, maxAttempts); + (int)resp.StatusCode, attempt, attempts); } } diff --git a/CHANGELOG.md b/CHANGELOG.md index 44022a4..e53dcd8 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,10 @@ ## Features - feat(enroll): `Enroll()` now polls for the issued certificate after submitting an order, so fast-issuing (DV / already-approved) orders return in the same call instead of waiting for the next sync. Tunable via `PickupRetries` (default 5, `0` disables) and `PickupDelay` (default 10s); ~55s default ceiling. Orders not issued within the window are returned pending and imported by a later sync, as before. +- chore(enroll): The enrollment-start log line now includes `RequestFormat` for diagnostics. + +## Bug Fixes +- fix(client): Order submission (`GenerateOrderSSL`) and CSR submission are no longer auto-retried on a network-level timeout. Because a timeout can occur after the CA has already created the order, re-sending the same transaction was being rejected as a duplicate (`EMS-947 "Duplicate requestTxn"`), failing the enrollment while orphaning the created order. Non-idempotent submissions now run once; if the CA created the order it is imported by the next synchronization. A duplicate-transaction response is also now reported with a clear, actionable message. (Idempotent read calls are unaffected and still retry.) # 1.0.0 From e8e47391ec26262f6fb8c0d03c12e1356a32f474 Mon Sep 17 00:00:00 2001 From: spbsoluble <1661003+spbsoluble@users.noreply.github.com> Date: Fri, 31 Jul 2026 13:23:46 -0700 Subject: [PATCH 4/5] fix(client): enrich orphaned-order warnings + SubmitCSR transient guidance MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Compliance follow-ups (both Low): - Add DomainName as a non-sensitive correlation key to the PlaceOrder transient and EMS-947 warnings so an orphaned order can be tied to its enrollment under concurrency (requestTxn is deliberately NOT logged — it is part of the authKey preimage). - SubmitCSR now carries the "may already have been received; do not resubmit" guidance in the thrown exception on a transient failure, for parity with PlaceOrderAsync (previously only in the log line). --- CERTInext/Client/CERTInextClient.cs | 15 ++++++++++----- 1 file changed, 10 insertions(+), 5 deletions(-) diff --git a/CERTInext/Client/CERTInextClient.cs b/CERTInext/Client/CERTInextClient.cs index edc9970..668c4a3 100644 --- a/CERTInext/Client/CERTInextClient.cs +++ b/CERTInext/Client/CERTInextClient.cs @@ -245,10 +245,10 @@ public async Task PlaceOrderAsync( if (transientFailure) { Logger.LogWarning( - "PlaceOrder received no usable response (HttpStatus={Status}, LatencyMs={Latency}). " + + "PlaceOrder received no usable response (DomainName={Domain}, HttpStatus={Status}, LatencyMs={Latency}). " + "Not retrying to avoid a duplicate order (EMS-947). If CERTInext created the order it " + "will be imported by the next synchronization.", - (int)resp.StatusCode, sw.ElapsedMilliseconds); + request.OrderDetails?.CertificateInformation?.DomainName, (int)resp.StatusCode, sw.ElapsedMilliseconds); throw new Exception( "CERTInext did not return a usable response to the order submission. If the order was " + "created it will be imported by the next synchronization — do not resubmit immediately. " + @@ -296,9 +296,9 @@ public async Task PlaceOrderAsync( // benign duplicate rather than a hard failure. Logger.LogWarning( "PlaceOrder classified {ErrorCode} as a duplicate transaction (not a hard failure). " + - "Path={Path}, HttpStatus={Status}, LatencyMs={Latency}. If an order exists for this " + - "transaction it will be imported by the next synchronization.", - result.Meta.ErrorCode, Constants.Api.GenerateOrderSslPath, (int)resp.StatusCode, sw.ElapsedMilliseconds); + "DomainName={Domain}, Path={Path}, HttpStatus={Status}, LatencyMs={Latency}. If an order exists " + + "for this transaction it will be imported by the next synchronization.", + result.Meta.ErrorCode, request.OrderDetails?.CertificateInformation?.DomainName, Constants.Api.GenerateOrderSslPath, (int)resp.StatusCode, sw.ElapsedMilliseconds); throw new Exception( "CERTInext reported a duplicate order transaction (EMS-947). If an order was created " + "for this transaction it will be imported by the next synchronization — do not resubmit " + @@ -368,6 +368,11 @@ public async Task SubmitCsrAsync(SubmitCsrRequest request, CancellationToken ct "SubmitCSR received no usable response (HttpStatus={Status}, LatencyMs={Latency}); not retrying " + "(non-idempotent). If CERTInext already received the CSR, do not resubmit immediately.", (int)resp.StatusCode, sw.ElapsedMilliseconds); + // Parity with PlaceOrderAsync: carry the actionable guidance into the surfaced + // exception, not only the log line. + throw new Exception( + "CERTInext did not return a usable response to the CSR submission. If the CSR was received " + + "it will take effect — do not resubmit immediately. See gateway logs for details."); } throw new Exception($"CERTInext SubmitCSR failed. HTTP {(int)resp.StatusCode}. See gateway logs for details."); } From 6ae12b762884f17483f09a11e21c721433103ba5 Mon Sep 17 00:00:00 2001 From: spbsoluble <1661003+spbsoluble@users.noreply.github.com> Date: Fri, 31 Jul 2026 14:28:07 -0700 Subject: [PATCH 5/5] =?UTF-8?q?fix(enroll):=20harden=20synchronous=20picku?= =?UTF-8?q?p=20=E2=80=94=20DCV=20gating,=20wait=20ceiling,=20audit=20loggi?= =?UTF-8?q?ng?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Review-driven refinements to the v1.0.1 synchronous-pickup feature: - Skip the pickup poll when the DCV path already owns the in-call issuance wait, so the two never stack and a cancelled/rejected order is not re-polled for the full window (fixes a regression that broke the terminal-order guard). - Cap total in-call pickup wait at 180s regardless of how PickupRetries and PickupDelay are configured, so an aggressive combination can't exceed Command's enrollment timeout. - Log a terminal FAILED at Error and REVOKED at Warning; trace each poll at Debug; distinguish "all polls errored" from "still pending" in the timeout summary; include OrderNumber in the CSR transient-failure warning; surface a pending result that has no order number to poll instead of skipping silently. - Default pickup off in the unit-test fixtures and add targeted pickup tests (disabled / issued / terminal / budget-exhausted). Both flavors build clean (0 warnings); DCV 199/199, no-DCV 176/176. --- CERTInext.Tests/CERTInextCAPluginDcvTests.cs | 22 ++-- CERTInext.Tests/CERTInextCAPluginTests.cs | 107 ++++++++++++++++- CERTInext/CERTInextCAPlugin.cs | 119 ++++++++++++++++--- CERTInext/CERTInextCAPluginConfig.cs | 10 +- CERTInext/Client/CERTInextClient.cs | 7 +- CERTInext/Constants.cs | 12 +- CHANGELOG.md | 5 +- 7 files changed, 248 insertions(+), 34 deletions(-) diff --git a/CERTInext.Tests/CERTInextCAPluginDcvTests.cs b/CERTInext.Tests/CERTInextCAPluginDcvTests.cs index 837ae8d..d812074 100644 --- a/CERTInext.Tests/CERTInextCAPluginDcvTests.cs +++ b/CERTInext.Tests/CERTInextCAPluginDcvTests.cs @@ -35,7 +35,8 @@ private static CERTInextConfig DcvConfig( int propagationDelaySeconds = 1, int timeoutMinutes = 1, int dcvWaitForChallengeSeconds = 0, - int dcvWaitForIssuanceSeconds = 0) => + int dcvWaitForIssuanceSeconds = 0, + int pickupRetries = 0) => new CERTInextConfig { DcvEnabled = enabled, @@ -45,7 +46,12 @@ private static CERTInextConfig DcvConfig( // behaviour and run fast. Tests that exercise the new wait paths can opt // in with a positive value (see WaitsForChallenge_ToAppear / WaitsForIssuance). DcvWaitForChallengeSeconds = dcvWaitForChallengeSeconds, - DcvWaitForIssuanceSeconds = dcvWaitForIssuanceSeconds + DcvWaitForIssuanceSeconds = dcvWaitForIssuanceSeconds, + // Disable the synchronous pickup poll by default (same reasoning as the wait + // budgets above): the DCV path owns issuance for these tests, and a DCV-disabled + // or no-factory case that ends on a pending result must not pay the real pickup + // Task.Delay loop. The dedicated pickup tests live in CERTInextCAPluginTests. + PickupRetries = pickupRetries }; private static Mock NewMock() => @@ -437,17 +443,19 @@ public async Task Dcv_Skipped_WhenOrderStatusIdIsTerminal_EvenIfDcvValidated(str }); var validator = new FakeDomainValidator(); - // Issuance-wait budget > 0 so a wrong-path entry would manifest as a - // GetCertificate call we DON'T expect. + // Issuance-wait budget > 0 AND pickup ENABLED (pickupRetries > 0) so a wrong-path + // entry would manifest as a GetCertificate call we DON'T expect — this test must + // fail if either the DCV issuance-wait guard OR the synchronous-pickup gate + // (dcvIssuanceWaitRan) regresses and starts polling a cancelled/rejected order. var plugin = BuildPlugin(mock.Object, new FakeDomainValidatorFactory(validator), - DcvConfig(dcvWaitForIssuanceSeconds: 10)); + DcvConfig(dcvWaitForIssuanceSeconds: 10, pickupRetries: 5)); await Enroll(plugin); mock.Verify(c => c.GetCertificateAsync(It.IsAny(), It.IsAny()), Times.Never, - "Enroll must not enter WaitForIssuanceAfterDcvAsync when the order is " + - "cancelled/rejected, even if DCV happens to be in a 'validated' state"); + "Enroll must not enter WaitForIssuanceAfterDcvAsync OR the synchronous pickup poll " + + "when the order is cancelled/rejected, even if DCV happens to be in a 'validated' state"); validator.StagedRecords.Should().BeEmpty( "DCV staging must not run for a cancelled/rejected order"); } diff --git a/CERTInext.Tests/CERTInextCAPluginTests.cs b/CERTInext.Tests/CERTInextCAPluginTests.cs index 3ec5df1..7064b44 100644 --- a/CERTInext.Tests/CERTInextCAPluginTests.cs +++ b/CERTInext.Tests/CERTInextCAPluginTests.cs @@ -31,8 +31,20 @@ public class CERTInextCAPluginTests // Helpers // --------------------------------------------------------------------------- + // Pickup is disabled by default in the broad fixture (PickupRetries=0) — mirroring how + // DcvConfig defaults its wait budgets to 0 — so tests that don't care about the + // synchronous pickup don't pay its real Task.Delay-based poll. Tests that DO exercise + // pickup opt in via BuildPluginWithPickup. private static CERTInextCAPlugin BuildPlugin(ICERTInextClient client) => - new CERTInextCAPlugin(client); + new CERTInextCAPlugin(client, new CERTInextConfig { PickupRetries = 0 }); + + // Pickup-enabled fixture for the synchronous-pickup tests. PickupDelay is clamped to a + // 1s floor and the loop adds a fixed 5s initial delay, so these tests are intentionally + // a few seconds each. + private static CERTInextCAPlugin BuildPluginWithPickup( + ICERTInextClient client, int retries, int delaySeconds = 1) => + new CERTInextCAPlugin(client, + new CERTInextConfig { PickupRetries = retries, PickupDelayInSeconds = delaySeconds }); private static Mock NewMock() => new Mock(MockBehavior.Strict); @@ -345,6 +357,99 @@ public async Task Enroll_New_ReturnsPendingStatus_WhenCaReturnsPendingApproval() result.Status.Should().Be((int)EndEntityStatus.EXTERNALVALIDATION); } + // --------------------------------------------------------------------------- + // Synchronous certificate pickup (Sectigo parity) + // --------------------------------------------------------------------------- + + [Fact] + public async Task Pickup_Disabled_WhenPickupRetriesZero_ReturnsPendingWithoutPolling() + { + var mock = NewMock(); + mock.Setup(c => c.EnrollCertificateAsync( + It.IsAny(), It.IsAny())) + .ReturnsAsync(MockCertificateData.PendingEnrollResponse()); + + var plugin = BuildPluginWithPickup(mock.Object, retries: 0); + + var result = await plugin.Enroll( + csr: MockCertificateData.FakeCsrPem, subject: "CN=test.example.com", san: null, + productInfo: MakeProductInfo(), requestFormat: RequestFormat.PKCS10, + enrollmentType: EnrollmentType.New); + + result.Status.Should().Be((int)EndEntityStatus.EXTERNALVALIDATION); + mock.Verify(c => c.GetCertificateAsync(It.IsAny(), It.IsAny()), + Times.Never, "PickupRetries=0 must disable the synchronous pickup poll"); + } + + [Fact] + public async Task Pickup_ReturnsIssuedCert_WhenOrderIssuesDuringPoll() + { + var mock = NewMock(); + mock.Setup(c => c.EnrollCertificateAsync( + It.IsAny(), It.IsAny())) + .ReturnsAsync(MockCertificateData.PendingEnrollResponse()); + // The order finishes issuing by the time we poll: GetCertificate reports issued + PEM. + mock.Setup(c => c.GetCertificateAsync(It.IsAny(), It.IsAny())) + .ReturnsAsync(MockCertificateData.IssuedCertRecord()); + + var plugin = BuildPluginWithPickup(mock.Object, retries: 2); + + var result = await plugin.Enroll( + csr: MockCertificateData.FakeCsrPem, subject: "CN=test.example.com", san: null, + productInfo: MakeProductInfo(), requestFormat: RequestFormat.PKCS10, + enrollmentType: EnrollmentType.New); + + result.Status.Should().Be((int)EndEntityStatus.GENERATED); + result.Certificate.Should().NotBeNullOrEmpty("a synchronously-picked-up cert must carry its PEM"); + mock.Verify(c => c.GetCertificateAsync(It.IsAny(), It.IsAny()), + Times.AtLeastOnce); + } + + [Fact] + public async Task Pickup_SurfacesTerminalStatus_WhenOrderRevokedDuringPoll() + { + var mock = NewMock(); + mock.Setup(c => c.EnrollCertificateAsync( + It.IsAny(), It.IsAny())) + .ReturnsAsync(MockCertificateData.PendingEnrollResponse()); + mock.Setup(c => c.GetCertificateAsync(It.IsAny(), It.IsAny())) + .ReturnsAsync(MockCertificateData.RevokedCertRecord()); + + var plugin = BuildPluginWithPickup(mock.Object, retries: 3); + + var result = await plugin.Enroll( + csr: MockCertificateData.FakeCsrPem, subject: "CN=test.example.com", san: null, + productInfo: MakeProductInfo(), requestFormat: RequestFormat.PKCS10, + enrollmentType: EnrollmentType.New); + + result.Status.Should().Be((int)EndEntityStatus.REVOKED, + "a terminal status observed during pickup is surfaced immediately, not polled to exhaustion"); + } + + [Fact] + public async Task Pickup_ReturnsPending_WhenOrderNeverIssuesWithinBudget() + { + var mock = NewMock(); + mock.Setup(c => c.EnrollCertificateAsync( + It.IsAny(), It.IsAny())) + .ReturnsAsync(MockCertificateData.PendingEnrollResponse()); + // Every poll still reports pending — the budget is exhausted and Enroll returns the + // pending result for a later sync to complete. + mock.Setup(c => c.GetCertificateAsync(It.IsAny(), It.IsAny())) + .ReturnsAsync(MockCertificateData.PendingCertRecord()); + + var plugin = BuildPluginWithPickup(mock.Object, retries: 1); + + var result = await plugin.Enroll( + csr: MockCertificateData.FakeCsrPem, subject: "CN=test.example.com", san: null, + productInfo: MakeProductInfo(), requestFormat: RequestFormat.PKCS10, + enrollmentType: EnrollmentType.New); + + result.Status.Should().Be((int)EndEntityStatus.EXTERNALVALIDATION); + mock.Verify(c => c.GetCertificateAsync(It.IsAny(), It.IsAny()), + Times.AtLeastOnce, "an enabled pickup must actually poll before giving up"); + } + [Fact] public async Task Enroll_New_Throws_WhenProfileIdNotSet() { diff --git a/CERTInext/CERTInextCAPlugin.cs b/CERTInext/CERTInextCAPlugin.cs index 52fc364..b04c051 100644 --- a/CERTInext/CERTInextCAPlugin.cs +++ b/CERTInext/CERTInextCAPlugin.cs @@ -1105,12 +1105,38 @@ private async Task EnrollNewAsync( var enrollResp = await _client.EnrollCertificateAsync(enrollReq); + // Whether the DCV block below took ownership of the in-call issuance wait for this + // order. Declared outside the #if so both build flavors compile the pickup gate the + // same way (it simply stays false on the no-DCV build). When true, the synchronous + // pickup poll is skipped: on the DCV build the DCV path already owns the issuance + // decision — it either ran WaitForIssuanceAfterDcvAsync itself, deferred to another + // in-flight caller, or determined the order is terminal / not yet validated — so a + // second stacked poll would either double the wait or burn the budget polling an + // order that can never issue in-call (regression guard: a cancelled/rejected order + // must not be re-polled here after DCV already short-circuited it). + bool dcvIssuanceWaitRan = false; + #if SUPPORTS_DCV // DCV: run domain validation if enabled, the factory was injected, and the // order was accepted (not immediately failed). string orderNumber = enrollResp.Id; if (_domainValidatorFactory != null && _config.DcvEnabled && !string.IsNullOrEmpty(orderNumber)) { + // DCV owns the in-call issuance wait for this order from here on: every exit from + // this block (duplicate in-flight, DCV-validated + issuance poll, terminal order, + // or challenge-not-yet-exposed) is a decision the pickup poll must not second-guess. + // Set before any await so it holds on every path out of the block. + // + // This is intentionally coarse — keyed on "the DCV subsystem engaged for this order", + // not on "a DCV wait is actively running". The one case it over-defers is an order + // whose pending domains are all assigned to a non-DNS-01 method (HTTP/email): DCV does + // no work, yet pickup is skipped. That is an accepted trade: this plugin only drives + // DNS-01, so such orders depend on out-of-band validation and would not issue within + // the ~55s pickup window anyway — the next sync completes them. Distinguishing that + // sub-case from the terminal/cancelled case (which MUST skip pickup) would require a + // richer PerformDcvIfNeededAsync result and risk re-opening the terminal-order regression. + dcvIssuanceWaitRan = true; + // SOX CC7.3: bound the entire DCV flow with a hard timeout so a stuck // DNS provider or extreme propagation delay cannot hold a gateway worker // thread indefinitely. Configurable via DcvTimeoutMinutes (config or @@ -1175,7 +1201,7 @@ private async Task EnrollNewAsync( // already-issued/failed case and for OV/EV orders that CERTInext issues asynchronously // — those fall back to the pending result and are imported by the next sync. var newResult = BuildEnrollmentResult(enrollResp, ep.AutoApprove); - newResult = await PickUpEnrolledCertificateAsync(newResult, enrollResp.Id); + newResult = await PickUpEnrolledCertificateAsync(newResult, enrollResp.Id, dcvIssuanceWaitRan); _logger.MethodExit(LogLevel.Debug); return newResult; @@ -1305,7 +1331,8 @@ private async Task RenewOrReissueAsync( priorCaRequestId, renewResult.CARequestID, renewResult.Status); // Synchronous certificate pickup (Sectigo-parity), same as the new-enrollment path. - renewResult = await PickUpEnrolledCertificateAsync(renewResult, renewResp.Id); + // The renew path never runs an in-call DCV issuance wait, so pickup always applies. + renewResult = await PickUpEnrolledCertificateAsync(renewResult, renewResp.Id, dcvIssuanceWaitRan: false); return renewResult; } @@ -1894,15 +1921,31 @@ private async Task WaitForDcvVerificationAsync(string orderNumber, IReadOnlyList /// orders return in-call. Never throws — any polling error degrades to the pending result. /// private async Task PickUpEnrolledCertificateAsync( - EnrollmentResult pendingResult, string orderNumber) + EnrollmentResult pendingResult, string orderNumber, bool dcvIssuanceWaitRan) { + // The DCV path already owns the in-call issuance wait for this order — running a second + // stacked poll here would double the wait budget (when DCV ran WaitForIssuanceAfterDcvAsync) + // or waste it polling an order DCV already found terminal / not-yet-validated. Defer to + // the pending result; a later sync completes it. + if (dcvIssuanceWaitRan) + return pendingResult; + // Only a still-pending (external-validation) result can benefit from a pickup poll. - // An already issued/failed/revoked result, or a missing order number, is returned as-is. + // An already issued/failed/revoked result is returned as-is. if (pendingResult == null - || pendingResult.Status != (int)EndEntityStatus.EXTERNALVALIDATION - || string.IsNullOrWhiteSpace(orderNumber)) + || pendingResult.Status != (int)EndEntityStatus.EXTERNALVALIDATION) return pendingResult; + // A pending result with no order number cannot be polled — surface the anomaly rather + // than silently returning, so an un-pollable pending state leaves an audit trace. + if (string.IsNullOrWhiteSpace(orderNumber)) + { + _logger.LogWarning( + "Synchronous pickup skipped: a pending enrollment was returned with no order " + + "number to poll. The certificate can only be reconciled by a later synchronization."); + return pendingResult; + } + int retries = _config.GetEffectivePickupRetries(); if (retries <= 0) { @@ -1913,12 +1956,30 @@ private async Task PickUpEnrolledCertificateAsync( } int delaySeconds = _config.GetEffectivePickupDelaySeconds(); + + // Hard ceiling on total in-call occupancy. PickupRetries and PickupDelay are each clamped + // independently, but their product can still reach ~30 min at the extremes — enough to push + // Enroll() past Command's own enrollment timeout. If the configured budget would exceed the + // ceiling, cap the retry count to fit; the remainder is imported by the next synchronization. + int maxPollRetries = Math.Max(1, + (Constants.Pickup.MaxTotalWaitSeconds - Constants.Pickup.InitialDelaySeconds) / delaySeconds); + if (retries > maxPollRetries) + { + _logger.LogInformation( + "Configured pickup budget (PickupRetries={Configured}, PickupDelaySeconds={Delay}) exceeds the " + + "{MaxTotal}s in-call ceiling; capping to {Capped} attempts. The certificate will be imported by " + + "the next synchronization if it has not issued by then.", + retries, delaySeconds, Constants.Pickup.MaxTotalWaitSeconds, maxPollRetries); + retries = maxPollRetries; + } + _logger.LogInformation( "Starting synchronous certificate pickup. OrderNumber={OrderNumber}, PickupRetries={Retries}, " + "PickupDelaySeconds={Delay} (max ~{Max}s including a {Initial}s initial delay).", orderNumber, retries, delaySeconds, Constants.Pickup.InitialDelaySeconds + retries * delaySeconds, Constants.Pickup.InitialDelaySeconds); + int pollErrors = 0; try { // Small static delay before the first poll — mirrors the Sectigo connector's @@ -1932,6 +1993,14 @@ private async Task PickUpEnrolledCertificateAsync( var cert = await _client.GetCertificateAsync(orderNumber); int disposition = StatusMapper.ToRequestDisposition(cert.Status); + // SOC2 CC7.3: record each poll's observed disposition so the issuance + // timeline is reconstructable (how many polls ran, what each returned). + _logger.LogDebug( + "Pickup poll observed status. OrderNumber={OrderNumber}, Attempt={Attempt}/{Retries}, " + + "MappedDisposition={Disposition}, Status='{Status}', BodyPresent={HasBody}.", + orderNumber, attempt, retries, disposition, cert.Status, + !string.IsNullOrWhiteSpace(cert.Certificate)); + // Issued: only surface GENERATED when the PEM is actually present — never // hand Command a body-less "issued" record. A body-less issued state keeps // polling until the body appears or the budget runs out. @@ -1957,9 +2026,19 @@ private async Task PickUpEnrolledCertificateAsync( if (disposition == (int)EndEntityStatus.REVOKED || disposition == (int)EndEntityStatus.FAILED) { - _logger.LogInformation( - "Order {OrderNumber} reached terminal status '{Status}' during synchronous pickup.", - orderNumber, cert.Status); + // SOX/SOC2 CC7.2: an issuance FAILURE must cross the error threshold that + // SIEM issuance-failure rules key on (parity with BuildEnrollmentResult's + // enroll-time FAILED handling); a REVOKED terminal state is a warning. + if (disposition == (int)EndEntityStatus.FAILED) + _logger.LogError( + "Order {OrderNumber} reached terminal FAILED status '{Status}' during " + + "synchronous pickup (attempt {Attempt}/{Retries}).", + orderNumber, cert.Status, attempt, retries); + else + _logger.LogWarning( + "Order {OrderNumber} was REVOKED ('{Status}') during synchronous pickup " + + "(attempt {Attempt}/{Retries}).", + orderNumber, cert.Status, attempt, retries); return new EnrollmentResult { CARequestID = string.IsNullOrWhiteSpace(cert.Id) ? orderNumber : cert.Id, @@ -1973,6 +2052,7 @@ private async Task PickUpEnrolledCertificateAsync( { // A transient fetch failure consumes an attempt rather than aborting the // wait; if it never recovers the pending result is returned below. + pollErrors++; _logger.LogWarning(ex, "Pickup GetCertificate failed for order {OrderNumber} (attempt {Attempt}/{Retries}).", orderNumber, attempt, retries); @@ -1983,11 +2063,22 @@ private async Task PickUpEnrolledCertificateAsync( await Task.Delay(TimeSpan.FromSeconds(delaySeconds)); } - _logger.LogInformation( - "Synchronous pickup did not complete within {Retries} attempts for order {OrderNumber}. " + - "Returning pending result; the certificate will be imported by the next synchronization. " + - "CERTInext issues OV/EV asynchronously by design (support ticket #162763).", - retries, orderNumber); + // SOC1 accuracy: don't attribute non-completion to "OV/EV async by design" when the + // real cause was every poll erroring (e.g. a CA-side TrackOrder outage). Distinguish + // the two so the log reflects what actually happened. + if (pollErrors == retries) + _logger.LogWarning( + "Synchronous pickup exhausted {Retries} attempts for order {OrderNumber} — ALL polls " + + "errored (see preceding warnings). Returning pending result; the next synchronization " + + "will re-attempt retrieval.", + retries, orderNumber); + else + _logger.LogInformation( + "Synchronous pickup did not complete within {Retries} attempts for order {OrderNumber} " + + "({Errors} poll error(s); remainder still pending). Returning pending result; the " + + "certificate will be imported by the next synchronization. CERTInext issues OV/EV " + + "asynchronously by design (support ticket #162763).", + retries, orderNumber, pollErrors); pendingResult.StatusMessage = $"{pendingResult.StatusMessage} The certificate was not issued within the enrollment-pickup " + "window; it will be imported by a later synchronization."; diff --git a/CERTInext/CERTInextCAPluginConfig.cs b/CERTInext/CERTInextCAPluginConfig.cs index baf86c9..e77ac68 100644 --- a/CERTInext/CERTInextCAPluginConfig.cs +++ b/CERTInext/CERTInextCAPluginConfig.cs @@ -286,10 +286,12 @@ public static Dictionary GetCAConnectorAnnotations() }, [Constants.Config.PickupDelay] = new PropertyConfigInfo { - Comments = "OPTIONAL: Number of seconds between certificate-pickup retries. The total number of retries " + - "times this delay (plus a short initial delay) is the maximum time an enrollment call " + - "occupies a Command worker thread. If the duration is too long the request may time out, so " + - $"keep the total well under ~90s. Default: {Constants.Pickup.DefaultDelaySeconds} " + + Comments = "OPTIONAL: Number of seconds between certificate-pickup retries. PickupRetries times this " + + "delay (plus a short initial delay) is the maximum time an enrollment call occupies a Command " + + "worker thread. If the duration is too long the request may time out, so target a total well " + + $"under ~90s. As a safety backstop the plugin additionally caps the effective total at " + + $"{Constants.Pickup.MaxTotalWaitSeconds}s regardless of how PickupRetries/PickupDelay are set, " + + $"reducing the retry count to fit. Default: {Constants.Pickup.DefaultDelaySeconds} " + $"(with default retries this yields a ~{Constants.Pickup.InitialDelaySeconds + Constants.Pickup.DefaultRetries * Constants.Pickup.DefaultDelaySeconds}s ceiling).", Hidden = false, DefaultValue = Constants.Pickup.DefaultDelaySeconds, diff --git a/CERTInext/Client/CERTInextClient.cs b/CERTInext/Client/CERTInextClient.cs index 668c4a3..c6ad56b 100644 --- a/CERTInext/Client/CERTInextClient.cs +++ b/CERTInext/Client/CERTInextClient.cs @@ -365,9 +365,10 @@ public async Task SubmitCsrAsync(SubmitCsrRequest request, CancellationToken ct if (transientFailure) { Logger.LogWarning( - "SubmitCSR received no usable response (HttpStatus={Status}, LatencyMs={Latency}); not retrying " + - "(non-idempotent). If CERTInext already received the CSR, do not resubmit immediately.", - (int)resp.StatusCode, sw.ElapsedMilliseconds); + "SubmitCSR received no usable response (OrderNumber={OrderNumber}, HttpStatus={Status}, " + + "LatencyMs={Latency}); not retrying (non-idempotent). If CERTInext already received the CSR, " + + "do not resubmit immediately.", + request.OrderDetails?.OrderNumber, (int)resp.StatusCode, sw.ElapsedMilliseconds); // Parity with PlaceOrderAsync: carry the actionable guidance into the surfaced // exception, not only the log line. throw new Exception( diff --git a/CERTInext/Constants.cs b/CERTInext/Constants.cs index abf5188..4510286 100644 --- a/CERTInext/Constants.cs +++ b/CERTInext/Constants.cs @@ -292,10 +292,18 @@ public static class Pickup // issuing before we poll at all, avoiding a guaranteed-miss first attempt. public const int InitialDelaySeconds = 5; - // Safety clamps so a mis-configured connector cannot orphan a worker thread. Command - // abandons enrollment calls well before these bounds; they only backstop absurd input. + // Per-factor safety clamps so a single mis-typed value cannot produce a tight busy-loop + // or an absurd per-attempt delay. These bound each knob independently; the *product* + // (retries * delay) is bounded separately by MaxTotalWaitSeconds below. public const int MaxRetries = 30; public const int MaxDelaySeconds = 60; + + // Hard ceiling on total in-call pickup occupancy (initial delay + retries * delay). + // The per-factor clamps above still permit a ~1805s product at the extremes, which could + // push Enroll() past Command's enrollment timeout; PickUpEnrolledCertificateAsync caps the + // effective retry count so the total never exceeds this. Kept comfortably under a typical + // enrollment timeout while leaving room for the documented ~90s default guidance. + public const int MaxTotalWaitSeconds = 180; } public static class Dcv diff --git a/CHANGELOG.md b/CHANGELOG.md index e53dcd8..d971478 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,11 +1,10 @@ # 1.0.1 ## Features -- feat(enroll): `Enroll()` now polls for the issued certificate after submitting an order, so fast-issuing (DV / already-approved) orders return in the same call instead of waiting for the next sync. Tunable via `PickupRetries` (default 5, `0` disables) and `PickupDelay` (default 10s); ~55s default ceiling. Orders not issued within the window are returned pending and imported by a later sync, as before. -- chore(enroll): The enrollment-start log line now includes `RequestFormat` for diagnostics. +- **Faster enrollment for quickly-issued certificates.** Enrollment now waits briefly for the certificate and returns it in the same request when it issues fast (DV and already-approved orders), instead of always waiting for the next synchronization. Two new optional settings control the wait: `PickupRetries` (default 5; set to `0` to disable) and `PickupDelay` (default 10 seconds) — about a 55-second wait by default, with a built-in ceiling so it can't run long enough to time out the enrollment. Orders that don't issue in that window — including OV/EV, which CERTInext validates asynchronously over minutes to hours — return pending and are imported by a later sync, exactly as before. Works with or without DNS-based DCV. ## Bug Fixes -- fix(client): Order submission (`GenerateOrderSSL`) and CSR submission are no longer auto-retried on a network-level timeout. Because a timeout can occur after the CA has already created the order, re-sending the same transaction was being rejected as a duplicate (`EMS-947 "Duplicate requestTxn"`), failing the enrollment while orphaning the created order. Non-idempotent submissions now run once; if the CA created the order it is imported by the next synchronization. A duplicate-transaction response is also now reported with a clear, actionable message. (Idempotent read calls are unaffected and still retry.) +- **No more duplicate or orphaned orders after a network timeout.** Order and CSR submissions are no longer retried after a network timeout. A timeout can happen *after* the CA has already accepted the request, so the automatic retry was being rejected as a duplicate — failing the enrollment and leaving an orphaned order behind. These requests now run once; if the order was created it is imported by the next synchronization, and duplicate responses are reported with clear, actionable guidance. (Read-only calls are unaffected and still retry.) # 1.0.0