From af7f3a368ec158503b5899c0fe2b62fee0a3c45f Mon Sep 17 00:00:00 2001 From: Brian Hill Date: Fri, 16 Oct 2026 10:34:58 -0400 Subject: [PATCH 1/9] Resolve renew/reissue from order expiry for ~200 day certs Requests carrying a prior certificate are now resolved from the SSL Store order expiry instead of the certificate expiry: reissue under the active order outside RenewalWindowDays (default 30), renew inside it, and order new once the order has expired. Removes the expired-cert renewal rejection. Adds FlowLogger step diagrams to Enroll, Synchronize, Revoke, GetSingleRecord and Initialize, and tightens error handling on the enrollment path. --- CHANGELOG.md | 6 + SampleConfig.json | 1 + SslStoreCaProxy/Constants.cs | 2 + SslStoreCaProxy/FlowLogger.cs | 225 +++++++++++ SslStoreCaProxy/SslStoreCaProxy.cs | 534 ++++++++++++++++--------- SslStoreCaProxy/SslStoreCaProxy.csproj | 1 + readme_source.md | 2 + 7 files changed, 591 insertions(+), 180 deletions(-) create mode 100644 SslStoreCaProxy/FlowLogger.cs diff --git a/CHANGELOG.md b/CHANGELOG.md index e82d4d6..93c8718 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,9 @@ +v1.2.0 +- New/Renew/Reissue requests with a prior certificate are resolved from the SSL Store order expiry: reissued under the active order outside the renewal window (RenewalWindowDays, default 30), renewed inside it, ordered new once the order has expired. Supports shorter-lived (~200 day) certificates +- Removed the 'cannot renew an expired cert' failure; an expired order is now ordered as a new certificate +- Added FlowLogger step diagrams to the Trace log for Enroll, Synchronize, Revoke, GetSingleRecord and Initialize +- Hardening: clearer errors when the prior certificate or its order cannot be found, SSL Store calls surface the original exception, per-step failure reporting in the flow log + v1.1.1 - SSL Store Api Changed Encoding Rules, needed to fix integration to match diff --git a/SampleConfig.json b/SampleConfig.json index dcb3f97..ab47e41 100644 --- a/SampleConfig.json +++ b/SampleConfig.json @@ -27,6 +27,7 @@ "KeyfactorApiUserId": "SomeKeyfactorAPIUser", "KeyfactorApiPassword": "SomeKeyfactorAPIPassword", "PageSize": "25", + "RenewalWindowDays": "30", "SampleRequest": { "AuthRequest": { "PartnerCode": { diff --git a/SslStoreCaProxy/Constants.cs b/SslStoreCaProxy/Constants.cs index cddd657..1064022 100644 --- a/SslStoreCaProxy/Constants.cs +++ b/SslStoreCaProxy/Constants.cs @@ -6,9 +6,11 @@ internal class Constants public static string PartnerCode = "PartnerCode"; public static string AuthToken = "AuthToken"; public static string PageSize = "PageSize"; + public static string RenewalWindowDays = "RenewalWindowDays"; public static string KeyfactorApiUrl = "KeyfactorApiUrl"; public static string KeyfactorApiUserId = "KeyfactorApiUserId"; public static string KeyfactorApiPassword = "KeyfactorApiPassword"; public static int DefaultPageSize = 100; + public static int DefaultRenewalWindowDays = 30; } } \ No newline at end of file diff --git a/SslStoreCaProxy/FlowLogger.cs b/SslStoreCaProxy/FlowLogger.cs new file mode 100644 index 0000000..8572957 --- /dev/null +++ b/SslStoreCaProxy/FlowLogger.cs @@ -0,0 +1,225 @@ +using System; +using System.Collections.Generic; +using System.Diagnostics; +using System.Linq; +using System.Text; + +namespace Keyfactor.AnyGateway.SslStore +{ + public enum FlowStepStatus + { + Success, + Failed, + Skipped, + InProgress + } + + public class FlowStep + { + public string Name { get; set; } + public FlowStepStatus Status { get; set; } + public string Detail { get; set; } + public long ElapsedMs { get; set; } + public List Children { get; } = new List(); + } + + /// + /// Tracks the high-level flow of an operation and renders a step diagram to the Trace log when disposed. + /// Steps should only carry non-sensitive detail (IDs, counts, decisions), never CSRs, keys or contact data. + /// Usage: + /// using (var flow = new FlowLogger(m => Logger.Trace(m), "Enroll-New")) + /// { + /// flow.Step("ValidateInput"); + /// var result = flow.Step("SubmitRegistration", () => client.Submit(...)); + /// flow.Fail("CreateOrder", "API returned 400"); + /// } + /// + public sealed class FlowLogger : IDisposable + { + private readonly Action _log; + private readonly string _flowName; + private readonly Stopwatch _totalTimer; + private readonly List _steps = new List(); + private FlowStep _currentParent; + private bool _disposed; + + public FlowLogger(Action log, string flowName) + { + _log = log ?? (_ => { }); + _flowName = flowName; + _totalTimer = Stopwatch.StartNew(); + Write($"===== FLOW START: {_flowName} ====="); + } + + /// True if any recorded step failed. + public bool HasFailures => _steps.Any(s => s.Status == FlowStepStatus.Failed || + s.Children.Any(c => c.Status == FlowStepStatus.Failed)); + + /// Record a completed step. + public FlowLogger Step(string name, string detail = null) + { + AddStep(new FlowStep { Name = name, Status = FlowStepStatus.Success, Detail = detail }); + Write($" [{_flowName}] {name} ... OK{(detail != null ? $" ({detail})" : "")}"); + return this; + } + + /// Run an action as a timed step. Failures are recorded and rethrown. + public FlowLogger Step(string name, Action action, string detail = null) + { + Step(name, () => + { + action(); + return null; + }, detail); + return this; + } + + /// Run a function as a timed step and return its result. Failures are recorded and rethrown. + public T Step(string name, Func func, string detail = null) + { + var sw = Stopwatch.StartNew(); + var step = new FlowStep { Name = name, Detail = detail }; + try + { + Write($" [{_flowName}] {name} ..."); + var result = func(); + sw.Stop(); + step.Status = FlowStepStatus.Success; + step.ElapsedMs = sw.ElapsedMilliseconds; + AddStep(step); + Write($" [{_flowName}] {name} ... OK ({sw.ElapsedMilliseconds}ms){(detail != null ? $" {detail}" : "")}"); + return result; + } + catch (Exception ex) + { + sw.Stop(); + step.Status = FlowStepStatus.Failed; + step.ElapsedMs = sw.ElapsedMilliseconds; + step.Detail = ex.Message; + AddStep(step); + Write($" [{_flowName}] {name} ... FAILED ({sw.ElapsedMilliseconds}ms): {ex.Message}"); + throw; + } + } + + /// Record a failed step without throwing. + public FlowLogger Fail(string name, string reason = null) + { + AddStep(new FlowStep { Name = name, Status = FlowStepStatus.Failed, Detail = reason }); + Write($" [{_flowName}] {name} ... FAILED{(reason != null ? $": {reason}" : "")}"); + return this; + } + + /// Record a skipped step. + public FlowLogger Skip(string name, string reason = null) + { + AddStep(new FlowStep { Name = name, Status = FlowStepStatus.Skipped, Detail = reason }); + Write($" [{_flowName}] {name} ... SKIPPED{(reason != null ? $": {reason}" : "")}"); + return this; + } + + /// Start a branch (group of child steps). + public FlowLogger Branch(string name) + { + var step = new FlowStep { Name = name, Status = FlowStepStatus.InProgress }; + AddStep(step); + _currentParent = step; + Write($" [{_flowName}] >> Branch: {name}"); + return this; + } + + /// End the current branch. + public FlowLogger EndBranch() + { + if (_currentParent != null && _currentParent.Status == FlowStepStatus.InProgress) + _currentParent.Status = _currentParent.Children.Any(c => c.Status == FlowStepStatus.Failed) + ? FlowStepStatus.Failed + : FlowStepStatus.Success; + _currentParent = null; + return this; + } + + private void Write(string message) + { + try + { + _log(message); + } + catch + { + // Flow logging must never break the operation being logged. + } + } + + private void AddStep(FlowStep step) + { + if (_currentParent != null) + _currentParent.Children.Add(step); + else + _steps.Add(step); + } + + private string RenderFlow() + { + var sb = new StringBuilder(); + sb.AppendLine(); + sb.AppendLine($" ===== FLOW: {_flowName} ({_totalTimer.ElapsedMilliseconds}ms total) ====="); + sb.AppendLine(); + + for (var i = 0; i < _steps.Count; i++) + { + var step = _steps[i]; + sb.AppendLine($" {GetStatusIcon(step.Status)} {step.Name}{FormatTiming(step)}{FormatDetail(step)}"); + + foreach (var child in step.Children) + { + sb.AppendLine(" |"); + sb.AppendLine($" +-- {GetStatusIcon(child.Status)} {child.Name}{FormatTiming(child)}{FormatDetail(child)}"); + } + + if (i < _steps.Count - 1) + { + sb.AppendLine(" |"); + sb.AppendLine(" v"); + } + } + + sb.AppendLine(); + var finalStatus = _steps.Count > 0 && _steps.Last().Status == FlowStepStatus.Failed + ? "FAILED" + : HasFailures ? "PARTIAL FAILURE" : "SUCCESS"; + sb.AppendLine($" ===== FLOW RESULT: {finalStatus} ====="); + return sb.ToString(); + } + + private static string FormatTiming(FlowStep step) + { + return step.ElapsedMs > 0 ? $" ({step.ElapsedMs}ms)" : ""; + } + + private static string FormatDetail(FlowStep step) + { + return !string.IsNullOrEmpty(step.Detail) ? $" [{step.Detail}]" : ""; + } + + private static string GetStatusIcon(FlowStepStatus status) + { + switch (status) + { + case FlowStepStatus.Success: return "[OK]"; + case FlowStepStatus.Failed: return "[FAIL]"; + case FlowStepStatus.Skipped: return "[SKIP]"; + case FlowStepStatus.InProgress: return "[...]"; + default: return "[?]"; + } + } + + public void Dispose() + { + if (_disposed) return; + _disposed = true; + _totalTimer.Stop(); + Write(RenderFlow()); + } + } +} diff --git a/SslStoreCaProxy/SslStoreCaProxy.cs b/SslStoreCaProxy/SslStoreCaProxy.cs index 52e1520..6df86a7 100644 --- a/SslStoreCaProxy/SslStoreCaProxy.cs +++ b/SslStoreCaProxy/SslStoreCaProxy.cs @@ -1,6 +1,7 @@ using System; using System.Collections.Concurrent; using System.Collections.Generic; +using System.Globalization; using System.Security.Cryptography.X509Certificates; using System.Text; using System.Threading; @@ -22,6 +23,8 @@ namespace Keyfactor.AnyGateway.SslStore { public class SslStoreCaProxy : BaseCAConnector { + private const int FailedStatus = 30; + private readonly RequestManager _requestManager; public SslStoreCaProxy() @@ -35,8 +38,37 @@ public SslStoreCaProxy() public string PartnerCode { get; set; } public string AuthenticationToken { get; set; } public int PageSize { get; set; } + private int RenewalWindowDays { get; set; } = Constants.DefaultRenewalWindowDays; + + private FlowLogger NewFlow(string name) + { + return new FlowLogger(message => Logger.Trace(message), name); + } + + private static T RunSync(Func> operation) + { + //GetAwaiter().GetResult() surfaces the real exception instead of an AggregateException + return Task.Run(operation).GetAwaiter().GetResult(); + } + + private static EnrollmentResult Failure(string message) + { + return new EnrollmentResult + { + Status = FailedStatus, + StatusMessage = message + }; + } public override int Revoke(string caRequestId, string hexSerialNumber, uint revocationReason) + { + using (var flow = NewFlow("Revoke")) + { + return RevokeInternal(flow, caRequestId, hexSerialNumber, revocationReason); + } + } + + private int RevokeInternal(FlowLogger flow, string caRequestId, string hexSerialNumber, uint revocationReason) { Logger.MethodEntry(ILogExtensions.MethodLogLevel.Debug); Logger.Trace($"Entering Revoke Method: caRequestId={caRequestId ?? "(null)"}, hexSerialNumber={hexSerialNumber ?? "(null)"}, revocationReason={revocationReason}"); @@ -45,23 +77,26 @@ public override int Revoke(string caRequestId, string hexSerialNumber, uint revo if (string.IsNullOrEmpty(caRequestId)) { Logger.Error("Revoke called with null or empty caRequestId."); + flow.Fail("ValidateInput", "caRequestId is null or empty"); return Convert.ToInt32(PKIConstants.Microsoft.RequestDisposition.FAILED); } var caRequestIdParts = caRequestId.Split('-'); Logger.Trace($"Revoke caRequestId split into {caRequestIdParts.Length} parts, using first part: {caRequestIdParts[0]}"); + flow.Step("ValidateInput", $"order={caRequestIdParts[0]}, reason={revocationReason}"); var revokeOrderRequest = _requestManager.GetRevokeOrderRequest(caRequestIdParts[0]); Logger.Trace($"Revoke Request JSON {JsonConvert.SerializeObject(revokeOrderRequest)}"); - var requestResponse = - Task.Run(async () => await SslStoreClient.SubmitRevokeCertificateAsync(revokeOrderRequest)).Result; + var requestResponse = flow.Step("SubmitRevokeToSslStore", + () => RunSync(() => SslStoreClient.SubmitRevokeCertificateAsync(revokeOrderRequest))); Logger.Trace($"Revoke Response JSON {JsonConvert.SerializeObject(requestResponse)}"); if (requestResponse == null) { Logger.Error("Revoke response is null."); + flow.Fail("EvaluateResponse", "response is null"); Logger.MethodExit(ILogExtensions.MethodLogLevel.Debug); return Convert.ToInt32(PKIConstants.Microsoft.RequestDisposition.FAILED); } @@ -69,6 +104,7 @@ public override int Revoke(string caRequestId, string hexSerialNumber, uint revo if (requestResponse.AuthResponse == null) { Logger.Error("Revoke response AuthResponse is null."); + flow.Fail("EvaluateResponse", "AuthResponse is null"); Logger.MethodExit(ILogExtensions.MethodLogLevel.Debug); return Convert.ToInt32(PKIConstants.Microsoft.RequestDisposition.FAILED); } @@ -76,10 +112,12 @@ public override int Revoke(string caRequestId, string hexSerialNumber, uint revo if (requestResponse.AuthResponse.IsError) { Logger.Error($"Revoke Error Occurred: {JsonConvert.SerializeObject(requestResponse.AuthResponse)}"); + flow.Fail("EvaluateResponse", "SSL Store returned an error"); Logger.MethodExit(ILogExtensions.MethodLogLevel.Debug); return Convert.ToInt32(PKIConstants.Microsoft.RequestDisposition.FAILED); } + flow.Step("EvaluateResponse", "revoked"); Logger.Trace("Revoke completed successfully."); Logger.MethodExit(ILogExtensions.MethodLogLevel.Debug); @@ -87,6 +125,7 @@ public override int Revoke(string caRequestId, string hexSerialNumber, uint revo } catch (Exception e) { + flow.Fail("Revoke", e.Message); Logger.Error($"An Error has occurred during the revoke process: {e.Message}\n{e.StackTrace}"); if (e.InnerException != null) Logger.Error($"Inner exception: {e.InnerException.Message}\n{e.InnerException.StackTrace}"); @@ -109,226 +148,299 @@ public override EnrollmentResult Enroll(ICertificateDataReader certificateDataRe Logger.MethodEntry(ILogExtensions.MethodLogLevel.Debug); Logger.Trace($"Enroll called: enrollmentType={enrollmentType}, subject={subject ?? "(null)"}, ProductID={productInfo?.ProductID ?? "(null)"}"); - try + using (var flow = NewFlow($"Enroll-{enrollmentType}")) { - if (productInfo == null) + try { - Logger.Error("Enroll called with null productInfo."); - return new EnrollmentResult { Status = 30, StatusMessage = "Product info is null." }; + return EnrollInternal(flow, certificateDataReader, csr, productInfo, enrollmentType); } - - if (productInfo.ProductParameters == null) + catch (Exception ex) { - Logger.Error("Enroll called with null ProductParameters."); - return new EnrollmentResult { Status = 30, StatusMessage = "Product parameters are null." }; + flow.Fail("Enroll", ex.Message); + Logger.Error($"Enroll failed with exception: {ex.Message}\n{ex.StackTrace}"); + if (ex.InnerException != null) + Logger.Error($"Inner exception: {ex.InnerException.Message}\n{ex.InnerException.StackTrace}"); + return Failure($"Enrollment failed: {ex.Message}"); } - - Logger.Trace($"Enroll ProductParameters keys: {string.Join(", ", productInfo.ProductParameters.Keys)}"); - - INewOrderResponse enrollmentResponse = null; - NewOrderRequest enrollmentRequest; - ReIssueRequest reIssueRequest; - CAConnectorCertificate priorCert; - OrderStatusRequest orderStatusRequest; - INewOrderResponse orderStatusResponse; - - switch (enrollmentType) + finally { - case RequestUtilities.EnrollmentType.New: - Logger.Trace("Entering New Enrollment"); - //If they renewed an expired cert it gets here and this will not be supported - if (!productInfo.ProductParameters.ContainsKey("PriorCertSN")) - { - string[] arrayProducts = Array.Empty(); - string[] arrayApproverEmails = Array.Empty(); - - if (productInfo.ProductParameters.ContainsKey("DNS Names Comma Separated")) - { - Logger.Trace($"DNS Comma Separated {productInfo.ProductParameters["DNS Names Comma Separated"]}"); - arrayProducts = productInfo.ProductParameters["DNS Names Comma Separated"].Split(new char[] { ',' }); - } - if (productInfo.ProductParameters.ContainsKey("Approver Email")) - { - Logger.Trace($"Approver Email {productInfo.ProductParameters["Approver Email"]}"); - arrayApproverEmails = productInfo.ProductParameters["Approver Email"].Split(new char[] { ',' }); - } - - Logger.Trace($"New Enrollment: {arrayProducts.Length} DNS products, {arrayApproverEmails.Length} approver emails"); - - var count = 1; - foreach (var product in arrayProducts) - { - Logger.Trace($"Validating email approver for product domain '{product}' (#{count})..."); - var emailApproverRequest = _requestManager.GetEmailApproverListRequest(productInfo.ProductID, product); - Logger.Trace($"Email Approver Request JSON {JsonConvert.SerializeObject(emailApproverRequest)}"); - - var emailApproverResponse = Task.Run(async () => - await SslStoreClient.SubmitEmailApproverRequestAsync(emailApproverRequest)); - - Logger.Trace($"Email Approver Response JSON {JsonConvert.SerializeObject(emailApproverResponse)}"); - - var emailValidation = ValidateEmails(emailApproverResponse, arrayApproverEmails, productInfo, count); - - Logger.Trace($"Email Validation Result {emailValidation}"); - - if (emailValidation.Length > 0) - { - Logger.Warn($"Email validation failed: {emailValidation}"); - return new EnrollmentResult - { - Status = 30, //failure - StatusMessage = emailValidation - }; - } - count++; - } - + Logger.MethodExit(ILogExtensions.MethodLogLevel.Debug); + } + } + } - Logger.Trace("Building enrollment request..."); - enrollmentRequest = - _requestManager.GetEnrollmentRequest(csr, productInfo, ConfigManager, false); + private EnrollmentResult EnrollInternal(FlowLogger flow, ICertificateDataReader certificateDataReader, + string csr, EnrollmentProductInfo productInfo, RequestUtilities.EnrollmentType requestedType) + { + if (productInfo == null) + { + flow.Fail("ValidateInput", "productInfo is null"); + return Failure("Product info is null."); + } - Logger.Trace($"enrollmentRequest JSON {JsonConvert.SerializeObject(enrollmentRequest)}"); + if (productInfo.ProductParameters == null) + { + flow.Fail("ValidateInput", "ProductParameters is null"); + return Failure("Product parameters are null."); + } - Logger.Trace("Submitting new order request..."); - enrollmentResponse = - Task.Run(async () => await SslStoreClient.SubmitNewOrderRequestAsync(enrollmentRequest)) - .Result; + var hasPriorCert = productInfo.ProductParameters.TryGetValue("PriorCertSN", out var priorCertSn) && + !string.IsNullOrWhiteSpace(priorCertSn); + flow.Step("ValidateInput", $"product={productInfo.ProductID}, hasPriorCert={hasPriorCert}"); + Logger.Trace($"Enroll ProductParameters keys: {string.Join(", ", productInfo.ProductParameters.Keys)}"); - Logger.Trace($"enrollmentResponse JSON {JsonConvert.SerializeObject(enrollmentResponse)}"); - } - else - { - Logger.Warn("Enrollment rejected: PriorCertSN present in New enrollment (expired cert renewal not supported)."); - return new EnrollmentResult - { - Status = 30, //failure - StatusMessage = "You cannot renew and expired cert please perform an new enrollment." - }; - } + if (requestedType != RequestUtilities.EnrollmentType.New && + requestedType != RequestUtilities.EnrollmentType.Renew && + requestedType != RequestUtilities.EnrollmentType.Reissue) + { + flow.Fail("SelectPath", $"unsupported enrollment type {requestedType}"); + return Failure($"Unknown enrollment type: {requestedType}"); + } - break; - case RequestUtilities.EnrollmentType.Renew: - Logger.Trace("Entering Renew Enrollment"); + if (!hasPriorCert && requestedType != RequestUtilities.EnrollmentType.New) + { + flow.Fail("ValidateInput", $"{requestedType} requires PriorCertSN"); + return Failure($"PriorCertSN is required for {requestedType.ToString().ToLowerInvariant()}."); + } - if (!productInfo.ProductParameters.ContainsKey("PriorCertSN")) - { - Logger.Error("Renew enrollment missing required PriorCertSN parameter."); - return new EnrollmentResult { Status = 30, StatusMessage = "PriorCertSN is required for renewal." }; - } + // New, Renew and Reissue requests that carry a prior certificate are resolved from the prior certificate's + // order, not from what Command asked for, so shorter-lived (~200 day) certs under an active order are + // reissued instead of renewed (and an expired order is simply ordered again). + INewOrderResponse priorOrder = null; + var enrollmentType = requestedType; + if (hasPriorCert) + { + priorOrder = GetPriorOrder(flow, certificateDataReader, priorCertSn); + enrollmentType = ResolveEnrollmentType(flow, priorOrder, requestedType); + } + else + { + flow.Skip("EvaluateOrderValidity", "no PriorCertSN"); + } - Logger.Trace($"PriorCertSN={productInfo.ProductParameters["PriorCertSN"]}"); - priorCert = certificateDataReader.GetCertificateRecord( - DataConversion.HexToBytes(productInfo.ProductParameters["PriorCertSN"])); + flow.Step("EnrollmentDecision", $"requested={requestedType}, resolved={enrollmentType}"); - if (priorCert == null) - { - Logger.Error($"Prior certificate not found for PriorCertSN={productInfo.ProductParameters["PriorCertSN"]}"); - return new EnrollmentResult { Status = 30, StatusMessage = "Prior certificate record not found." }; - } + INewOrderResponse enrollmentResponse; + switch (enrollmentType) + { + case RequestUtilities.EnrollmentType.New: + if (hasPriorCert) + flow.Step("PriorCertNotReused", "ordering as a new certificate"); + var newOrderFailure = SubmitNewOrder(flow, csr, productInfo, out enrollmentResponse); + if (newOrderFailure != null) return newOrderFailure; + break; + case RequestUtilities.EnrollmentType.Renew: + var renewRequest = flow.Step("BuildRenewalRequest", + () => _requestManager.GetRenewalRequest(priorOrder, csr)); + Logger.Trace($"renewRequest JSON {JsonConvert.SerializeObject(renewRequest)}"); + enrollmentResponse = flow.Step("SubmitRenewalToSslStore", + () => RunSync(() => SslStoreClient.SubmitRenewRequestAsync(renewRequest))); + break; + default: + var reIssueRequest = flow.Step("BuildReissueRequest", + () => _requestManager.GetReIssueRequest(priorOrder, csr, false)); + Logger.Trace($"reIssueRequest JSON {JsonConvert.SerializeObject(reIssueRequest)}"); + enrollmentResponse = flow.Step("SubmitReissueToSslStore", + () => RunSync(() => SslStoreClient.SubmitReIssueRequestAsync(reIssueRequest))); + break; + } - Logger.Trace($"Prior Cert CARequestID={priorCert.CARequestID ?? "(null)"}"); + Logger.Trace($"enrollmentResponse JSON {JsonConvert.SerializeObject(enrollmentResponse)}"); - if (string.IsNullOrEmpty(priorCert.CARequestID)) - { - Logger.Error("Prior certificate has null/empty CARequestID."); - return new EnrollmentResult { Status = 30, StatusMessage = "Prior certificate has no CA Request ID." }; - } + var result = GetEnrollmentResult(enrollmentResponse); + if (result.Status == FailedStatus) + flow.Fail("MapEnrollmentResult", $"SSL Store rejected the request: {result.StatusMessage}"); + else + flow.Step("MapEnrollmentResult", $"status={result.Status}"); + return result; + } - orderStatusRequest = _requestManager.GetOrderStatusRequest(priorCert.CARequestID.Split('-')[0]); + /// + /// Validates approver emails and submits a brand new order. Returns a failure result, or null on success. + /// + private EnrollmentResult SubmitNewOrder(FlowLogger flow, string csr, EnrollmentProductInfo productInfo, + out INewOrderResponse enrollmentResponse) + { + enrollmentResponse = null; + var arrayProducts = Array.Empty(); + var arrayApproverEmails = Array.Empty(); - Logger.Trace($"orderStatusRequest JSON {JsonConvert.SerializeObject(orderStatusRequest)}"); + if (productInfo.ProductParameters.ContainsKey("DNS Names Comma Separated")) + { + Logger.Trace($"DNS Comma Separated {productInfo.ProductParameters["DNS Names Comma Separated"]}"); + arrayProducts = productInfo.ProductParameters["DNS Names Comma Separated"].Split(','); + } - orderStatusResponse = Task.Run(async () => - await SslStoreClient.SubmitOrderStatusRequestAsync(orderStatusRequest)).Result; + if (productInfo.ProductParameters.ContainsKey("Approver Email")) + { + Logger.Trace($"Approver Email {productInfo.ProductParameters["Approver Email"]}"); + arrayApproverEmails = productInfo.ProductParameters["Approver Email"].Split(','); + } - if (orderStatusResponse == null) - { - Logger.Error("Order status response is null during renewal."); - return new EnrollmentResult { Status = 30, StatusMessage = "Failed to retrieve order status for renewal." }; - } + Logger.Trace($"New Enrollment: {arrayProducts.Length} DNS products, {arrayApproverEmails.Length} approver emails"); - Logger.Trace($"orderStatusResponse JSON {JsonConvert.SerializeObject(orderStatusResponse)}"); + var count = 1; + foreach (var product in arrayProducts) + { + Logger.Trace($"Validating email approver for product domain '{product}' (#{count})..."); + var emailApproverRequest = _requestManager.GetEmailApproverListRequest(productInfo.ProductID, product); + Logger.Trace($"Email Approver Request JSON {JsonConvert.SerializeObject(emailApproverRequest)}"); - var renewRequest = _requestManager.GetRenewalRequest(orderStatusResponse, csr); + var emailApproverResponse = Task.Run(async () => + await SslStoreClient.SubmitEmailApproverRequestAsync(emailApproverRequest)); - Logger.Trace($"renewRequest JSON {JsonConvert.SerializeObject(renewRequest)}"); + var emailValidation = ValidateEmails(emailApproverResponse, arrayApproverEmails, productInfo, count); + Logger.Trace($"Email Validation Result {emailValidation}"); - Logger.Trace("Submitting renewal request..."); - enrollmentResponse = - Task.Run(async () => await SslStoreClient.SubmitRenewRequestAsync(renewRequest)).Result; + if (emailValidation.Length > 0) + { + Logger.Warn($"Email validation failed: {emailValidation}"); + flow.Fail("ValidateApproverEmails", emailValidation); + return Failure(emailValidation); + } - Logger.Trace($"enrollmentResponse JSON {JsonConvert.SerializeObject(enrollmentResponse)}"); + count++; + } - break; - case RequestUtilities.EnrollmentType.Reissue: - Logger.Trace("Entering Reissue Enrollment"); + flow.Step("ValidateApproverEmails", $"{arrayProducts.Length} domain(s)"); - if (!productInfo.ProductParameters.ContainsKey("PriorCertSN")) - { - Logger.Error("Reissue enrollment missing required PriorCertSN parameter."); - return new EnrollmentResult { Status = 30, StatusMessage = "PriorCertSN is required for reissue." }; - } + var enrollmentRequest = flow.Step("BuildNewOrderRequest", + () => _requestManager.GetEnrollmentRequest(csr, productInfo, ConfigManager, false)); + Logger.Trace($"enrollmentRequest JSON {JsonConvert.SerializeObject(enrollmentRequest)}"); - Logger.Trace($"PriorCertSN={productInfo.ProductParameters["PriorCertSN"]}"); - priorCert = - certificateDataReader.GetCertificateRecord( - DataConversion.HexToBytes(productInfo.ProductParameters["PriorCertSN"])); + enrollmentResponse = flow.Step("SubmitNewOrderToSslStore", + () => RunSync(() => SslStoreClient.SubmitNewOrderRequestAsync(enrollmentRequest))); + return null; + } - if (priorCert == null) - { - Logger.Error($"Prior certificate not found for PriorCertSN={productInfo.ProductParameters["PriorCertSN"]}"); - return new EnrollmentResult { Status = 30, StatusMessage = "Prior certificate record not found." }; - } + /// + /// Finds the prior certificate in the gateway database and returns the current status of its SSL Store order. + /// + private INewOrderResponse GetPriorOrder(FlowLogger flow, ICertificateDataReader certificateDataReader, + string priorCertSn) + { + Logger.Trace($"PriorCertSN={priorCertSn}"); + var priorCert = certificateDataReader.GetCertificateRecord(DataConversion.HexToBytes(priorCertSn)); + if (priorCert == null) + { + Logger.Error($"Prior certificate not found for PriorCertSN={priorCertSn}"); + throw new InvalidOperationException($"Prior certificate record not found for serial number '{priorCertSn}'."); + } - Logger.Trace($"Prior Cert CARequestID={priorCert.CARequestID ?? "(null)"}"); + Logger.Trace($"Prior Cert CARequestID={priorCert.CARequestID ?? "(null)"}"); + if (string.IsNullOrEmpty(priorCert.CARequestID)) + { + Logger.Error("Prior certificate has null/empty CARequestID."); + throw new InvalidOperationException("Prior certificate has no CA Request ID."); + } - if (string.IsNullOrEmpty(priorCert.CARequestID)) - { - Logger.Error("Prior certificate has null/empty CARequestID."); - return new EnrollmentResult { Status = 30, StatusMessage = "Prior certificate has no CA Request ID." }; - } + //CARequestID is {SSL Store order id}-{serial number}, several certificates can share an order + var orderId = priorCert.CARequestID.Split('-')[0]; + flow.Step("ResolvePriorCertificate", $"order={orderId}"); - orderStatusRequest = _requestManager.GetOrderStatusRequest(priorCert.CARequestID.Split('-')[0]); + var orderStatusRequest = _requestManager.GetOrderStatusRequest(orderId); + Logger.Trace($"orderStatusRequest JSON {JsonConvert.SerializeObject(orderStatusRequest)}"); - Logger.Trace($"orderStatusRequest JSON {JsonConvert.SerializeObject(orderStatusRequest)}"); + var orderStatusResponse = flow.Step("FetchPriorOrderStatus", + () => RunSync(() => SslStoreClient.SubmitOrderStatusRequestAsync(orderStatusRequest)), $"order={orderId}"); + if (orderStatusResponse == null) + { + Logger.Error("Order status response is null for the prior order."); + throw new InvalidOperationException($"Failed to retrieve the status of prior order {orderId}."); + } - orderStatusResponse = Task.Run(async () => - await SslStoreClient.SubmitOrderStatusRequestAsync(orderStatusRequest)).Result; + Logger.Trace($"orderStatusResponse JSON {JsonConvert.SerializeObject(orderStatusResponse)}"); + return orderStatusResponse; + } - if (orderStatusResponse == null) - { - Logger.Error("Order status response is null during reissue."); - return new EnrollmentResult { Status = 30, StatusMessage = "Failed to retrieve order status for reissue." }; - } + /// + /// Resolves New / Renew / Reissue from the prior certificate's order expiry rather than the certificate's own + /// expiration, so shorter-lived certificates under an active order are reissued, not renewed. + /// explicit Reissue -> Reissue + /// order beyond the renewal window -> Reissue (under the active order) + /// order inside the window, not yet expired -> Renew + /// order expired -> New + /// Falls back to the certificate's expiration when the order expiry is unavailable. If nothing can be + /// evaluated the requested type is kept. + /// + private RequestUtilities.EnrollmentType ResolveEnrollmentType(FlowLogger flow, INewOrderResponse priorOrder, + RequestUtilities.EnrollmentType requested) + { + if (requested == RequestUtilities.EnrollmentType.Reissue) + { + flow.Skip("EvaluateOrderValidity", "explicit Reissue request"); + return requested; + } - Logger.Trace($"orderStatusResponse JSON {JsonConvert.SerializeObject(orderStatusResponse)}"); + try + { + if (TryGetOrderExpiry(priorOrder, out var orderExpiry, out var source)) + { + var daysLeft = (orderExpiry - DateTime.UtcNow).TotalDays; + var resolved = daysLeft > RenewalWindowDays ? RequestUtilities.EnrollmentType.Reissue + : daysLeft >= 0 ? RequestUtilities.EnrollmentType.Renew + : RequestUtilities.EnrollmentType.New; + flow.Step("EvaluateOrderValidity", + $"orderExpiry={orderExpiry:dd-MMM-yyyy} ({source}), daysLeft={(int) daysLeft}, window={RenewalWindowDays}, result={resolved}"); + return resolved; + } - reIssueRequest = _requestManager.GetReIssueRequest(orderStatusResponse, csr, false); + if (TryParseSslStoreDate(priorOrder.CertificateEndDateInUtc, priorOrder.CertificateEndDate, + out var certExpiry)) + { + var resolved = certExpiry >= DateTime.UtcNow ? RequestUtilities.EnrollmentType.Reissue : requested; + flow.Step("EvaluateOrderValidity", + $"order expiry unavailable, using certificate expiration {certExpiry:dd-MMM-yyyy}, result={resolved}"); + return resolved; + } - Logger.Trace($"reIssueRequest JSON {JsonConvert.SerializeObject(reIssueRequest)}"); + flow.Skip("EvaluateOrderValidity", "neither order expiry nor certificate expiration available"); + return requested; + } + catch (Exception e) + { + flow.Fail("EvaluateOrderValidity", e.Message); + Logger.Warn($"Unable to evaluate the prior order, keeping requested type {requested}: {e.Message}"); + return requested; + } + } - Logger.Trace("Submitting reissue request..."); - enrollmentResponse = - Task.Run(async () => await SslStoreClient.SubmitReIssueRequestAsync(reIssueRequest)).Result; + private static bool TryGetOrderExpiry(INewOrderResponse order, out DateTime expiryUtc, out string source) + { + if (TryParseSslStoreDate(order.OrderExpiryDateInUtc, order.OrderExpiryDate, out expiryUtc)) + { + source = "OrderExpiryDate"; + return true; + } - Logger.Trace($"enrollmentResponse JSON {JsonConvert.SerializeObject(enrollmentResponse)}"); + //No order expiry returned, the order runs for its validity (in months) from the purchase date + if (order.Validity > 0 && TryParseSslStoreDate(order.PurchaseDateInUtc, order.PurchaseDate, out var purchased)) + { + expiryUtc = purchased.AddMonths(order.Validity); + source = $"PurchaseDate+{order.Validity}mo"; + return true; + } - break; - default: - Logger.Error($"Unknown enrollment type: {enrollmentType}"); - return new EnrollmentResult { Status = 30, StatusMessage = $"Unknown enrollment type: {enrollmentType}" }; - } + source = null; + return false; + } - return GetEnrollmentResult(enrollmentResponse); - } - catch (Exception ex) + /// + /// Parses a date as UTC, preferring the explicit UTC value. Culture-safe: tries invariant first. + /// + private static bool TryParseSslStoreDate(string utcValue, string localValue, out DateTime utc) + { + foreach (var value in new[] {utcValue, localValue}) { - Logger.Error($"Enroll failed with exception: {ex.Message}\n{ex.StackTrace}"); - if (ex.InnerException != null) - Logger.Error($"Inner exception: {ex.InnerException.Message}\n{ex.InnerException.StackTrace}"); - return new EnrollmentResult { Status = 30, StatusMessage = $"Enrollment failed: {ex.Message}" }; + if (string.IsNullOrWhiteSpace(value)) continue; + const DateTimeStyles styles = DateTimeStyles.AssumeUniversal | DateTimeStyles.AdjustToUniversal; + if (DateTime.TryParse(value, CultureInfo.InvariantCulture, styles, out utc) || + DateTime.TryParse(value, CultureInfo.CurrentCulture, styles, out utc)) + return true; } + + utc = default(DateTime); + return false; } private EnrollmentResult GetEnrollmentResult(INewOrderResponse newOrderResponse) @@ -375,6 +487,14 @@ private EnrollmentResult GetEnrollmentResult(INewOrderResponse newOrderResponse) public override CAConnectorCertificate GetSingleRecord(string caRequestId) + { + using (var flow = NewFlow("GetSingleRecord")) + { + return GetSingleRecordInternal(flow, caRequestId); + } + } + + private CAConnectorCertificate GetSingleRecordInternal(FlowLogger flow, string caRequestId) { Logger.MethodEntry(ILogExtensions.MethodLogLevel.Debug); Logger.Trace($"GetSingleRecord called: caRequestId={caRequestId ?? "(null)"}"); @@ -384,6 +504,7 @@ public override CAConnectorCertificate GetSingleRecord(string caRequestId) if (string.IsNullOrEmpty(caRequestId)) { Logger.Error("GetSingleRecord called with null/empty caRequestId."); + flow.Fail("ValidateInput", "caRequestId is null or empty"); Logger.MethodExit(ILogExtensions.MethodLogLevel.Debug); return new CAConnectorCertificate { @@ -394,17 +515,19 @@ public override CAConnectorCertificate GetSingleRecord(string caRequestId) }; } + flow.Step("ValidateInput", $"caRequestId={caRequestId}"); var orderStatusRequest = _requestManager.GetOrderStatusRequest(caRequestId); Logger.Trace($"orderStatusRequest JSON {JsonConvert.SerializeObject(orderStatusRequest)}"); - var certResponse = Task - .Run(async () => await SslStoreClient.SubmitOrderStatusRequestAsync(orderStatusRequest)).Result; + var certResponse = flow.Step("FetchOrderStatus", + () => RunSync(() => SslStoreClient.SubmitOrderStatusRequestAsync(orderStatusRequest))); Logger.Trace($"certResponse JSON {JsonConvert.SerializeObject(certResponse)}"); var majorStatus = certResponse?.OrderStatus?.MajorStatus; Logger.Trace($"GetSingleRecord: MajorStatus={majorStatus ?? "(null)"}"); + flow.Step("MapStatus", $"majorStatus={majorStatus ?? "(null)"}"); Logger.MethodExit(ILogExtensions.MethodLogLevel.Debug); return new CAConnectorCertificate @@ -417,6 +540,7 @@ public override CAConnectorCertificate GetSingleRecord(string caRequestId) } catch (Exception ex) { + flow.Fail("GetSingleRecord", ex.Message); Logger.Error($"GetSingleRecord failed for caRequestId={caRequestId}: {ex.Message}\n{ex.StackTrace}"); if (ex.InnerException != null) Logger.Error($"Inner exception: {ex.InnerException.Message}\n{ex.InnerException.StackTrace}"); @@ -442,6 +566,16 @@ public override void Synchronize(ICertificateDataReader certificateDataReader, public override void Synchronize(ICertificateDataReader certificateDataReader, BlockingCollection blockingBuffer, CertificateAuthoritySyncInfo certificateAuthoritySyncInfo, CancellationToken cancelToken) + { + using (var flow = NewFlow("Synchronize")) + { + SynchronizeInternal(flow, certificateDataReader, blockingBuffer, certificateAuthoritySyncInfo, cancelToken); + } + } + + private void SynchronizeInternal(FlowLogger flow, ICertificateDataReader certificateDataReader, + BlockingCollection blockingBuffer, + CertificateAuthoritySyncInfo certificateAuthoritySyncInfo, CancellationToken cancelToken) { Logger.MethodEntry(ILogExtensions.MethodLogLevel.Debug); Logger.Trace("Synchronize starting..."); @@ -453,6 +587,7 @@ public override void Synchronize(ICertificateDataReader certificateDataReader, var templates=new BlockingCollection(100); KeyfactorClient.SubmitQueryTemplatesRequestAsync(templates, cancelToken, _requestManager); Logger.Trace("Template query submitted."); + flow.Step("QueryTemplates", "template query submitted"); //Get a list of orgs from digicert via SslStore API Logger.Trace("Getting organization list request..."); @@ -469,6 +604,11 @@ public override void Synchronize(ICertificateDataReader certificateDataReader, if (orgListResponse == null) { Logger.Warn("Organization list response is null. Skipping template organization updates."); + flow.Fail("FetchOrganizations", "response is null, template organization updates skipped"); + } + else + { + flow.Step("FetchOrganizations", $"count={orgListResponse.OrganizationList?.Count ?? 0}"); } Logger.Trace("Beginning template enumeration..."); @@ -563,6 +703,7 @@ public override void Synchronize(ICertificateDataReader certificateDataReader, } Logger.Trace("Template processing complete. Beginning certificate sync..."); + flow.Step("ProcessTemplates"); var certs = new BlockingCollection(100); SslStoreClient.SubmitQueryOrderRequestAsync(certs, cancelToken, _requestManager); Logger.Trace("Certificate query submitted."); @@ -722,10 +863,14 @@ await SslStoreClient.SubmitDownloadCertificateAsync( } Logger.Trace($"Synchronize certificate processing complete. Total processed={certCount}, Added to buffer={addedCount}, Errors={errorCount}"); + var syncSummary = $"processed={certCount}, added={addedCount}, errors={errorCount}"; + if (errorCount > 0) flow.Fail("SyncCertificates", syncSummary); + else flow.Step("SyncCertificates", syncSummary); } catch (AggregateException aggEx) { var flatEx = aggEx.Flatten(); + flow.Fail("Synchronize", flatEx.Message); Logger.Error($"SslStore Synchronize Task failed! {flatEx.Message}"); foreach (var innerEx in flatEx.InnerExceptions) { @@ -736,6 +881,7 @@ await SslStoreClient.SubmitDownloadCertificateAsync( } catch (Exception ex) { + flow.Fail("Synchronize", ex.Message); Logger.Error($"SslStore Synchronize unexpected error: {ex.Message}\n{ex.StackTrace}"); if (ex.InnerException != null) Logger.Error($"Inner exception: {ex.InnerException.Message}\n{ex.InnerException.StackTrace}"); @@ -748,6 +894,14 @@ await SslStoreClient.SubmitDownloadCertificateAsync( public override void Initialize(ICAConnectorConfigProvider configProvider) + { + using (var flow = NewFlow("Initialize")) + { + InitializeInternal(flow, configProvider); + } + } + + private void InitializeInternal(FlowLogger flow, ICAConnectorConfigProvider configProvider) { Logger.MethodEntry(ILogExtensions.MethodLogLevel.Debug); Logger.Trace("Initialize called."); @@ -780,6 +934,7 @@ public override void Initialize(ICAConnectorConfigProvider configProvider) throw new InvalidOperationException($"Missing required config key '{Constants.AuthToken}'."); } + flow.Step("ValidateConfig", "required keys present"); PartnerCode = configProvider.CAConnectionData[Constants.PartnerCode]?.ToString(); Logger.Trace($"Initialize: PartnerCode={PartnerCode ?? "(null)"}"); @@ -796,12 +951,31 @@ public override void Initialize(ICAConnectorConfigProvider configProvider) PageSize = _requestManager.GetClientPageSize(configProvider); Logger.Trace($"Initialize: PageSize={PageSize}"); + flow.Step("CreateClients", $"pageSize={PageSize}"); + + RenewalWindowDays = Constants.DefaultRenewalWindowDays; + if (configProvider.CAConnectionData.TryGetValue(Constants.RenewalWindowDays, out var renewalWindow)) + { + if (int.TryParse(renewalWindow?.ToString(), out var renewalWindowDays) && renewalWindowDays > 0) + { + RenewalWindowDays = renewalWindowDays; + } + else + { + Logger.Warn($"{Constants.RenewalWindowDays} value '{renewalWindow}' could not be parsed or was <= 0, using default {Constants.DefaultRenewalWindowDays}."); + flow.Fail("ReadRenewalWindowDays", $"invalid value, using default {Constants.DefaultRenewalWindowDays}"); + } + } + + flow.Step("ReadRenewalWindowDays", $"days={RenewalWindowDays}"); + ConfigManager = configProvider; Logger.Trace("Initialize complete."); } catch (Exception ex) { + flow.Fail("Initialize", ex.Message); Logger.Error($"Initialize failed: {ex.Message}\n{ex.StackTrace}"); throw; } diff --git a/SslStoreCaProxy/SslStoreCaProxy.csproj b/SslStoreCaProxy/SslStoreCaProxy.csproj index bb919cd..e8cce0b 100644 --- a/SslStoreCaProxy/SslStoreCaProxy.csproj +++ b/SslStoreCaProxy/SslStoreCaProxy.csproj @@ -147,6 +147,7 @@ + diff --git a/readme_source.md b/readme_source.md index d30820f..2dfb211 100644 --- a/readme_source.md +++ b/readme_source.md @@ -137,6 +137,7 @@ the CA. Without the imported configuration, the service will fail to start. "ADMINISTRATOR": "Allow" } ``` +- *Renewal window* (optional `RenewalWindowDays` in `CAConnection`, default 30): when a renewal or reissue is requested for an existing certificate, the gateway looks at the expiry of the SSL Store **order**, not the certificate. More than `RenewalWindowDays` left on the order -> reissue under the active order; inside the window -> renewal; order expired -> new order (which needs the full enrollment fields). This keeps certificates that are shorter than the order term (for example 200 day certs) from being renewed (and charged) every time. - *SSLStore Environment Settings* (Modify these with the keys and Urls obtained from SSLStore) ``` "CAConnection": { @@ -147,6 +148,7 @@ the CA. Without the imported configuration, the service will fail to start. "KeyfactorApiUserId": "SomeKeyfactorAPIUser", "KeyfactorApiPassword": "SomeKeyfactorAPIPassword", "PageSize": "25", + "RenewalWindowDays": "30", "SampleRequest": { "AuthRequest": { "PartnerCode": { From 3958edbc68399649c44b78e43f5f31d50d3ec208 Mon Sep 17 00:00:00 2001 From: Brian Hill Date: Fri, 16 Oct 2026 13:34:34 -0400 Subject: [PATCH 2/9] Redact credentials and tokens from Trace logging Request and response bodies are logged through LogRedactor, which masks AuthToken, PartnerCode, Token, TokenCode, TokenID and password values. The PartnerCode is no longer logged at Initialize. --- CHANGELOG.md | 1 + SslStoreCaProxy/Client/KeyfactorClient.cs | 4 +-- SslStoreCaProxy/Client/SslStoreClient.cs | 34 ++++++++++----------- SslStoreCaProxy/LogRedactor.cs | 30 +++++++++++++++++++ SslStoreCaProxy/SslStoreCaProxy.cs | 36 +++++++++++------------ SslStoreCaProxy/SslStoreCaProxy.csproj | 1 + 6 files changed, 69 insertions(+), 37 deletions(-) create mode 100644 SslStoreCaProxy/LogRedactor.cs diff --git a/CHANGELOG.md b/CHANGELOG.md index 93c8718..f1bc361 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,6 +1,7 @@ v1.2.0 - New/Renew/Reissue requests with a prior certificate are resolved from the SSL Store order expiry: reissued under the active order outside the renewal window (RenewalWindowDays, default 30), renewed inside it, ordered new once the order has expired. Supports shorter-lived (~200 day) certificates - Removed the 'cannot renew an expired cert' failure; an expired order is now ordered as a new certificate +- Credentials and tokens (AuthToken, PartnerCode, Token, TokenCode, TokenID, passwords) are now masked in all Trace log output - Added FlowLogger step diagrams to the Trace log for Enroll, Synchronize, Revoke, GetSingleRecord and Initialize - Hardening: clearer errors when the prior certificate or its order cannot be found, SSL Store calls surface the original exception, per-step failure reporting in the flow log diff --git a/SslStoreCaProxy/Client/KeyfactorClient.cs b/SslStoreCaProxy/Client/KeyfactorClient.cs index 5528388..561cc34 100644 --- a/SslStoreCaProxy/Client/KeyfactorClient.cs +++ b/SslStoreCaProxy/Client/KeyfactorClient.cs @@ -84,12 +84,12 @@ public async Task