From e485a499b70eeaedbdac6b21068c43b1fa2fd754 Mon Sep 17 00:00:00 2001 From: Cristian Magherusan-Stanciu Date: Fri, 22 May 2026 18:46:55 +0200 Subject: [PATCH 01/13] feat(providers/aws): add purchasecfg helper to bound purchase-path SDK retries Introduce providers/aws/internal/purchasecfg.NewConfig which returns a copy of the caller's aws.Config with RetryMaxAttempts=2 and http.Client.Timeout=15s. Worst-case wall clock: 2 * 15s = 30s, well inside the 300s Lambda budget. Recommendation-collection clients (recommendations.NewClient) are explicitly NOT touched; they call Cost Explorer and need the higher default retry budget. Adds five unit tests covering: retry cap, HTTP timeout, immutability of the base config, region preservation, and the wall-clock bound invariant. Closes #683. Refs #667 #668 #632 #681. --- providers/aws/internal/purchasecfg/config.go | 46 ++++++++++++ .../aws/internal/purchasecfg/config_test.go | 75 +++++++++++++++++++ 2 files changed, 121 insertions(+) create mode 100644 providers/aws/internal/purchasecfg/config.go create mode 100644 providers/aws/internal/purchasecfg/config_test.go diff --git a/providers/aws/internal/purchasecfg/config.go b/providers/aws/internal/purchasecfg/config.go new file mode 100644 index 000000000..5aa2ee850 --- /dev/null +++ b/providers/aws/internal/purchasecfg/config.go @@ -0,0 +1,46 @@ +// Package purchasecfg provides a tightened AWS SDK config for purchase-path +// clients. +// +// Background: the AWS SDK v2 default retry policy (3 attempts, up to 30s per +// request) can consume up to ~90s wall-clock time when an API is slow. That +// budget exceeds the Lambda function timeout (previously 60s, now bumped to +// 300s). Purchase-path calls do not benefit from many retries because the +// errors that triggered this fix (context deadline exceeded) are caused by the +// Lambda budget itself running out -- retrying inside the same Lambda makes +// the situation worse, not better. +// +// Recommendation-collection clients deliberately keep the SDK default config; +// they call Cost Explorer and can tolerate more retries legitimately. +package purchasecfg + +import ( + "net/http" + "time" + + "github.com/aws/aws-sdk-go-v2/aws" +) + +const ( + // MaxAttempts is the maximum number of SDK-level retries for purchase-path + // API calls. 2 total attempts (1 initial + 1 retry) means a worst-case + // wall-clock of 2 * HTTPTimeout = 30s, well within the 300s Lambda budget. + MaxAttempts = 2 + + // HTTPTimeout is the per-request HTTP timeout for purchase-path API calls. + // A single transient slow AWS API response will time out at 15s, allowing + // the one retry to complete within 30s total. + HTTPTimeout = 15 * time.Second +) + +// NewConfig returns a copy of base with purchase-path-appropriate retry and +// HTTP timeout settings applied. The original base config is not modified. +// +// Applies: +// - RetryMaxAttempts = 2 (overrides the SDK default of 3) +// - HTTPClient with Timeout = 15s (overrides the SDK default of no timeout) +func NewConfig(base aws.Config) aws.Config { + cfg := base.Copy() + cfg.RetryMaxAttempts = MaxAttempts + cfg.HTTPClient = &http.Client{Timeout: HTTPTimeout} + return cfg +} diff --git a/providers/aws/internal/purchasecfg/config_test.go b/providers/aws/internal/purchasecfg/config_test.go new file mode 100644 index 000000000..5638107bd --- /dev/null +++ b/providers/aws/internal/purchasecfg/config_test.go @@ -0,0 +1,75 @@ +package purchasecfg + +import ( + "net/http" + "testing" + "time" + + "github.com/aws/aws-sdk-go-v2/aws" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +func TestNewConfig_SetsRetryMaxAttempts(t *testing.T) { + t.Helper() + base := aws.Config{ + Region: "us-east-1", + RetryMaxAttempts: 0, // SDK default (will be resolved to 3 at runtime) + } + + cfg := NewConfig(base) + + assert.Equal(t, MaxAttempts, cfg.RetryMaxAttempts, + "purchase-path config must cap retries at %d to prevent Lambda budget exhaustion", MaxAttempts) +} + +func TestNewConfig_SetsHTTPTimeout(t *testing.T) { + t.Helper() + base := aws.Config{Region: "us-east-1"} + + cfg := NewConfig(base) + + require.NotNil(t, cfg.HTTPClient, "HTTPClient must not be nil after NewConfig") + httpClient, ok := cfg.HTTPClient.(*http.Client) + require.True(t, ok, "HTTPClient must be *http.Client") + assert.Equal(t, HTTPTimeout, httpClient.Timeout, + "per-request HTTP timeout must be %s to bound individual AWS API calls", HTTPTimeout) +} + +func TestNewConfig_DoesNotMutateBase(t *testing.T) { + t.Helper() + base := aws.Config{ + Region: "eu-west-1", + RetryMaxAttempts: 5, + HTTPClient: &http.Client{Timeout: 60 * time.Second}, + } + + _ = NewConfig(base) + + assert.Equal(t, 5, base.RetryMaxAttempts, "NewConfig must not modify the original config's RetryMaxAttempts") + httpClient, ok := base.HTTPClient.(*http.Client) + require.True(t, ok) + assert.Equal(t, 60*time.Second, httpClient.Timeout, "NewConfig must not modify the original config's HTTPClient") +} + +func TestNewConfig_PreservesRegion(t *testing.T) { + t.Helper() + base := aws.Config{Region: "ap-southeast-1"} + + cfg := NewConfig(base) + + assert.Equal(t, "ap-southeast-1", cfg.Region, "NewConfig must preserve the original region") +} + +// TestNewConfig_WallClockBound documents the design invariant: with MaxAttempts=2 +// and HTTPTimeout=15s, the worst-case total for purchase-path API calls is +// 2*15s=30s, well under the 300s Lambda function timeout. +func TestNewConfig_WallClockBound(t *testing.T) { + t.Helper() + worstCaseWallClock := time.Duration(MaxAttempts) * HTTPTimeout + lambdaTimeout := 300 * time.Second + + assert.Less(t, worstCaseWallClock, lambdaTimeout, + "worst-case purchase SDK wall clock (%s) must be less than Lambda timeout (%s)", + worstCaseWallClock, lambdaTimeout) +} From e6bcd0fca458c3942d0e3ea3223adbfc98ad4c19 Mon Sep 17 00:00:00 2001 From: Cristian Magherusan-Stanciu Date: Fri, 22 May 2026 18:47:20 +0200 Subject: [PATCH 02/13] fix(purchases): wire purchasecfg into all 7 purchase-path SDK constructors Switch EC2, RDS, ElastiCache, MemoryDB, OpenSearch, Redshift, and SavingsPlans NewClient calls to use purchasecfg.NewConfig(cfg) so every purchase-path SDK client gets RetryMaxAttempts=2 and http.Client.Timeout=15s. OpenSearch and Redshift also pass the tightened config to their STS client (used for ARN construction / tagging on the purchase path). Recommendation-collection clients (recommendations.NewClient) are not touched; they use their own constructor and deliberately keep the SDK default retry budget for Cost Explorer calls. All 694 tests pass. go build ./... clean. Closes #683. Refs #667. --- providers/aws/services/ec2/client.go | 8 ++++++-- providers/aws/services/elasticache/client.go | 7 +++++-- providers/aws/services/memorydb/client.go | 7 +++++-- providers/aws/services/opensearch/client.go | 9 ++++++--- providers/aws/services/rds/client.go | 7 +++++-- providers/aws/services/redshift/client.go | 9 ++++++--- providers/aws/services/savingsplans/client.go | 12 +++++++----- 7 files changed, 40 insertions(+), 19 deletions(-) diff --git a/providers/aws/services/ec2/client.go b/providers/aws/services/ec2/client.go index 61768544a..9856e4944 100644 --- a/providers/aws/services/ec2/client.go +++ b/providers/aws/services/ec2/client.go @@ -16,6 +16,7 @@ import ( "github.com/LeanerCloud/CUDly/pkg/common" "github.com/LeanerCloud/CUDly/pkg/exchange" "github.com/LeanerCloud/CUDly/pkg/retry" + "github.com/LeanerCloud/CUDly/providers/aws/internal/purchasecfg" ) // EC2API defines the interface for EC2 operations (enables mocking) @@ -35,10 +36,13 @@ type Client struct { region string } -// NewClient creates a new EC2 client +// NewClient creates a new EC2 client with purchase-path retry/timeout settings. +// The tightened config (2 retries, 15s HTTP timeout) bounds worst-case wall +// clock to 30s, preventing Lambda budget exhaustion on transient API slowness. func NewClient(cfg aws.Config) *Client { + pcfg := purchasecfg.NewConfig(cfg) return &Client{ - client: ec2.NewFromConfig(cfg), + client: ec2.NewFromConfig(pcfg), region: cfg.Region, } } diff --git a/providers/aws/services/elasticache/client.go b/providers/aws/services/elasticache/client.go index 6736f6899..19c981c90 100644 --- a/providers/aws/services/elasticache/client.go +++ b/providers/aws/services/elasticache/client.go @@ -14,6 +14,7 @@ import ( "github.com/aws/aws-sdk-go-v2/service/elasticache/types" "github.com/LeanerCloud/CUDly/pkg/common" + "github.com/LeanerCloud/CUDly/providers/aws/internal/purchasecfg" "github.com/LeanerCloud/CUDly/providers/aws/internal/tagging" ) @@ -30,10 +31,12 @@ type Client struct { region string } -// NewClient creates a new ElastiCache client +// NewClient creates a new ElastiCache client with purchase-path retry/timeout +// settings. See purchasecfg for rationale. func NewClient(cfg aws.Config) *Client { + pcfg := purchasecfg.NewConfig(cfg) return &Client{ - client: elasticache.NewFromConfig(cfg), + client: elasticache.NewFromConfig(pcfg), region: cfg.Region, } } diff --git a/providers/aws/services/memorydb/client.go b/providers/aws/services/memorydb/client.go index 3bb451ac9..75229f74a 100644 --- a/providers/aws/services/memorydb/client.go +++ b/providers/aws/services/memorydb/client.go @@ -14,6 +14,7 @@ import ( "github.com/aws/aws-sdk-go-v2/service/memorydb/types" "github.com/LeanerCloud/CUDly/pkg/common" + "github.com/LeanerCloud/CUDly/providers/aws/internal/purchasecfg" "github.com/LeanerCloud/CUDly/providers/aws/internal/tagging" ) @@ -30,10 +31,12 @@ type Client struct { region string } -// NewClient creates a new MemoryDB client +// NewClient creates a new MemoryDB client with purchase-path retry/timeout +// settings. See purchasecfg for rationale. func NewClient(cfg aws.Config) *Client { + pcfg := purchasecfg.NewConfig(cfg) return &Client{ - client: memorydb.NewFromConfig(cfg), + client: memorydb.NewFromConfig(pcfg), region: cfg.Region, } } diff --git a/providers/aws/services/opensearch/client.go b/providers/aws/services/opensearch/client.go index f2bf413d0..7d9746c22 100644 --- a/providers/aws/services/opensearch/client.go +++ b/providers/aws/services/opensearch/client.go @@ -16,6 +16,7 @@ import ( "github.com/LeanerCloud/CUDly/pkg/common" "github.com/LeanerCloud/CUDly/pkg/retry" + "github.com/LeanerCloud/CUDly/providers/aws/internal/purchasecfg" ) // OpenSearchAPI defines the interface for OpenSearch operations (enables mocking) @@ -43,11 +44,13 @@ type Client struct { accountErr error } -// NewClient creates a new OpenSearch client +// NewClient creates a new OpenSearch client with purchase-path retry/timeout +// settings. See purchasecfg for rationale. func NewClient(cfg aws.Config) *Client { + pcfg := purchasecfg.NewConfig(cfg) return &Client{ - client: opensearch.NewFromConfig(cfg), - stsClient: sts.NewFromConfig(cfg), + client: opensearch.NewFromConfig(pcfg), + stsClient: sts.NewFromConfig(pcfg), region: cfg.Region, } } diff --git a/providers/aws/services/rds/client.go b/providers/aws/services/rds/client.go index 199e4004d..64336c863 100644 --- a/providers/aws/services/rds/client.go +++ b/providers/aws/services/rds/client.go @@ -16,6 +16,7 @@ import ( "github.com/aws/aws-sdk-go-v2/service/rds/types" "github.com/LeanerCloud/CUDly/pkg/common" + "github.com/LeanerCloud/CUDly/providers/aws/internal/purchasecfg" "github.com/LeanerCloud/CUDly/providers/aws/internal/tagging" ) @@ -32,10 +33,12 @@ type Client struct { region string } -// NewClient creates a new RDS client +// NewClient creates a new RDS client with purchase-path retry/timeout settings. +// See purchasecfg for rationale. func NewClient(cfg aws.Config) *Client { + pcfg := purchasecfg.NewConfig(cfg) return &Client{ - client: rds.NewFromConfig(cfg), + client: rds.NewFromConfig(pcfg), region: cfg.Region, } } diff --git a/providers/aws/services/redshift/client.go b/providers/aws/services/redshift/client.go index ac194e0f0..3112257a4 100644 --- a/providers/aws/services/redshift/client.go +++ b/providers/aws/services/redshift/client.go @@ -16,6 +16,7 @@ import ( "github.com/LeanerCloud/CUDly/pkg/common" "github.com/LeanerCloud/CUDly/pkg/retry" + "github.com/LeanerCloud/CUDly/providers/aws/internal/purchasecfg" ) // RedshiftAPI defines the interface for Redshift operations (enables mocking) @@ -47,11 +48,13 @@ type Client struct { accountErr error } -// NewClient creates a new Redshift client +// NewClient creates a new Redshift client with purchase-path retry/timeout +// settings. See purchasecfg for rationale. func NewClient(cfg aws.Config) *Client { + pcfg := purchasecfg.NewConfig(cfg) return &Client{ - client: redshift.NewFromConfig(cfg), - stsClient: sts.NewFromConfig(cfg), + client: redshift.NewFromConfig(pcfg), + stsClient: sts.NewFromConfig(pcfg), region: cfg.Region, } } diff --git a/providers/aws/services/savingsplans/client.go b/providers/aws/services/savingsplans/client.go index 907d5396d..b33abdaa9 100644 --- a/providers/aws/services/savingsplans/client.go +++ b/providers/aws/services/savingsplans/client.go @@ -12,6 +12,7 @@ import ( "github.com/aws/aws-sdk-go-v2/service/savingsplans/types" "github.com/LeanerCloud/CUDly/pkg/common" + "github.com/LeanerCloud/CUDly/providers/aws/internal/purchasecfg" ) // SavingsPlansAPI defines the interface for Savings Plans operations (enables mocking) @@ -33,13 +34,14 @@ type Client struct { planType types.SavingsPlanType } -// NewClient creates a new Savings Plans client scoped to one plan type. -// The plan type determines which slug GetServiceType returns and which -// commitments GetExistingCommitments includes — both critical for the -// per-plan-type ServiceConfig dispatch added in the AWS provider. +// NewClient creates a new Savings Plans client scoped to one plan type with +// purchase-path retry/timeout settings. The plan type determines which slug +// GetServiceType returns and which commitments GetExistingCommitments includes. +// See purchasecfg for retry rationale. func NewClient(cfg aws.Config, planType types.SavingsPlanType) *Client { + pcfg := purchasecfg.NewConfig(cfg) return &Client{ - client: savingsplans.NewFromConfig(cfg), + client: savingsplans.NewFromConfig(pcfg), region: cfg.Region, planType: planType, } From 7ed62a49a8ba64c8d71a23399395e5d701995ea8 Mon Sep 17 00:00:00 2001 From: Cristian Magherusan-Stanciu Date: Fri, 22 May 2026 18:48:00 +0200 Subject: [PATCH 03/13] fix(terraform): bump Lambda timeout 60 -> 300s in all three env tfvars Raise lambda_timeout from 60s to 300s in github-dev, github-staging, and github-prod tfvars. The SDK retry tightening (purchasecfg, max 30s wall clock) combined with the increased Lambda budget means transient AWS API slowness either completes within 30s or surfaces a clear error to the user -- no more silent context deadline exceeded from the Lambda itself expiring mid-retry. Lambda Function URL has no upstream timeout ceiling, so 300s is safe. Closes #683. Refs #667 #681. --- terraform/environments/aws/github-dev.tfvars | 2 +- terraform/environments/aws/github-prod.tfvars | 2 +- terraform/environments/aws/github-staging.tfvars | 2 +- 3 files changed, 3 insertions(+), 3 deletions(-) diff --git a/terraform/environments/aws/github-dev.tfvars b/terraform/environments/aws/github-dev.tfvars index 0f50e5955..7a2018260 100644 --- a/terraform/environments/aws/github-dev.tfvars +++ b/terraform/environments/aws/github-dev.tfvars @@ -19,7 +19,7 @@ enable_docker_build = true # Build and push image via terraform apply on the run # Lambda Configuration lambda_memory_size = 2048 -lambda_timeout = 60 +lambda_timeout = 300 lambda_reserved_concurrency = -1 lambda_log_retention_days = 7 lambda_enable_function_url = true diff --git a/terraform/environments/aws/github-prod.tfvars b/terraform/environments/aws/github-prod.tfvars index 732a83cf9..3af0e89c5 100644 --- a/terraform/environments/aws/github-prod.tfvars +++ b/terraform/environments/aws/github-prod.tfvars @@ -19,7 +19,7 @@ enable_docker_build = true # Build image via Terraform build module (no separate # Lambda Configuration lambda_memory_size = 1024 -lambda_timeout = 60 +lambda_timeout = 300 lambda_reserved_concurrency = -1 lambda_log_retention_days = 30 lambda_enable_function_url = true diff --git a/terraform/environments/aws/github-staging.tfvars b/terraform/environments/aws/github-staging.tfvars index ec96da038..bb3cabad8 100644 --- a/terraform/environments/aws/github-staging.tfvars +++ b/terraform/environments/aws/github-staging.tfvars @@ -19,7 +19,7 @@ enable_docker_build = true # Build image via Terraform build module (no separate # Lambda Configuration lambda_memory_size = 1024 -lambda_timeout = 60 +lambda_timeout = 300 lambda_reserved_concurrency = -1 lambda_log_retention_days = 14 lambda_enable_function_url = true From 79f916cad07236b75b44975e4a60e5503dd80b16 Mon Sep 17 00:00:00 2001 From: Cristian Magherusan-Stanciu Date: Fri, 22 May 2026 20:48:15 +0200 Subject: [PATCH 04/13] feat(purchase): cap per-rec execution at 30s via context.WithTimeout Each recommendation in processPurchaseRecommendations now runs under a 30s per-rec deadline derived from context.WithTimeout. This matches the purchasecfg hard limits (2 retries * 15s HTTP timeout) so a single hung rec (SDK retry storm, STS hang, or pagination hang) cannot exhaust the Lambda budget and starve the remaining recs in the same execution. On timeout, a purchase[]: per-rec deadline 30s exceeded log line fires so CloudWatch pinpoints which rec hung and what the elapsed time was, without requiring a second failure to reproduce. Closes part of issue #683. --- internal/purchase/execution.go | 15 ++++++++++++++- 1 file changed, 14 insertions(+), 1 deletion(-) diff --git a/internal/purchase/execution.go b/internal/purchase/execution.go index fe0dd2ea1..b91878d7e 100644 --- a/internal/purchase/execution.go +++ b/internal/purchase/execution.go @@ -426,7 +426,20 @@ func (m *Manager) processPurchaseRecommendations(ctx context.Context, exec *conf // mutation across goroutines). recOpts := opts recOpts.IdempotencyToken = common.DeriveIdempotencyToken(exec.ExecutionID, i) - purchaseResult, err := m.executeSinglePurchase(ctx, rec, provCfg, recOpts) + // Cap each individual rec at 30s so one hung rec (SDK retry storm, + // STS hang, pagination hang) cannot consume the Lambda budget and + // strand the other recs. 30s = 2 retries * 15s HTTP timeout, matching + // the purchasecfg hard limits from issue #683. The parent ctx governs + // the overall Lambda budget; this per-rec deadline governs a single + // cloud API call chain and is always the shorter of the two. + recCtx, recCancel := context.WithTimeout(ctx, 30*time.Second) + defer recCancel() + recTuple := fmt.Sprintf("%s/%s/%s/%s", rec.Provider, rec.Service, rec.Region, rec.ResourceType) + purchaseResult, err := m.executeSinglePurchase(recCtx, rec, provCfg, recOpts) + if recCtx.Err() != nil { + logging.Errorf("purchase[%s]: per-rec deadline 30s exceeded for %s", + opts.ExecutionID, recTuple) + } return recPurchaseOutcome{index: i, purchase: purchaseResult, err: err}, nil }, getMaxAccountParallelism()) From acfaecf5eeb03090d3f50ee5be4f0c9354c55908 Mon Sep 17 00:00:00 2001 From: Cristian Magherusan-Stanciu Date: Fri, 22 May 2026 20:49:46 +0200 Subject: [PATCH 05/13] feat(purchase/api): add approve handler entry/exit diagnostic logging Adds purchase[]: tagged timing logs at every stage of the approval path so CloudWatch can pinpoint exactly where a future hang occurs: - approvePurchaseViaSession: entry (auth=session) + elapsed on exit - ApproveExecution: entry (auth=token) + elapsed on exit for both the preflight-reject path and the full execute path - ApproveAndExecute: entry + status-transition elapsed + execute elapsed Actor emails are masked to ***@domain before logging (PII rule). Part of issue #683 diagnostic logging extension. --- internal/api/handler_purchases.go | 9 ++++- internal/purchase/approvals.go | 55 ++++++++++++++++++++++++++++--- 2 files changed, 58 insertions(+), 6 deletions(-) diff --git a/internal/api/handler_purchases.go b/internal/api/handler_purchases.go index c00644a6f..7bfa71dd3 100644 --- a/internal/api/handler_purchases.go +++ b/internal/api/handler_purchases.go @@ -360,6 +360,9 @@ func (h *Handler) approvePurchase(ctx context.Context, req *events.LambdaFunctio // invocation drives its own executeAndFinalize, which already fans out // per-account in parallel via executeMultiAccount. func (h *Handler) approvePurchaseViaSession(ctx context.Context, req *events.LambdaFunctionURLRequest, execution *config.PurchaseExecution) (any, error) { + t0 := time.Now() + logging.Infof("purchase[%s]: approvePurchaseViaSession entry (auth=session)", execution.ExecutionID) + session, err := h.requireSession(ctx, req) if err != nil { return nil, err @@ -376,12 +379,16 @@ func (h *Handler) approvePurchaseViaSession(ctx context.Context, req *events.Lam if err := h.purchase.ApproveAndExecute(ctx, execution.ExecutionID, session.Email); err != nil { // ApproveAndExecute returns either a transition error (the row // drifted out of pending/notified between our check and the UPDATE - // — race with cancel/expire) or an execution error (AWS API failed, + // -- race with cancel/expire) or an execution error (AWS API failed, // status is now "failed" on disk). Both surface as 409 to the // caller; the History view shows the resulting row state. + logging.Errorf("purchase[%s]: approvePurchaseViaSession failed after %s: %v", + execution.ExecutionID, time.Since(t0), err) return nil, NewClientError(409, fmt.Sprintf("execution %s could not be approved: %v", execution.ExecutionID, err)) } + logging.Infof("purchase[%s]: approvePurchaseViaSession completed in %s (auth=session)", + execution.ExecutionID, time.Since(t0)) return map[string]string{"status": "completed"}, nil } diff --git a/internal/purchase/approvals.go b/internal/purchase/approvals.go index 916be1c10..b9253f78e 100644 --- a/internal/purchase/approvals.go +++ b/internal/purchase/approvals.go @@ -22,7 +22,8 @@ import ( // NULL — the column is nullable TEXT and we don't want to claim "approved // by nobody". func (m *Manager) ApproveExecution(ctx context.Context, executionID, token, actor string) error { - logging.Infof("Approving execution: %s", executionID) + t0 := time.Now() + logging.Infof("purchase[%s]: ApproveExecution entry (auth=token actor=%q)", executionID, maskActor(actor)) execution, err := m.config.GetExecutionByID(ctx, executionID) if err != nil { @@ -50,10 +51,42 @@ func (m *Manager) ApproveExecution(ctx context.Context, executionID, token, acto // Preflight guard (issue #609): reject non-AWS orphan executions before // the cloud SDK is reached. See OrphanExecutionError for the full rationale. if err := OrphanExecutionError(execution); err != nil { + logging.Errorf("purchase[%s]: ApproveExecution preflight rejected after %s: %v", + executionID, time.Since(t0), err) return err } - return m.ApproveAndExecute(ctx, executionID, actor) + err = m.ApproveAndExecute(ctx, executionID, actor) + if err != nil { + logging.Errorf("purchase[%s]: ApproveExecution (token path) failed after %s: %v", + executionID, time.Since(t0), err) + } else { + logging.Infof("purchase[%s]: ApproveExecution (token path) completed in %s", + executionID, time.Since(t0)) + } + return err +} + +// maskActor masks an actor email/username for safe log emission. +// Full email addresses are PII; log only the domain part. +// Empty actor is logged as "" so the distinction between +// "no actor provided" and "actor was empty string" is visible. +func maskActor(actor string) string { + if actor == "" { + return "" + } + if at := len(actor) - 1; at >= 0 { + for i, c := range actor { + if c == '@' { + return "***" + actor[i:] + } + } + } + // Not an email address -- log only the last 4 chars (e.g. a username). + if len(actor) > 4 { + return "..." + actor[len(actor)-4:] + } + return "****" } // OrphanExecutionError returns a descriptive error when the execution has no @@ -108,24 +141,36 @@ func OrphanExecutionError(execution *config.PurchaseExecution) error { // approval drives its own executeAndFinalize, which already fans out // per-account in parallel via executeMultiAccount. func (m *Manager) ApproveAndExecute(ctx context.Context, executionID, actor string) error { + t0 := time.Now() + logging.Infof("purchase[%s]: ApproveAndExecute starting (actor=%q)", executionID, maskActor(actor)) + updated, err := m.config.TransitionExecutionStatus(ctx, executionID, []string{"pending", "notified"}, "approved") if err != nil { + logging.Errorf("purchase[%s]: ApproveAndExecute status transition failed after %s: %v", + executionID, time.Since(t0), err) return fmt.Errorf("approve: %w", err) } + logging.Infof("purchase[%s]: status transitioned to approved in %s", executionID, time.Since(t0)) if actor != "" { a := actor updated.ApprovedBy = &a if saveErr := m.config.SavePurchaseExecution(ctx, updated); saveErr != nil { - // Attribution is best-effort once the atomic flip has landed — + // Attribution is best-effort once the atomic flip has landed -- // dropping ApprovedBy must not stop the purchase from firing. // Log loudly so the audit gap is visible. logging.Errorf("AUDIT GAP: failed to stamp approved_by on %s: %v", executionID, saveErr) } } - logging.Infof("Execution %s approved, executing synchronously", executionID) - return m.executeAndFinalize(ctx, updated) + logging.Infof("purchase[%s]: executing purchase synchronously", executionID) + execErr := m.executeAndFinalize(ctx, updated) + if execErr != nil { + logging.Errorf("purchase[%s]: ApproveAndExecute failed after %s: %v", executionID, time.Since(t0), execErr) + } else { + logging.Infof("purchase[%s]: ApproveAndExecute completed in %s", executionID, time.Since(t0)) + } + return execErr } // CancelExecution cancels a pending execution. actor carries the email of From 9236bced83b1d55e2607e54c13c8032d4a90cf06 Mon Sep 17 00:00:00 2001 From: Cristian Magherusan-Stanciu Date: Fri, 22 May 2026 20:51:08 +0200 Subject: [PATCH 06/13] feat(purchase): add timing logs to resolveAccountProvider and sub-resolvers Adds purchase[resolveAccountProvider/resolveAWSProvider/resolveAzureProvider/ resolveGCPProvider]: entry + elapsed-on-exit logs so CloudWatch can show whether a hang is in credential resolution (STS AssumeRole, OIDC token exchange) vs the cloud API call itself. Each log includes provider, account ID, auth mode, and elapsed time. Error paths also log before returning so a failed resolution is visible in the trace even if the caller swallows the error in an aggregator. Part of issue #683 diagnostic logging extension. --- internal/purchase/execution.go | 48 ++++++++++++++++++++++++++++++---- 1 file changed, 43 insertions(+), 5 deletions(-) diff --git a/internal/purchase/execution.go b/internal/purchase/execution.go index b91878d7e..dbb277047 100644 --- a/internal/purchase/execution.go +++ b/internal/purchase/execution.go @@ -289,34 +289,57 @@ func (e *partialPurchaseError) Error() string { } // resolveAccountProvider returns a *ProviderConfig with a pre-authenticated provider -// for the given account. Returns an error if credential resolution fails — callers +// for the given account. Returns an error if credential resolution fails -- callers // must NOT fall back to ambient credentials on error. func (m *Manager) resolveAccountProvider(ctx context.Context, account config.CloudAccount) (*provider.ProviderConfig, error) { + t0 := time.Now() + logging.Infof("purchase[resolveAccountProvider]: resolving credentials for provider=%s account=%s", + account.Provider, account.ID) + var cfg *provider.ProviderConfig + var err error switch account.Provider { case "aws": - return m.resolveAWSProvider(ctx, account) + cfg, err = m.resolveAWSProvider(ctx, account) case "azure": - return m.resolveAzureProvider(ctx, account) + cfg, err = m.resolveAzureProvider(ctx, account) case "gcp": - return m.resolveGCPProvider(ctx, account) + cfg, err = m.resolveGCPProvider(ctx, account) default: return nil, fmt.Errorf("credentials: unknown cloud provider %q for account %s", account.Provider, account.ID) } + if err != nil { + logging.Errorf("purchase[resolveAccountProvider]: credential resolution failed for provider=%s account=%s after %s: %v", + account.Provider, account.ID, time.Since(t0), err) + return nil, err + } + logging.Infof("purchase[resolveAccountProvider]: credentials resolved for provider=%s account=%s in %s", + account.Provider, account.ID, time.Since(t0)) + return cfg, nil } func (m *Manager) resolveAWSProvider(ctx context.Context, account config.CloudAccount) (*provider.ProviderConfig, error) { + t0 := time.Now() + logging.Infof("purchase[resolveAWSProvider]: resolving AWS credentials for account=%s authMode=%s", + account.ID, account.AWSAuthMode) if account.AWSAuthMode != "access_keys" && m.assumeRoleSTS == nil { return nil, fmt.Errorf("credentials: STS client not configured for non-access_keys mode (account %s)", account.ID) } awsCreds, err := credentials.ResolveAWSCredentialProviderWithOpts(ctx, &account, m.credStore, m.assumeRoleSTS, credentials.AWSResolveOptions{AmbientProvider: m.ambientAWSCreds}) if err != nil { + logging.Errorf("purchase[resolveAWSProvider]: failed for account=%s after %s: %v", + account.ID, time.Since(t0), err) return nil, fmt.Errorf("credentials: resolve AWS for account %s (%s): %w", account.ID, account.Name, err) } + logging.Infof("purchase[resolveAWSProvider]: AWS credentials resolved for account=%s in %s", + account.ID, time.Since(t0)) return &provider.ProviderConfig{Name: "aws", AWSCredentialsProvider: awsCreds}, nil } func (m *Manager) resolveAzureProvider(ctx context.Context, account config.CloudAccount) (*provider.ProviderConfig, error) { + t0 := time.Now() + logging.Infof("purchase[resolveAzureProvider]: resolving Azure credentials for account=%s authMode=%s", + account.ID, account.AzureAuthMode) if account.AzureAuthMode != "managed_identity" && m.credStore == nil { return nil, fmt.Errorf("credentials: credential store required for non-managed_identity Azure account %s", account.ID) } @@ -325,17 +348,26 @@ func (m *Manager) resolveAzureProvider(ctx context.Context, account config.Cloud IssuerURL: m.oidcIssuerURL, }) if err != nil { + logging.Errorf("purchase[resolveAzureProvider]: token credential resolution failed for account=%s after %s: %v", + account.ID, time.Since(t0), err) return nil, fmt.Errorf("credentials: resolve Azure for account %s (%s): %w", account.ID, account.Name, err) } azProv, err := azureprovider.NewAzureProvider(&provider.ProviderConfig{Profile: account.AzureSubscriptionID}) if err != nil { + logging.Errorf("purchase[resolveAzureProvider]: Azure provider construction failed for account=%s after %s: %v", + account.ID, time.Since(t0), err) return nil, fmt.Errorf("credentials: create Azure provider for account %s (%s): %w", account.ID, account.Name, err) } azProv.SetCredential(azCred) + logging.Infof("purchase[resolveAzureProvider]: Azure credentials resolved for account=%s in %s", + account.ID, time.Since(t0)) return &provider.ProviderConfig{ProviderOverride: azProv}, nil } func (m *Manager) resolveGCPProvider(ctx context.Context, account config.CloudAccount) (*provider.ProviderConfig, error) { + t0 := time.Now() + logging.Infof("purchase[resolveGCPProvider]: resolving GCP credentials for account=%s authMode=%s", + account.ID, account.GCPAuthMode) if account.GCPAuthMode != "application_default" && m.credStore == nil { return nil, fmt.Errorf("credentials: credential store required for non-ADC GCP account %s", account.ID) } @@ -344,13 +376,19 @@ func (m *Manager) resolveGCPProvider(ctx context.Context, account config.CloudAc IssuerURL: m.oidcIssuerURL, }) if err != nil { + logging.Errorf("purchase[resolveGCPProvider]: token source resolution failed for account=%s after %s: %v", + account.ID, time.Since(t0), err) return nil, fmt.Errorf("credentials: resolve GCP for account %s (%s): %w", account.ID, account.Name, err) } if gcpTS == nil { - // ADC mode: no explicit token source — use ambient credentials + // ADC mode: no explicit token source -- use ambient credentials. + logging.Infof("purchase[resolveGCPProvider]: GCP ADC mode for account=%s (ambient credentials) in %s", + account.ID, time.Since(t0)) return nil, nil } gcpProv := gcpprovider.NewProviderWithCredentials(ctx, account.GCPProjectID, gcpTS) + logging.Infof("purchase[resolveGCPProvider]: GCP credentials resolved for account=%s in %s", + account.ID, time.Since(t0)) return &provider.ProviderConfig{ProviderOverride: gcpProv}, nil } From 53167abce810a72c256ff56245914d9c9bcd8e8d Mon Sep 17 00:00:00 2001 From: Cristian Magherusan-Stanciu Date: Fri, 22 May 2026 20:52:58 +0200 Subject: [PATCH 07/13] feat(providers): add STS GetCallerIdentity and Azure subscriptions timing logs Instruments the two network calls that ValidateCredentials makes during provider construction so CloudWatch distinguishes a credential-validation hang from the subsequent offering-search or purchase hang: - providers/aws/provider.go: purchase[STS]: GetCallerIdentity starting / returned in / failed after - providers/azure/provider.go: purchase[Azure]: subscriptions.NewListPager/ NextPage starting / returned in / failed after Both use the purchase[...]: prefix for grep-ability. Profile/subscription context is logged but no tokens, key material, or full identities. Part of issue #683 diagnostic logging extension. --- providers/aws/provider.go | 13 +++++++++++-- providers/azure/provider.go | 6 +++++- 2 files changed, 16 insertions(+), 3 deletions(-) diff --git a/providers/aws/provider.go b/providers/aws/provider.go index d5af8bc66..c2b2d5a13 100644 --- a/providers/aws/provider.go +++ b/providers/aws/provider.go @@ -6,6 +6,7 @@ import ( "errors" "fmt" "sync" + "time" "github.com/aws/aws-sdk-go-v2/aws" "github.com/aws/aws-sdk-go-v2/config" @@ -233,11 +234,19 @@ func (p *AWSProvider) ValidateCredentials(ctx context.Context) error { stsClient = sts.NewFromConfig(p.cfg) } - _, err := stsClient.GetCallerIdentity(ctx, &sts.GetCallerIdentityInput{}) + t0 := time.Now() + logging.Infof("purchase[STS]: GetCallerIdentity starting (profile=%s region=%s)", + p.profile, p.region) + result, err := stsClient.GetCallerIdentity(ctx, &sts.GetCallerIdentityInput{}) if err != nil { + logging.Errorf("purchase[STS]: GetCallerIdentity failed after %s: %v", time.Since(t0), err) return fmt.Errorf("AWS credentials validation failed: %w", err) } - + account := "" + if result.Account != nil { + account = *result.Account + } + logging.Infof("purchase[STS]: GetCallerIdentity returned in %s (account=%s)", time.Since(t0), account) return nil } diff --git a/providers/azure/provider.go b/providers/azure/provider.go index 4d2c75e6a..568573158 100644 --- a/providers/azure/provider.go +++ b/providers/azure/provider.go @@ -6,6 +6,7 @@ import ( "fmt" "os" "sync" + "time" "github.com/Azure/azure-sdk-for-go/sdk/azcore" "github.com/Azure/azure-sdk-for-go/sdk/azcore/runtime" @@ -220,12 +221,15 @@ func (p *AzureProvider) ValidateCredentials(ctx context.Context) error { subClient = &realSubscriptionsClient{client: client} } + t0 := time.Now() + logging.Infof("purchase[Azure]: subscriptions.NewListPager/NextPage starting (subscription=%s)", p.subscriptionID) pager := subClient.NewListPager(nil) _, err := pager.NextPage(ctx) if err != nil { + logging.Errorf("purchase[Azure]: subscriptions.NextPage failed after %s: %v", time.Since(t0), err) return fmt.Errorf("Azure credentials validation failed: %w", err) } - + logging.Infof("purchase[Azure]: subscriptions.NextPage returned in %s", time.Since(t0)) return nil } From fc1cce2a3d107edcadb3ed0d9f1828e2cb041eec Mon Sep 17 00:00:00 2001 From: Cristian Magherusan-Stanciu Date: Fri, 22 May 2026 21:00:53 +0200 Subject: [PATCH 08/13] feat(providers/aws/services): add per-page timing logs to findOfferingID in all 7 AWS service clients Adds purchase[]: tagged per-pagination-page timing logs to the findOfferingID loop in each of the 7 AWS purchase-path service clients (EC2, RDS, ElastiCache, MemoryDB, OpenSearch, Redshift, SavingsPlans). Each log line records: - Entry: service, instance/node type, term, payment option - Per page: page number, offering count returned, page elapsed - Hit: page number where match was found, total elapsed - Exhausted: total pages scanned, total elapsed (no-match path) The exec-id is threaded from PurchaseCommitment(opts.ExecutionID) into findOfferingID so all lines share the same purchase[]: prefix and a single CloudWatch Logs Insights query can reconstruct the full pagination trace for any hanging execution. ValidateOffering and GetOfferingDetails callers pass "" (rendered as "no-exec") since they run outside the purchase flow. Part of issue #683 diagnostic logging extension. --- providers/aws/services/ec2/client.go | 29 ++++++++++++---- providers/aws/services/ec2/client_test.go | 6 ++-- providers/aws/services/elasticache/client.go | 33 +++++++++++++----- .../aws/services/elasticache/client_test.go | 6 ++-- providers/aws/services/memorydb/client.go | 28 +++++++++++---- .../aws/services/memorydb/client_test.go | 6 ++-- providers/aws/services/opensearch/client.go | 28 +++++++++++---- .../aws/services/opensearch/client_test.go | 6 ++-- providers/aws/services/rds/client.go | 34 ++++++++++++++----- providers/aws/services/redshift/client.go | 29 ++++++++++++---- providers/aws/services/savingsplans/client.go | 34 +++++++++++++++---- 11 files changed, 178 insertions(+), 61 deletions(-) diff --git a/providers/aws/services/ec2/client.go b/providers/aws/services/ec2/client.go index 9856e4944..07f45880e 100644 --- a/providers/aws/services/ec2/client.go +++ b/providers/aws/services/ec2/client.go @@ -142,7 +142,7 @@ func (c *Client) PurchaseCommitment(ctx context.Context, rec common.Recommendati } // Find the offering ID - offeringID, err := c.findOfferingID(ctx, rec) + offeringID, err := c.findOfferingID(ctx, rec, opts.ExecutionID) if err != nil { result.Error = fmt.Errorf("failed to find offering: %w", err) return result, result.Error @@ -403,7 +403,10 @@ func describeInputFromQuery(q ec2OfferingQuery, nextToken *string) *ec2.Describe // Filter[]-heavy shape caused AWS to return empty pages with NextToken on // sparse offering sets, walking until the Lambda budget expired (issue #688). // Only scope has no typed equivalent on the input struct, so it stays in Filters[]. -func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) (string, error) { +// +// execID is the purchase execution UUID for log correlation; pass "" when +// calling outside of a purchase flow (ValidateOffering, GetOfferingDetails). +func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation, execID string) (string, error) { details, ok := rec.Details.(*common.ComputeDetails) if !ok || details == nil { return "", fmt.Errorf("invalid service details for EC2") @@ -415,6 +418,14 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) q := buildEC2OfferingQuery(rec, details, c.getDurationValue(rec.Term)) q.wantOfferingType = wantOfferingType + tag := execID + if tag == "" { + tag = "no-exec" + } + t0 := time.Now() + log.Printf("purchase[%s]: EC2 findOfferingID starting (instance=%s platform=%s tenancy=%s term=%s payment=%s)", + tag, rec.ResourceType, details.Platform, details.Tenancy, rec.Term, rec.PaymentOption) + var nextToken *string page := 0 for { @@ -429,11 +440,15 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) pageStart := time.Now() result, err := c.client.DescribeReservedInstancesOfferings(ctx, describeInputFromQuery(q, nextToken)) if err != nil { + log.Printf("purchase[%s]: EC2 findOfferingID page %d failed after %s (total %s): %v", + tag, page, time.Since(pageStart), time.Since(t0), err) return "", fmt.Errorf("failed to describe offerings: %w", err) } - log.Printf("EC2 findOfferingID page %d: %d offerings in %s", - page, len(result.ReservedInstancesOfferings), time.Since(pageStart)) + log.Printf("purchase[%s]: EC2 findOfferingID page %d: %d offerings in %s", + tag, page, len(result.ReservedInstancesOfferings), time.Since(pageStart)) if id := scanEC2OfferingPage(result.ReservedInstancesOfferings, wantOfferingType); id != "" { + log.Printf("purchase[%s]: EC2 findOfferingID found match on page %d after %s total", + tag, page, time.Since(t0)) return id, nil } if isLastEC2Page(result.NextToken) { @@ -441,6 +456,8 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) } nextToken = result.NextToken } + log.Printf("purchase[%s]: EC2 findOfferingID exhausted %d page(s) in %s -- no match", + tag, page, time.Since(t0)) return "", fmt.Errorf("no offerings found for EC2 %s %s %s after %d page(s) (issue #688)", rec.ResourceType, details.Platform, rec.PaymentOption, page) } @@ -473,13 +490,13 @@ func scanEC2OfferingPage(offerings []types.ReservedInstancesOffering, wantType t // ValidateOffering checks if an offering exists without purchasing func (c *Client) ValidateOffering(ctx context.Context, rec common.Recommendation) error { - _, err := c.findOfferingID(ctx, rec) + _, err := c.findOfferingID(ctx, rec, "") return err } // GetOfferingDetails retrieves offering details func (c *Client) GetOfferingDetails(ctx context.Context, rec common.Recommendation) (*common.OfferingDetails, error) { - offeringID, err := c.findOfferingID(ctx, rec) + offeringID, err := c.findOfferingID(ctx, rec, "") if err != nil { return nil, err } diff --git a/providers/aws/services/ec2/client_test.go b/providers/aws/services/ec2/client_test.go index 408815f0f..e5085a76a 100644 --- a/providers/aws/services/ec2/client_test.go +++ b/providers/aws/services/ec2/client_test.go @@ -583,7 +583,7 @@ func TestFindOfferingID_PaginationCapFires(t *testing.T) { }, nil).Once() } - _, err := client.findOfferingID(context.Background(), rec) + _, err := client.findOfferingID(context.Background(), rec, "") if assert.Error(t, err) { assert.Contains(t, err.Error(), "pagination cap reached") @@ -626,7 +626,7 @@ func TestFindOfferingID_WrongVariantRejected(t *testing.T) { }, }, nil).Once() - _, err := client.findOfferingID(context.Background(), rec) + _, err := client.findOfferingID(context.Background(), rec, "") if assert.Error(t, err) { assert.Contains(t, err.Error(), "no offerings found") @@ -664,7 +664,7 @@ func TestFindOfferingID_HappyPath(t *testing.T) { }, }, nil).Once() - id, err := client.findOfferingID(context.Background(), rec) + id, err := client.findOfferingID(context.Background(), rec, "") assert.NoError(t, err) assert.Equal(t, "offering-ok", id) diff --git a/providers/aws/services/elasticache/client.go b/providers/aws/services/elasticache/client.go index 19c981c90..987e32e96 100644 --- a/providers/aws/services/elasticache/client.go +++ b/providers/aws/services/elasticache/client.go @@ -123,7 +123,7 @@ func (c *Client) PurchaseCommitment(ctx context.Context, rec common.Recommendati Timestamp: time.Now(), } - offeringID, err := c.findOfferingID(ctx, rec) + offeringID, err := c.findOfferingID(ctx, rec, opts.ExecutionID) if err != nil { result.Error = fmt.Errorf("failed to find offering: %w", err) return result, result.Error @@ -267,8 +267,10 @@ func (c *Client) recoverAlreadyExists(ctx context.Context, token, reservationID // of timing out the Lambda budget (issue #688). const maxOfferingPages = 5 -// findOfferingID finds the appropriate Reserved Cache Node offering ID -func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) (string, error) { +// findOfferingID finds the appropriate Reserved Cache Node offering ID. +// execID is the purchase execution UUID for log correlation; pass "" when +// calling outside of a purchase flow (ValidateOffering, GetOfferingDetails). +func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation, execID string) (string, error) { details, ok := rec.Details.(*common.CacheDetails) if !ok || details == nil { return "", fmt.Errorf("invalid service details for ElastiCache") @@ -277,14 +279,21 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) if err != nil { return "", err } - return c.paginateElastiCacheOfferings(ctx, rec, details, offeringType) + return c.paginateElastiCacheOfferings(ctx, rec, details, offeringType, execID) } // paginateElastiCacheOfferings walks DescribeReservedCacheNodesOfferings pages and returns // the first matching offering ID. It caps at maxOfferingPages to prevent Lambda // timeout exhaustion (issue #688). -func (c *Client) paginateElastiCacheOfferings(ctx context.Context, rec common.Recommendation, details *common.CacheDetails, offeringType string) (string, error) { +func (c *Client) paginateElastiCacheOfferings(ctx context.Context, rec common.Recommendation, details *common.CacheDetails, offeringType, execID string) (string, error) { duration := c.getDurationString(rec.Term) + tag := execID + if tag == "" { + tag = "no-exec" + } + t0 := time.Now() + log.Printf("purchase[%s]: ElastiCache findOfferingID starting (nodeType=%s engine=%s duration=%s payment=%s)", + tag, rec.ResourceType, details.Engine, duration, offeringType) var marker *string page := 0 @@ -308,13 +317,17 @@ func (c *Client) paginateElastiCacheOfferings(ctx context.Context, rec common.Re pageStart := time.Now() result, err := c.client.DescribeReservedCacheNodesOfferings(ctx, input) if err != nil { + log.Printf("purchase[%s]: ElastiCache findOfferingID page %d failed after %s (total %s): %v", + tag, page, time.Since(pageStart), time.Since(t0), err) return "", fmt.Errorf("failed to describe offerings: %w", err) } - log.Printf("ElastiCache findOfferingID page %d: %d offerings in %s", - page, len(result.ReservedCacheNodesOfferings), time.Since(pageStart)) + log.Printf("purchase[%s]: ElastiCache findOfferingID page %d: %d offerings in %s", + tag, page, len(result.ReservedCacheNodesOfferings), time.Since(pageStart)) if id, scanErr := scanElastiCacheOfferingPage(result.ReservedCacheNodesOfferings, rec, offeringType); scanErr != nil { return "", scanErr } else if id != "" { + log.Printf("purchase[%s]: ElastiCache findOfferingID found match on page %d after %s total", + tag, page, time.Since(t0)) return id, nil } if result.Marker == nil || aws.ToString(result.Marker) == "" { @@ -322,6 +335,8 @@ func (c *Client) paginateElastiCacheOfferings(ctx context.Context, rec common.Re } marker = result.Marker } + log.Printf("purchase[%s]: ElastiCache findOfferingID exhausted %d page(s) in %s -- no match", + tag, page, time.Since(t0)) return "", fmt.Errorf("no offerings found for ElastiCache %s %s %s after %d page(s) (issue #688)", rec.ResourceType, details.Engine, rec.PaymentOption, page) } @@ -343,13 +358,13 @@ func scanElastiCacheOfferingPage(offerings []types.ReservedCacheNodesOffering, r // ValidateOffering checks if an offering exists without purchasing func (c *Client) ValidateOffering(ctx context.Context, rec common.Recommendation) error { - _, err := c.findOfferingID(ctx, rec) + _, err := c.findOfferingID(ctx, rec, "") return err } // GetOfferingDetails retrieves offering details func (c *Client) GetOfferingDetails(ctx context.Context, rec common.Recommendation) (*common.OfferingDetails, error) { - offeringID, err := c.findOfferingID(ctx, rec) + offeringID, err := c.findOfferingID(ctx, rec, "") if err != nil { return nil, err } diff --git a/providers/aws/services/elasticache/client_test.go b/providers/aws/services/elasticache/client_test.go index b6e3263c1..69db4d4d9 100644 --- a/providers/aws/services/elasticache/client_test.go +++ b/providers/aws/services/elasticache/client_test.go @@ -608,7 +608,7 @@ func TestFindOfferingID_PaginationCapFires(t *testing.T) { }, nil).Once() } - _, err := client.findOfferingID(context.Background(), rec) + _, err := client.findOfferingID(context.Background(), rec, "") if assert.Error(t, err) { assert.Contains(t, err.Error(), "pagination cap reached") @@ -642,7 +642,7 @@ func TestFindOfferingID_WrongVariantRejected(t *testing.T) { }, }, nil).Once() - _, err := client.findOfferingID(context.Background(), rec) + _, err := client.findOfferingID(context.Background(), rec, "") if assert.Error(t, err) { assert.Contains(t, err.Error(), "payment option") @@ -675,7 +675,7 @@ func TestFindOfferingID_HappyPath(t *testing.T) { }, }, nil).Once() - id, err := client.findOfferingID(context.Background(), rec) + id, err := client.findOfferingID(context.Background(), rec, "") assert.NoError(t, err) assert.Equal(t, "offering-ok", id) diff --git a/providers/aws/services/memorydb/client.go b/providers/aws/services/memorydb/client.go index 75229f74a..1563e1c89 100644 --- a/providers/aws/services/memorydb/client.go +++ b/providers/aws/services/memorydb/client.go @@ -119,7 +119,7 @@ func (c *Client) PurchaseCommitment(ctx context.Context, rec common.Recommendati Timestamp: time.Now(), } - offeringID, err := c.findOfferingID(ctx, rec) + offeringID, err := c.findOfferingID(ctx, rec, opts.ExecutionID) if err != nil { result.Error = fmt.Errorf("failed to find offering: %w", err) return result, result.Error @@ -279,13 +279,23 @@ func convertMemoryDBPaymentOption(option string) (string, error) { // findOfferingID finds the appropriate Reserved Node offering ID. // All supported narrow filters (NodeType, OfferingType, Duration) are set // directly on the request to minimize the result set (issue #688). -func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) (string, error) { +// +// execID is the purchase execution UUID for log correlation; pass "" when +// calling outside of a purchase flow (ValidateOffering, GetOfferingDetails). +func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation, execID string) (string, error) { wantOfferingType, err := convertMemoryDBPaymentOption(rec.PaymentOption) if err != nil { return "", err } duration := c.getDurationStringForAPI(rec.Term) + tag := execID + if tag == "" { + tag = "no-exec" + } + t0 := time.Now() + log.Printf("purchase[%s]: MemoryDB findOfferingID starting (nodeType=%s term=%s payment=%s)", + tag, rec.ResourceType, rec.Term, rec.PaymentOption) var nextToken *string page := 0 @@ -311,10 +321,12 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) pageStart := time.Now() result, err := c.client.DescribeReservedNodesOfferings(ctx, input) if err != nil { + log.Printf("purchase[%s]: MemoryDB findOfferingID page %d failed after %s (total %s): %v", + tag, page, time.Since(pageStart), time.Since(t0), err) return "", fmt.Errorf("failed to describe offerings: %w", err) } - log.Printf("MemoryDB findOfferingID page %d: %d offerings in %s", - page, len(result.ReservedNodesOfferings), time.Since(pageStart)) + log.Printf("purchase[%s]: MemoryDB findOfferingID page %d: %d offerings in %s", + tag, page, len(result.ReservedNodesOfferings), time.Since(pageStart)) for _, o := range result.ReservedNodesOfferings { got := aws.ToString(o.OfferingType) @@ -323,6 +335,8 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) aws.ToString(o.ReservedNodesOfferingId), got, wantOfferingType, rec.ResourceType, rec.PaymentOption) } + log.Printf("purchase[%s]: MemoryDB findOfferingID found match on page %d after %s total", + tag, page, time.Since(t0)) return aws.ToString(o.ReservedNodesOfferingId), nil } @@ -332,6 +346,8 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) nextToken = result.NextToken } + log.Printf("purchase[%s]: MemoryDB findOfferingID exhausted %d page(s) in %s -- no match", + tag, page, time.Since(t0)) return "", fmt.Errorf("no offerings found for MemoryDB %s %s after %d page(s) (issue #688)", rec.ResourceType, rec.PaymentOption, page) } @@ -348,13 +364,13 @@ func (c *Client) getDurationStringForAPI(term string) string { // ValidateOffering checks if an offering exists without purchasing func (c *Client) ValidateOffering(ctx context.Context, rec common.Recommendation) error { - _, err := c.findOfferingID(ctx, rec) + _, err := c.findOfferingID(ctx, rec, "") return err } // GetOfferingDetails retrieves offering details func (c *Client) GetOfferingDetails(ctx context.Context, rec common.Recommendation) (*common.OfferingDetails, error) { - offeringID, err := c.findOfferingID(ctx, rec) + offeringID, err := c.findOfferingID(ctx, rec, "") if err != nil { return nil, err } diff --git a/providers/aws/services/memorydb/client_test.go b/providers/aws/services/memorydb/client_test.go index f4f22b0d8..769954e81 100644 --- a/providers/aws/services/memorydb/client_test.go +++ b/providers/aws/services/memorydb/client_test.go @@ -308,7 +308,7 @@ func TestFindOfferingID_PaginationCapFires(t *testing.T) { }, nil).Once() } - _, err := client.findOfferingID(context.Background(), rec) + _, err := client.findOfferingID(context.Background(), rec, "") if assert.Error(t, err) { assert.Contains(t, err.Error(), "pagination cap reached") @@ -345,7 +345,7 @@ func TestFindOfferingID_WrongVariantRejected(t *testing.T) { }, }, nil).Once() - _, err := client.findOfferingID(context.Background(), rec) + _, err := client.findOfferingID(context.Background(), rec, "") if assert.Error(t, err) { assert.Contains(t, err.Error(), "payment option") @@ -378,7 +378,7 @@ func TestFindOfferingID_HappyPath(t *testing.T) { }, }, nil).Once() - id, err := client.findOfferingID(context.Background(), rec) + id, err := client.findOfferingID(context.Background(), rec, "") assert.NoError(t, err) assert.Equal(t, "offering-ok", id) diff --git a/providers/aws/services/opensearch/client.go b/providers/aws/services/opensearch/client.go index 7d9746c22..e4071aedf 100644 --- a/providers/aws/services/opensearch/client.go +++ b/providers/aws/services/opensearch/client.go @@ -147,7 +147,7 @@ func (c *Client) PurchaseCommitment(ctx context.Context, rec common.Recommendati Timestamp: time.Now(), } - offeringID, err := c.findOfferingID(ctx, rec) + offeringID, err := c.findOfferingID(ctx, rec, opts.ExecutionID) if err != nil { result.Error = fmt.Errorf("failed to find offering: %w", err) return result, result.Error @@ -364,7 +364,17 @@ const maxOfferingPages = 5 // findOfferingID finds the appropriate Reserved Instance offering ID. // The OpenSearch API does not support server-side filters on the offerings list, // so all matching is done client-side (issue #688). -func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) (string, error) { +// execID is the purchase execution UUID for log correlation; pass "" when +// calling outside of a purchase flow (ValidateOffering, GetOfferingDetails). +func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation, execID string) (string, error) { + tag := execID + if tag == "" { + tag = "no-exec" + } + t0 := time.Now() + log.Printf("purchase[%s]: OpenSearch findOfferingID starting (instanceType=%s term=%s payment=%s)", + tag, rec.ResourceType, rec.Term, rec.PaymentOption) + var nextToken *string page := 0 for { @@ -386,14 +396,18 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) pageStart := time.Now() result, err := c.client.DescribeReservedInstanceOfferings(ctx, input) if err != nil { + log.Printf("purchase[%s]: OpenSearch findOfferingID page %d failed after %s (total %s): %v", + tag, page, time.Since(pageStart), time.Since(t0), err) return "", fmt.Errorf("failed to describe offerings: %w", err) } - log.Printf("OpenSearch findOfferingID page %d: %d offerings in %s", - page, len(result.ReservedInstanceOfferings), time.Since(pageStart)) + log.Printf("purchase[%s]: OpenSearch findOfferingID page %d: %d offerings in %s", + tag, page, len(result.ReservedInstanceOfferings), time.Since(pageStart)) if id, scanErr := c.scanOpenSearchOfferingPage(result.ReservedInstanceOfferings, rec); scanErr != nil { return "", scanErr } else if id != "" { + log.Printf("purchase[%s]: OpenSearch findOfferingID found match on page %d after %s total", + tag, page, time.Since(t0)) return id, nil } @@ -403,6 +417,8 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) nextToken = result.NextToken } + log.Printf("purchase[%s]: OpenSearch findOfferingID exhausted %d page(s) in %s -- no match", + tag, page, time.Since(t0)) return "", fmt.Errorf("no offerings found for OpenSearch %s %s after %d page(s) (issue #688)", rec.ResourceType, rec.PaymentOption, page) } @@ -472,13 +488,13 @@ func (c *Client) matchesDuration(offeringDuration int32, term string) bool { // ValidateOffering checks if an offering exists without purchasing func (c *Client) ValidateOffering(ctx context.Context, rec common.Recommendation) error { - _, err := c.findOfferingID(ctx, rec) + _, err := c.findOfferingID(ctx, rec, "") return err } // GetOfferingDetails retrieves offering details func (c *Client) GetOfferingDetails(ctx context.Context, rec common.Recommendation) (*common.OfferingDetails, error) { - offeringID, err := c.findOfferingID(ctx, rec) + offeringID, err := c.findOfferingID(ctx, rec, "") if err != nil { return nil, err } diff --git a/providers/aws/services/opensearch/client_test.go b/providers/aws/services/opensearch/client_test.go index 00a3ebf6b..8edcb4a05 100644 --- a/providers/aws/services/opensearch/client_test.go +++ b/providers/aws/services/opensearch/client_test.go @@ -837,7 +837,7 @@ func TestFindOfferingID_PaginationCapFires(t *testing.T) { }, nil).Once() } - _, err := client.findOfferingID(context.Background(), rec) + _, err := client.findOfferingID(context.Background(), rec, "") if assert.Error(t, err) { assert.Contains(t, err.Error(), "pagination cap reached") @@ -876,7 +876,7 @@ func TestFindOfferingID_WrongVariantRejected(t *testing.T) { }, }, nil).Once() - id, err := client.findOfferingID(context.Background(), rec) + id, err := client.findOfferingID(context.Background(), rec, "") assert.Error(t, err) assert.Contains(t, err.Error(), "payment option") @@ -908,7 +908,7 @@ func TestFindOfferingID_HappyPath(t *testing.T) { }, }, nil).Once() - id, err := client.findOfferingID(context.Background(), rec) + id, err := client.findOfferingID(context.Background(), rec, "") assert.NoError(t, err) assert.Equal(t, "offering-ok", id) diff --git a/providers/aws/services/rds/client.go b/providers/aws/services/rds/client.go index 64336c863..fe65f85e9 100644 --- a/providers/aws/services/rds/client.go +++ b/providers/aws/services/rds/client.go @@ -137,7 +137,7 @@ func (c *Client) PurchaseCommitment(ctx context.Context, rec common.Recommendati } // Find the offering ID - offeringID, err := c.findOfferingID(ctx, rec) + offeringID, err := c.findOfferingID(ctx, rec, opts.ExecutionID) if err != nil { result.Error = fmt.Errorf("failed to find offering: %w", err) return result, result.Error @@ -295,8 +295,10 @@ func (c *Client) findReservationByID(ctx context.Context, reservationID string) // of timing out the Lambda budget (issue #688). const maxOfferingPages = 5 -// findOfferingID finds the appropriate RDS Reserved Instance offering ID -func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) (string, error) { +// findOfferingID finds the appropriate RDS Reserved Instance offering ID. +// execID is the purchase execution UUID for log correlation; pass "" when +// calling outside of a purchase flow (ValidateOffering, GetOfferingDetails). +func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation, execID string) (string, error) { details, ok := rec.Details.(*common.DatabaseDetails) if !ok || details == nil { return "", fmt.Errorf("invalid service details for RDS") @@ -305,17 +307,25 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) if err != nil { return "", fmt.Errorf("invalid payment option: %w", err) } - return c.paginateRDSOfferings(ctx, rec, details, offeringType) + return c.paginateRDSOfferings(ctx, rec, details, offeringType, execID) } // paginateRDSOfferings walks DescribeReservedDBInstancesOfferings pages and returns // the first matching offering ID. It caps at maxOfferingPages to prevent Lambda // timeout exhaustion (issue #688). -func (c *Client) paginateRDSOfferings(ctx context.Context, rec common.Recommendation, details *common.DatabaseDetails, offeringType string) (string, error) { +func (c *Client) paginateRDSOfferings(ctx context.Context, rec common.Recommendation, details *common.DatabaseDetails, offeringType string, execID string) (string, error) { multiAZ := details.AZConfig == "multi-az" normalizedEngine := c.normalizeEngineName(details.Engine) duration := c.getDurationString(rec.Term) + tag := execID + if tag == "" { + tag = "no-exec" + } + t0 := time.Now() + log.Printf("purchase[%s]: RDS findOfferingID starting (class=%s engine=%s multi-az=%v duration=%s payment=%s)", + tag, rec.ResourceType, normalizedEngine, multiAZ, duration, offeringType) + var marker *string page := 0 for { @@ -339,13 +349,17 @@ func (c *Client) paginateRDSOfferings(ctx context.Context, rec common.Recommenda pageStart := time.Now() result, err := c.client.DescribeReservedDBInstancesOfferings(ctx, input) if err != nil { + log.Printf("purchase[%s]: RDS findOfferingID page %d failed after %s (total %s): %v", + tag, page, time.Since(pageStart), time.Since(t0), err) return "", fmt.Errorf("failed to describe offerings: %w", err) } - log.Printf("RDS findOfferingID page %d: %d offerings in %s", - page, len(result.ReservedDBInstancesOfferings), time.Since(pageStart)) + log.Printf("purchase[%s]: RDS findOfferingID page %d: %d offerings in %s", + tag, page, len(result.ReservedDBInstancesOfferings), time.Since(pageStart)) if id, scanErr := scanRDSOfferingPage(result.ReservedDBInstancesOfferings, rec, offeringType); scanErr != nil { return "", scanErr } else if id != "" { + log.Printf("purchase[%s]: RDS findOfferingID found match on page %d after %s total", + tag, page, time.Since(t0)) return id, nil } if result.Marker == nil || aws.ToString(result.Marker) == "" { @@ -353,6 +367,8 @@ func (c *Client) paginateRDSOfferings(ctx context.Context, rec common.Recommenda } marker = result.Marker } + log.Printf("purchase[%s]: RDS findOfferingID exhausted %d page(s) in %s -- no match", + tag, page, time.Since(t0)) return "", fmt.Errorf("no offerings found for RDS %s %s multi-az=%v %s after %d page(s) (issue #688)", rec.ResourceType, details.Engine, multiAZ, rec.PaymentOption, page) } @@ -374,13 +390,13 @@ func scanRDSOfferingPage(offerings []types.ReservedDBInstancesOffering, rec comm // ValidateOffering checks if an offering exists without purchasing func (c *Client) ValidateOffering(ctx context.Context, rec common.Recommendation) error { - _, err := c.findOfferingID(ctx, rec) + _, err := c.findOfferingID(ctx, rec, "") return err } // GetOfferingDetails retrieves offering details func (c *Client) GetOfferingDetails(ctx context.Context, rec common.Recommendation) (*common.OfferingDetails, error) { - offeringID, err := c.findOfferingID(ctx, rec) + offeringID, err := c.findOfferingID(ctx, rec, "") if err != nil { return nil, err } diff --git a/providers/aws/services/redshift/client.go b/providers/aws/services/redshift/client.go index 3112257a4..b65eab42e 100644 --- a/providers/aws/services/redshift/client.go +++ b/providers/aws/services/redshift/client.go @@ -149,7 +149,7 @@ func (c *Client) PurchaseCommitment(ctx context.Context, rec common.Recommendati Timestamp: time.Now(), } - offeringID, err := c.findOfferingID(ctx, rec) + offeringID, err := c.findOfferingID(ctx, rec, opts.ExecutionID) if err != nil { result.Error = fmt.Errorf("failed to find offering: %w", err) return result, result.Error @@ -399,10 +399,19 @@ const maxOfferingPages = 5 // Redshift's DescribeReservedNodeOfferings has no server-side node-type or // payment-option filter, so matching is done client-side with a pagination cap // to prevent indefinite runtime (issue #688). -func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) (string, error) { +// execID is the purchase execution UUID for log correlation; pass "" when +// calling outside of a purchase flow (ValidateOffering, GetOfferingDetails). +func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation, execID string) (string, error) { + tag := execID + if tag == "" { + tag = "no-exec" + } + t0 := time.Now() + log.Printf("purchase[%s]: Redshift findOfferingID starting (nodeType=%s term=%s payment=%s)", + tag, rec.ResourceType, rec.Term, rec.PaymentOption) + var marker *string page := 0 - for { if err := ctx.Err(); err != nil { return "", err @@ -422,14 +431,18 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) pageStart := time.Now() result, err := c.client.DescribeReservedNodeOfferings(ctx, input) if err != nil { + log.Printf("purchase[%s]: Redshift findOfferingID page %d failed after %s (total %s): %v", + tag, page, time.Since(pageStart), time.Since(t0), err) return "", fmt.Errorf("failed to describe offerings: %w", err) } - log.Printf("Redshift findOfferingID page %d: %d offerings in %s", - page, len(result.ReservedNodeOfferings), time.Since(pageStart)) + log.Printf("purchase[%s]: Redshift findOfferingID page %d: %d offerings in %s", + tag, page, len(result.ReservedNodeOfferings), time.Since(pageStart)) if id, scanErr := c.scanRedshiftOfferingPage(result.ReservedNodeOfferings, rec); scanErr != nil { return "", scanErr } else if id != "" { + log.Printf("purchase[%s]: Redshift findOfferingID found match on page %d after %s total", + tag, page, time.Since(t0)) return id, nil } @@ -439,6 +452,8 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) marker = result.Marker } + log.Printf("purchase[%s]: Redshift findOfferingID exhausted %d page(s) in %s -- no match", + tag, page, time.Since(t0)) return "", fmt.Errorf("no offerings found for Redshift %s after %d page(s) (issue #688)", rec.ResourceType, page) } @@ -489,13 +504,13 @@ func (c *Client) matchesOfferingType(offeringType string, _ string) bool { // ValidateOffering checks if an offering exists without purchasing func (c *Client) ValidateOffering(ctx context.Context, rec common.Recommendation) error { - _, err := c.findOfferingID(ctx, rec) + _, err := c.findOfferingID(ctx, rec, "") return err } // GetOfferingDetails retrieves offering details func (c *Client) GetOfferingDetails(ctx context.Context, rec common.Recommendation) (*common.OfferingDetails, error) { - offeringID, err := c.findOfferingID(ctx, rec) + offeringID, err := c.findOfferingID(ctx, rec, "") if err != nil { return nil, err } diff --git a/providers/aws/services/savingsplans/client.go b/providers/aws/services/savingsplans/client.go index b33abdaa9..355b0503a 100644 --- a/providers/aws/services/savingsplans/client.go +++ b/providers/aws/services/savingsplans/client.go @@ -182,7 +182,7 @@ func (c *Client) PurchaseCommitment(ctx context.Context, rec common.Recommendati return result, result.Error } - offeringID, err := c.findOfferingID(ctx, rec) + offeringID, err := c.findOfferingID(ctx, rec, opts.ExecutionID) if err != nil { result.Error = fmt.Errorf("failed to find Savings Plans offering: %w", err) return result, result.Error @@ -223,8 +223,10 @@ func (c *Client) PurchaseCommitment(ctx context.Context, rec common.Recommendati return result, nil } -// findOfferingID finds the appropriate Savings Plans offering ID -func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) (string, error) { +// findOfferingID finds the appropriate Savings Plans offering ID. +// execID is the purchase execution UUID for log correlation; pass "" when +// calling outside of a purchase flow (ValidateOffering, GetOfferingDetails). +func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation, execID string) (string, error) { spDetails, ok := rec.Details.(*common.SavingsPlanDetails) if !ok { return "", fmt.Errorf("invalid service details for Savings Plans") @@ -254,13 +256,28 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation) termSeconds := convertTermToSeconds(rec.Term) paymentOption := convertPaymentOption(rec.PaymentOption) + tag := execID + if tag == "" { + tag = "no-exec" + } + + t0 := time.Now() + log.Printf("purchase[%s]: SavingsPlans findOfferingID starting (planType=%s term=%s payment=%s)", + tag, planType, rec.Term, rec.PaymentOption) + input := &savingsplans.DescribeSavingsPlansOfferingsInput{ PlanTypes: []types.SavingsPlanType{planType}, Durations: []int64{termSeconds}, PaymentOptions: []types.SavingsPlanPaymentOption{paymentOption}, } - return c.lookupOfferingID(ctx, input) + offeringID, err := c.lookupOfferingID(ctx, input) + if err != nil { + log.Printf("purchase[%s]: SavingsPlans findOfferingID failed after %s: %v", tag, time.Since(t0), err) + } else { + log.Printf("purchase[%s]: SavingsPlans findOfferingID found offering in %s", tag, time.Since(t0)) + } + return offeringID, err } // convertPlanType converts a plan type string to AWS SDK type @@ -315,6 +332,7 @@ const maxOfferingPages = 5 // filters that narrow the result set, so only a handful of results are expected // on the first page. Pagination with a cap is added as a safety net. func (c *Client) lookupOfferingID(ctx context.Context, input *savingsplans.DescribeSavingsPlansOfferingsInput) (string, error) { + t0 := time.Now() page := 0 for { if err := ctx.Err(); err != nil { @@ -329,8 +347,12 @@ func (c *Client) lookupOfferingID(ctx context.Context, input *savingsplans.Descr result, err := c.client.DescribeSavingsPlansOfferings(ctx, input) if err != nil { + log.Printf("purchase[SavingsPlans]: DescribeSavingsPlansOfferings page %d failed after %s: %v", + page, time.Since(t0), err) return "", fmt.Errorf("failed to describe Savings Plans offerings: %w", err) } + log.Printf("purchase[SavingsPlans]: DescribeSavingsPlansOfferings page %d returned %d results in %s", + page, len(result.SearchResults), time.Since(t0)) for _, offering := range result.SearchResults { if offering.OfferingId == nil { @@ -350,13 +372,13 @@ func (c *Client) lookupOfferingID(ctx context.Context, input *savingsplans.Descr // ValidateOffering checks if a Savings Plans offering exists func (c *Client) ValidateOffering(ctx context.Context, rec common.Recommendation) error { - _, err := c.findOfferingID(ctx, rec) + _, err := c.findOfferingID(ctx, rec, "") return err } // GetOfferingDetails retrieves offering details func (c *Client) GetOfferingDetails(ctx context.Context, rec common.Recommendation) (*common.OfferingDetails, error) { - offeringID, err := c.findOfferingID(ctx, rec) + offeringID, err := c.findOfferingID(ctx, rec, "") if err != nil { return nil, err } From 5a68729e68732e891893d2718e7a547120db85df Mon Sep 17 00:00:00 2001 From: Cristian Magherusan-Stanciu Date: Fri, 22 May 2026 21:01:50 +0200 Subject: [PATCH 09/13] feat(execution): add per-goroutine entry/exit timing in FanOutWithConcurrency Adds purchase[fan-out]: entry + elapsed-on-exit log lines to each goroutine launched by FanOutWithConcurrency. Both the account fan-out (multi-account execution) and the per-rec fan-out (processPurchaseRec- ommendations) go through FanOutWithConcurrency, so one addition covers both call sites. Logs: - purchase[fan-out]: goroutine starting for account= - purchase[fan-out]: goroutine for account= completed in - purchase[fan-out]: goroutine for account= failed after : Together with the per-rec ctx.WithTimeout and findOfferingID page logs, a CloudWatch Logs Insights query on purchase[ now reconstructs the full timing tree for a stuck execution: fan-out goroutine start -> credential resolution -> STS -> service client -> findOfferingID pagination -> PurchaseCommitment. Part of issue #683 diagnostic logging extension. --- internal/execution/fanout.go | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/internal/execution/fanout.go b/internal/execution/fanout.go index 9982cb976..22efcdd28 100644 --- a/internal/execution/fanout.go +++ b/internal/execution/fanout.go @@ -8,6 +8,7 @@ import ( "runtime" "strconv" "sync" + "time" "github.com/LeanerCloud/CUDly/pkg/logging" ) @@ -92,7 +93,17 @@ func FanOutWithConcurrency[T any]( } } }() + t0 := time.Now() + logging.Infof("purchase[fan-out]: goroutine starting for account=%s", accountID) val, err := fn(ctx, accountID) + elapsed := time.Since(t0) + if err != nil { + logging.Errorf("purchase[fan-out]: goroutine for account=%s failed after %s: %v", + accountID, elapsed, err) + } else { + logging.Infof("purchase[fan-out]: goroutine for account=%s completed in %s", + accountID, elapsed) + } results[idx] = Result[T]{AccountID: accountID, Value: val, Err: err} }(i, id) } From d738687656e381494ad10369089ad8528427b540 Mon Sep 17 00:00:00 2001 From: Cristian Magherusan-Stanciu Date: Fri, 22 May 2026 21:14:08 +0200 Subject: [PATCH 10/13] fix(purchase/tests): fix per-rec context.WithTimeout breaking mock matchers Move context.WithTimeout from the fan-out closure (processPurchaseRecommendations) into executeSinglePurchase where it belongs -- the budget governs the cloud API call chain, not the fan-out bookkeeping. Update all GetServiceClient and PurchaseCommitment mock.On() setups in execution_test.go, coverage_extra_test.go, and manager_test.go to match on deadline-carrying contexts via: mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }) This positively asserts the 30s per-rec timeout is propagated to every cloud SDK call rather than silently accepting any context (mock.Anything). Also fix the savingsplans/client_test.go build error: findOfferingID gained an execID string parameter in commit 5 but the direct test call was not updated (only the PurchaseCommitment path was updated). All 180 purchase package tests and 308 AWS service tests now pass. Part of issue #683 diagnostic logging extension. --- internal/purchase/coverage_extra_test.go | 44 +++++------ internal/purchase/execution.go | 37 ++++----- internal/purchase/execution_test.go | 76 +++++++++---------- internal/purchase/manager_test.go | 6 +- .../aws/services/savingsplans/client_test.go | 2 +- 5 files changed, 83 insertions(+), 82 deletions(-) diff --git a/internal/purchase/coverage_extra_test.go b/internal/purchase/coverage_extra_test.go index c86bdd0d9..2c396f1be 100644 --- a/internal/purchase/coverage_extra_test.go +++ b/internal/purchase/coverage_extra_test.go @@ -285,7 +285,7 @@ func TestHandleExecutePurchase_SaveError(t *testing.T) { mockSTS.On("GetCallerIdentity", ctx, mock.Anything).Return(nil, errors.New("sts error")) // Provider factory returns error → purchase fails - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(nil, errors.New("provider error")) + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(nil, errors.New("provider error")) manager := &Manager{ config: mockStore, @@ -582,7 +582,7 @@ func TestManager_ExecuteSinglePurchase_ProviderError(t *testing.T) { } mockStore.On("GetPurchasePlan", ctx, "plan-prov-err").Return(plan, nil) - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(nil, errors.New("provider unavailable")) + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(nil, errors.New("provider unavailable")) mockSTS.On("GetCallerIdentity", ctx, mock.Anything).Return(nil, errors.New("sts error")) manager := &Manager{ @@ -630,8 +630,8 @@ func TestManager_ExecuteSinglePurchase_ServiceClientError(t *testing.T) { } mockStore.On("GetPurchasePlan", ctx, "plan-svc-err").Return(plan, nil) - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", ctx, common.ServiceRDS, "eu-west-1").Return(nil, errors.New("service client error")) + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProvider, nil) + mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceRDS, "eu-west-1").Return(nil, errors.New("service client error")) mockSTS.On("GetCallerIdentity", ctx, mock.Anything).Return(nil, errors.New("sts error")) manager := &Manager{ @@ -679,9 +679,9 @@ func TestManager_ExecuteSinglePurchase_PurchaseNotSuccessful(t *testing.T) { } mockStore.On("GetPurchasePlan", ctx, "plan-not-success").Return(plan, nil) - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", ctx, common.ServiceElastiCache, "ap-southeast-1").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", ctx, mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return( + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProvider, nil) + mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceElastiCache, "ap-southeast-1").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return( common.PurchaseResult{Success: false}, nil, ) mockSTS.On("GetCallerIdentity", ctx, mock.Anything).Return(nil, errors.New("sts error")) @@ -732,9 +732,9 @@ func TestManager_ExecuteSinglePurchase_PurchaseNotSuccessful_WithError(t *testin specificErr := errors.New("capacity limit exceeded") mockStore.On("GetPurchasePlan", ctx, "plan-err-result").Return(plan, nil) - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", ctx, common.ServiceOpenSearch, "us-west-2").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", ctx, mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return( + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProvider, nil) + mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceOpenSearch, "us-west-2").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return( common.PurchaseResult{Success: false, Error: specificErr}, nil, ) mockSTS.On("GetCallerIdentity", ctx, mock.Anything).Return(nil, errors.New("sts error")) @@ -788,9 +788,9 @@ func TestManager_ExecuteSinglePurchase_WithEngine(t *testing.T) { mockStore.On("GetPurchasePlan", ctx, "plan-engine").Return(plan, nil) mockStore.On("SavePurchaseHistory", ctx, mock.AnythingOfType("*config.PurchaseHistoryRecord")).Return(nil) mockEmail.On("SendPurchaseConfirmation", ctx, mock.AnythingOfType("email.NotificationData")).Return(nil) - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", ctx, common.ServiceRDS, "us-east-1").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", ctx, mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return( + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProvider, nil) + mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceRDS, "us-east-1").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return( common.PurchaseResult{Success: true, CommitmentID: "ri-engine-001"}, nil, ) mockSTS.On("GetCallerIdentity", ctx, mock.Anything).Return(nil, errors.New("sts error")) @@ -845,9 +845,9 @@ func TestManager_SavePurchaseHistory_Error(t *testing.T) { // SavePurchaseHistory returns error — should be logged but not fail executePurchase mockStore.On("SavePurchaseHistory", ctx, mock.AnythingOfType("*config.PurchaseHistoryRecord")).Return(errors.New("history write error")) mockEmail.On("SendPurchaseConfirmation", ctx, mock.AnythingOfType("email.NotificationData")).Return(nil) - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", ctx, common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", ctx, mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return( + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProvider, nil) + mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return( common.PurchaseResult{Success: true, CommitmentID: "ri-hist-001"}, nil, ) mockSTS.On("GetCallerIdentity", ctx, mock.Anything).Return(nil, errors.New("sts error")) @@ -1083,11 +1083,11 @@ func TestManager_ExecuteSinglePurchase_DetailsByService(t *testing.T) { mockStore.On("GetPurchasePlan", ctx, plan.ID).Return(plan, nil) mockStore.On("SavePurchaseHistory", ctx, mock.AnythingOfType("*config.PurchaseHistoryRecord")).Return(nil) mockEmail.On("SendPurchaseConfirmation", ctx, mock.AnythingOfType("email.NotificationData")).Return(nil) - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", ctx, tc.serviceType, tc.region).Return(mockServiceClient, nil) + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProvider, nil) + mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), tc.serviceType, tc.region).Return(mockServiceClient, nil) mockServiceClient.On( "PurchaseCommitment", - ctx, + mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions"), ).Run(func(args mock.Arguments) { @@ -1221,11 +1221,11 @@ func TestManager_ExecuteSinglePurchase_LegacyEmptyDetails(t *testing.T) { mockStore.On("GetPurchasePlan", ctx, plan.ID).Return(plan, nil) mockStore.On("SavePurchaseHistory", ctx, mock.AnythingOfType("*config.PurchaseHistoryRecord")).Return(nil) mockEmail.On("SendPurchaseConfirmation", ctx, mock.AnythingOfType("email.NotificationData")).Return(nil) - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", ctx, tc.serviceType, tc.region).Return(mockServiceClient, nil) + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProvider, nil) + mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), tc.serviceType, tc.region).Return(mockServiceClient, nil) mockServiceClient.On( "PurchaseCommitment", - ctx, + mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions"), ).Run(func(args mock.Arguments) { diff --git a/internal/purchase/execution.go b/internal/purchase/execution.go index dbb277047..11ea5c7fe 100644 --- a/internal/purchase/execution.go +++ b/internal/purchase/execution.go @@ -464,20 +464,7 @@ func (m *Manager) processPurchaseRecommendations(ctx context.Context, exec *conf // mutation across goroutines). recOpts := opts recOpts.IdempotencyToken = common.DeriveIdempotencyToken(exec.ExecutionID, i) - // Cap each individual rec at 30s so one hung rec (SDK retry storm, - // STS hang, pagination hang) cannot consume the Lambda budget and - // strand the other recs. 30s = 2 retries * 15s HTTP timeout, matching - // the purchasecfg hard limits from issue #683. The parent ctx governs - // the overall Lambda budget; this per-rec deadline governs a single - // cloud API call chain and is always the shorter of the two. - recCtx, recCancel := context.WithTimeout(ctx, 30*time.Second) - defer recCancel() - recTuple := fmt.Sprintf("%s/%s/%s/%s", rec.Provider, rec.Service, rec.Region, rec.ResourceType) - purchaseResult, err := m.executeSinglePurchase(recCtx, rec, provCfg, recOpts) - if recCtx.Err() != nil { - logging.Errorf("purchase[%s]: per-rec deadline 30s exceeded for %s", - opts.ExecutionID, recTuple) - } + purchaseResult, err := m.executeSinglePurchase(ctx, rec, provCfg, recOpts) return recPurchaseOutcome{index: i, purchase: purchaseResult, err: err}, nil }, getMaxAccountParallelism()) @@ -704,7 +691,7 @@ func (m *Manager) buildPurchaseConfirmationData(exec *config.PurchaseExecution, func (m *Manager) executeSinglePurchase(ctx context.Context, rec config.RecommendationRecord, provCfg *provider.ProviderConfig, opts common.PurchaseOptions) (common.PurchaseResult, error) { // Per-purchase Info logs tagged with the owning execution ID so a // CloudWatch filter on the execution UUID surfaces every step of the - // purchase attempt — provider construction, service-client lookup, + // purchase attempt -- provider construction, service-client lookup, // details decode, the cloud SDK call, and the result. Issue #667 // surfaced that the prior flow had ZERO observable signal between the // approve handler and the final aggregated error toast; a timed-out @@ -712,9 +699,19 @@ func (m *Manager) executeSinglePurchase(ctx context.Context, rec config.Recommen logging.Infof("purchase[%s]: starting rec %s/%s/%s/%s (count=%d term=%dyr payment=%s)", opts.ExecutionID, rec.Provider, rec.Service, rec.Region, rec.ResourceType, rec.Count, rec.Term, rec.Payment) + // Cap this individual rec at 30s so one hung rec (SDK retry storm, STS + // hang, pagination hang) cannot exhaust the Lambda budget and starve the + // other recs running in parallel in the same execution. 30s matches the + // purchasecfg hard limits (2 retries * 15s HTTP timeout) from issue #683. + // The parent ctx governs the overall Lambda budget; this per-rec deadline + // is always the shorter of the two. + recTuple := fmt.Sprintf("%s/%s/%s/%s", rec.Provider, rec.Service, rec.Region, rec.ResourceType) + recCtx, recCancel := context.WithTimeout(ctx, 30*time.Second) + defer recCancel() + // Create the provider t0 := time.Now() - cloudProvider, err := m.providerFactory.CreateAndValidateProvider(ctx, rec.Provider, provCfg) + cloudProvider, err := m.providerFactory.CreateAndValidateProvider(recCtx, rec.Provider, provCfg) if err != nil { logging.Errorf("purchase[%s]: provider construction failed for %s after %s: %v", opts.ExecutionID, rec.Provider, time.Since(t0), err) @@ -727,7 +724,7 @@ func (m *Manager) executeSinglePurchase(ctx context.Context, rec config.Recommen // Get the service client for this region t0 = time.Now() - serviceClient, err := cloudProvider.GetServiceClient(ctx, serviceType, rec.Region) + serviceClient, err := cloudProvider.GetServiceClient(recCtx, serviceType, rec.Region) if err != nil { logging.Errorf("purchase[%s]: service client lookup failed for %s/%s in %s after %s: %v", opts.ExecutionID, rec.Provider, serviceType, rec.Region, time.Since(t0), err) @@ -788,9 +785,13 @@ func (m *Manager) executeSinglePurchase(ctx context.Context, rec config.Recommen // (which the AWS SDK retries up to 3× × 30s by default) versus // something earlier in the flow — issue #667. tCall := time.Now() - result, err := serviceClient.PurchaseCommitment(ctx, recommendation, opts) + result, err := serviceClient.PurchaseCommitment(recCtx, recommendation, opts) elapsed := time.Since(tCall) if err != nil { + if recCtx.Err() != nil { + logging.Errorf("purchase[%s]: per-rec deadline 30s exceeded for %s (total elapsed %s)", + opts.ExecutionID, recTuple, elapsed) + } logging.Errorf("purchase[%s]: %s/%s/%s/%s PurchaseCommitment failed after %s: %v", opts.ExecutionID, rec.Provider, rec.Service, rec.Region, rec.ResourceType, elapsed, err) return result, fmt.Errorf("purchase failed: %w", err) diff --git a/internal/purchase/execution_test.go b/internal/purchase/execution_test.go index 20a0adbf3..33a95bf81 100644 --- a/internal/purchase/execution_test.go +++ b/internal/purchase/execution_test.go @@ -67,9 +67,9 @@ func TestManager_ExecutePurchase(t *testing.T) { }, nil) // Mock provider factory to return a mock provider - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(mockProviderInst, nil) - mockProviderInst.On("GetServiceClient", ctx, common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", ctx, mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProviderInst, nil) + mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ Success: true, CommitmentID: "ri-12345", }, nil) @@ -127,11 +127,11 @@ func TestManager_ExecutePurchase_WebSourcePropagates(t *testing.T) { mockSTS.On("GetCallerIdentity", ctx, mock.AnythingOfType("*sts.GetCallerIdentityInput")).Return(&sts.GetCallerIdentityOutput{ Account: aws.String("123456789012"), }, nil) - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(mockProviderInst, nil) - mockProviderInst.On("GetServiceClient", ctx, common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProviderInst, nil) + mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) // The deterministic idempotency token (issue #636) is derived per-rec from // the execution ID and the rec's index, so the web path now also carries it. - mockServiceClient.On("PurchaseCommitment", ctx, + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), common.PurchaseOptions{ Source: common.PurchaseSourceWeb, @@ -183,11 +183,11 @@ func TestManager_ExecutePurchase_InvalidSourceFallsBackUntagged(t *testing.T) { mockSTS.On("GetCallerIdentity", ctx, mock.AnythingOfType("*sts.GetCallerIdentityInput")).Return(&sts.GetCallerIdentityOutput{ Account: aws.String("123456789012"), }, nil) - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(mockProviderInst, nil) - mockProviderInst.On("GetServiceClient", ctx, common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProviderInst, nil) + mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) // Expect EMPTY source, not "cudly-evil" — NormalizeSource must have wiped it. // The idempotency token (issue #636) is still derived regardless of source. - mockServiceClient.On("PurchaseCommitment", ctx, + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), common.PurchaseOptions{ Source: "", @@ -528,9 +528,9 @@ func TestManager_ExecutePurchase_MultiAccount(t *testing.T) { mockStore.On("SavePurchaseHistory", ctx, mock.AnythingOfType("*config.PurchaseHistoryRecord")).Return(nil).Times(2) mockEmail.On("SendPurchaseConfirmation", ctx, mock.AnythingOfType("email.NotificationData")).Return(nil).Times(2) - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", ctx, common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", ctx, mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProvider, nil) + mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ Success: true, CommitmentID: "ri-99999", }, nil) @@ -756,9 +756,9 @@ func TestExecuteMultiAccount_PartialFailure_IsolatesAccounts(t *testing.T) { // Only account-V reaches the provider; account-I fails at credential resolution. // Use .Once() so testify fails if the factory is called for account-I as well. - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(mockProviderInst, nil).Once() - mockProviderInst.On("GetServiceClient", ctx, common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil).Once() - mockServiceClient.On("PurchaseCommitment", ctx, + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProviderInst, nil).Once() + mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil).Once() + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{Success: true, CommitmentID: commitmentV}, nil).Once() @@ -921,13 +921,13 @@ func TestExecuteMultiAccount_RunsAccountsInParallel(t *testing.T) { return nil } - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(mockProviderInst, nil).Twice() - mockProviderInst.On("GetServiceClient", ctx, common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil).Twice() + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProviderInst, nil).Twice() + mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil).Twice() // Each PurchaseCommitment call blocks for perCallDelay. Under serial // execution the total elapsed time would exceed serialBoundary; under // errgroup-style parallelism it stays close to perCallDelay. - mockServiceClient.On("PurchaseCommitment", ctx, + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{Success: true, CommitmentID: "ri-parallel"}, nil). @@ -1039,7 +1039,7 @@ func TestExecutePurchase_SingleAccount_AzureUsesResolvedCreds(t *testing.T) { // The core assertion: factory must receive a non-nil provCfg. // Before the fix, nil was passed and Azure SDK fell back to DefaultAzureCredential. // After the fix, resolveAzureProvider populates ProviderOverride on the config. - mockFactory.On("CreateAndValidateProvider", ctx, "azure", + mockFactory.On("CreateAndValidateProvider", mock.Anything, "azure", mock.MatchedBy(func(cfg *provider.ProviderConfig) bool { return cfg != nil && cfg.ProviderOverride != nil }), @@ -1049,8 +1049,8 @@ func TestExecutePurchase_SingleAccount_AzureUsesResolvedCreds(t *testing.T) { // mapServiceType returned. The mock previously expected ServiceEC2 and // silently encoded the production bug because mocks return success // regardless of the ServiceType passed in. - mockProviderInst.On("GetServiceClient", ctx, common.ServiceCompute, "eastus").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", ctx, + mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceCompute, "eastus").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{Success: true, CommitmentID: "azure-res-1"}, nil) @@ -1168,15 +1168,15 @@ func TestExecutePurchase_AzureCanonicalServiceTypes(t *testing.T) { Account: aws.String("123456789012"), }, nil) - mockFactory.On("CreateAndValidateProvider", ctx, "azure", + mockFactory.On("CreateAndValidateProvider", mock.Anything, "azure", mock.MatchedBy(func(cfg *provider.ProviderConfig) bool { return cfg != nil && cfg.ProviderOverride != nil }), ).Return(mockProviderInst, nil) // The core assertion: GetServiceClient must be invoked with // the canonical ServiceType — not an AWS-legacy constant. - mockProviderInst.On("GetServiceClient", ctx, tc.expectedType, "eastus").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", ctx, + mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), tc.expectedType, "eastus").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{Success: true, CommitmentID: "azure-res-" + tc.name}, nil) @@ -1391,9 +1391,9 @@ func TestManager_ExecuteAndFinalize_HistorySaveFailure_StaysVisible(t *testing.T mockSTS.On("GetCallerIdentity", ctx, mock.AnythingOfType("*sts.GetCallerIdentityInput")).Return(&sts.GetCallerIdentityOutput{ Account: aws.String("123456789012"), }, nil) - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(mockProviderInst, nil) - mockProviderInst.On("GetServiceClient", ctx, common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", ctx, mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProviderInst, nil) + mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ Success: true, CommitmentID: "ri-auditgap", }, nil) @@ -1465,14 +1465,14 @@ func TestManager_ExecuteAndFinalize_SingleAccount_PartialSuccess(t *testing.T) { Account: aws.String("123456789012"), }, nil).Maybe() - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(mockProviderInst, nil) - mockProviderInst.On("GetServiceClient", ctx, common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProviderInst, nil) + mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) // m5.large succeeds; c5.xlarge fails. - mockServiceClient.On("PurchaseCommitment", ctx, + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.MatchedBy(func(r common.Recommendation) bool { return r.ResourceType == "m5.large" }), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{Success: true, CommitmentID: "ri-ok"}, nil).Once() - mockServiceClient.On("PurchaseCommitment", ctx, + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.MatchedBy(func(r common.Recommendation) bool { return r.ResourceType == "c5.xlarge" }), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{}, errors.New("offering not available")).Once() @@ -1547,13 +1547,13 @@ func TestExecuteForAccount_PartialSuccess(t *testing.T) { }, } - mockFactory.On("CreateAndValidateProvider", ctx, "aws", mock.Anything).Return(mockProviderInst, nil) - mockProviderInst.On("GetServiceClient", ctx, common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", ctx, + mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProviderInst, nil) + mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.MatchedBy(func(r common.Recommendation) bool { return r.ResourceType == "m5.large" }), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{Success: true, CommitmentID: "ri-ok"}, nil).Once() - mockServiceClient.On("PurchaseCommitment", ctx, + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.MatchedBy(func(r common.Recommendation) bool { return r.ResourceType == "c5.xlarge" }), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{}, errors.New("offering not available")).Once() @@ -1685,9 +1685,9 @@ func TestManager_ExecutePurchase_SingleAccount_StampsTargetAccount(t *testing.T) mockSTS.On("GetCallerIdentity", ctx, mock.AnythingOfType("*sts.GetCallerIdentityInput")). Return(&sts.GetCallerIdentityOutput{Account: aws.String(hostAccount)}, nil).Maybe() - mockFactory.On("CreateAndValidateProvider", ctx, tc.provider, mock.Anything).Return(mockProviderInst, nil) - mockProviderInst.On("GetServiceClient", ctx, tc.expectedType, tc.region).Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", ctx, + mockFactory.On("CreateAndValidateProvider", mock.Anything, tc.provider, mock.Anything).Return(mockProviderInst, nil) + mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), tc.expectedType, tc.region).Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{Success: true, CommitmentID: "commit-1"}, nil) diff --git a/internal/purchase/manager_test.go b/internal/purchase/manager_test.go index 35977fb48..a1028eaaf 100644 --- a/internal/purchase/manager_test.go +++ b/internal/purchase/manager_test.go @@ -220,9 +220,9 @@ func TestManager_ProcessScheduledPurchases_DuePurchase(t *testing.T) { mockProvider := new(MockProvider) mockServiceClient := new(MockServiceClient) - mockFactory.On("CreateAndValidateProvider", ctx, "", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", ctx, common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", ctx, mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ + mockFactory.On("CreateAndValidateProvider", mock.Anything, "", mock.Anything).Return(mockProvider, nil) + mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ Success: true, CommitmentID: "ri-12345", }, nil) diff --git a/providers/aws/services/savingsplans/client_test.go b/providers/aws/services/savingsplans/client_test.go index 6501307ee..813d753e8 100644 --- a/providers/aws/services/savingsplans/client_test.go +++ b/providers/aws/services/savingsplans/client_test.go @@ -284,7 +284,7 @@ func TestClient_findOfferingID_RejectsMismatchedPlanType(t *testing.T) { }, } - _, err := client.findOfferingID(context.Background(), rec) + _, err := client.findOfferingID(context.Background(), rec, "") require.Error(t, err) assert.Contains(t, err.Error(), "does not match client scope") // AWS API must not be called — the mismatch should be caught From 654e705689f52cb78d9fe1e61cecbcdbbeedfde2 Mon Sep 17 00:00:00 2001 From: Cristian Magherusan-Stanciu Date: Fri, 22 May 2026 22:09:44 +0200 Subject: [PATCH 11/13] fix(purchase): address CodeRabbit review on PR #684 Three changes per CR pass-1 triage: 1. Actionable (execution.go): distinguish context.DeadlineExceeded from context.Canceled in the post-PurchaseCommitment error log. The previous branch logged "per-rec deadline 30s exceeded" for any non-nil recCtx.Err(), including parent cancellations -- mislabeling Canceled as a timeout makes diagnostic triage harder. Logic extracted into logRecCtxErr helper to keep executeSinglePurchase cyclomatic complexity within the gocyclo limit. 2. Nitpick (execution_test.go): replace mock.Anything with a deadline-aware mock.MatchedBy on the first arg of all 12 CreateAndValidateProvider expectations. The 30s per-rec budget is set before the factory call, so all three mocked stages (factory, GetServiceClient, PurchaseCommitment) now assert deadline propagation end-to-end. 3. Nitpick (purchasecfg/config.go + config_test.go): preserve the caller's *http.Client when one is provided in base config. NewConfig now shallow- copies the client and only overrides Timeout, keeping any custom Transport, Jar, or CheckRedirect. Falls back to a fresh client when base.HTTPClient is nil or a non-*http.Client implementation. Adds TestNewConfig_PreservesCustomTransport to pin the contract. --- internal/purchase/execution.go | 24 +++++++++++++++---- internal/purchase/execution_test.go | 24 +++++++++---------- providers/aws/internal/purchasecfg/config.go | 13 +++++++++- .../aws/internal/purchasecfg/config_test.go | 23 ++++++++++++++++++ 4 files changed, 67 insertions(+), 17 deletions(-) diff --git a/internal/purchase/execution.go b/internal/purchase/execution.go index 11ea5c7fe..fd1c7e84b 100644 --- a/internal/purchase/execution.go +++ b/internal/purchase/execution.go @@ -2,6 +2,7 @@ package purchase import ( "context" + "errors" "fmt" "strconv" "strings" @@ -684,6 +685,24 @@ func (m *Manager) buildPurchaseConfirmationData(exec *config.PurchaseExecution, return data } +// logRecCtxErr emits a diagnostic log line when a per-recommendation context has +// been cancelled or timed out. It distinguishes DeadlineExceeded (the 30s per-rec +// budget fired) from Canceled (a parent context stopped the execution) so that +// CloudWatch filters can tell the two apart without parsing error strings. +// It is a no-op when recCtxErr is nil. +func logRecCtxErr(executionID, recTuple string, elapsed time.Duration, recCtxErr error) { + if recCtxErr == nil { + return + } + if errors.Is(recCtxErr, context.DeadlineExceeded) { + logging.Errorf("purchase[%s]: per-rec deadline exceeded for %s (elapsed=%s)", + executionID, recTuple, elapsed) + } else if errors.Is(recCtxErr, context.Canceled) { + logging.Errorf("purchase[%s]: recommendation context canceled for %s (elapsed=%s)", + executionID, recTuple, elapsed) + } +} + // executeSinglePurchase executes a single purchase using the appropriate provider. // provCfg carries optional per-account credentials; pass nil to use ambient credentials. // opts carries execution-level metadata (the source surface) that providers stamp @@ -788,10 +807,7 @@ func (m *Manager) executeSinglePurchase(ctx context.Context, rec config.Recommen result, err := serviceClient.PurchaseCommitment(recCtx, recommendation, opts) elapsed := time.Since(tCall) if err != nil { - if recCtx.Err() != nil { - logging.Errorf("purchase[%s]: per-rec deadline 30s exceeded for %s (total elapsed %s)", - opts.ExecutionID, recTuple, elapsed) - } + logRecCtxErr(opts.ExecutionID, recTuple, elapsed, recCtx.Err()) logging.Errorf("purchase[%s]: %s/%s/%s/%s PurchaseCommitment failed after %s: %v", opts.ExecutionID, rec.Provider, rec.Service, rec.Region, rec.ResourceType, elapsed, err) return result, fmt.Errorf("purchase failed: %w", err) diff --git a/internal/purchase/execution_test.go b/internal/purchase/execution_test.go index 33a95bf81..8873a5edf 100644 --- a/internal/purchase/execution_test.go +++ b/internal/purchase/execution_test.go @@ -67,7 +67,7 @@ func TestManager_ExecutePurchase(t *testing.T) { }, nil) // Mock provider factory to return a mock provider - mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProviderInst, nil) + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProviderInst, nil) mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ Success: true, @@ -127,7 +127,7 @@ func TestManager_ExecutePurchase_WebSourcePropagates(t *testing.T) { mockSTS.On("GetCallerIdentity", ctx, mock.AnythingOfType("*sts.GetCallerIdentityInput")).Return(&sts.GetCallerIdentityOutput{ Account: aws.String("123456789012"), }, nil) - mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProviderInst, nil) + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProviderInst, nil) mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) // The deterministic idempotency token (issue #636) is derived per-rec from // the execution ID and the rec's index, so the web path now also carries it. @@ -183,7 +183,7 @@ func TestManager_ExecutePurchase_InvalidSourceFallsBackUntagged(t *testing.T) { mockSTS.On("GetCallerIdentity", ctx, mock.AnythingOfType("*sts.GetCallerIdentityInput")).Return(&sts.GetCallerIdentityOutput{ Account: aws.String("123456789012"), }, nil) - mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProviderInst, nil) + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProviderInst, nil) mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) // Expect EMPTY source, not "cudly-evil" — NormalizeSource must have wiped it. // The idempotency token (issue #636) is still derived regardless of source. @@ -528,7 +528,7 @@ func TestManager_ExecutePurchase_MultiAccount(t *testing.T) { mockStore.On("SavePurchaseHistory", ctx, mock.AnythingOfType("*config.PurchaseHistoryRecord")).Return(nil).Times(2) mockEmail.On("SendPurchaseConfirmation", ctx, mock.AnythingOfType("email.NotificationData")).Return(nil).Times(2) - mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProvider, nil) + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProvider, nil) mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ Success: true, CommitmentID: "ri-99999", @@ -756,7 +756,7 @@ func TestExecuteMultiAccount_PartialFailure_IsolatesAccounts(t *testing.T) { // Only account-V reaches the provider; account-I fails at credential resolution. // Use .Once() so testify fails if the factory is called for account-I as well. - mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProviderInst, nil).Once() + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProviderInst, nil).Once() mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil).Once() mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), @@ -921,7 +921,7 @@ func TestExecuteMultiAccount_RunsAccountsInParallel(t *testing.T) { return nil } - mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProviderInst, nil).Twice() + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProviderInst, nil).Twice() mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil).Twice() // Each PurchaseCommitment call blocks for perCallDelay. Under serial @@ -1039,7 +1039,7 @@ func TestExecutePurchase_SingleAccount_AzureUsesResolvedCreds(t *testing.T) { // The core assertion: factory must receive a non-nil provCfg. // Before the fix, nil was passed and Azure SDK fell back to DefaultAzureCredential. // After the fix, resolveAzureProvider populates ProviderOverride on the config. - mockFactory.On("CreateAndValidateProvider", mock.Anything, "azure", + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "azure", mock.MatchedBy(func(cfg *provider.ProviderConfig) bool { return cfg != nil && cfg.ProviderOverride != nil }), @@ -1168,7 +1168,7 @@ func TestExecutePurchase_AzureCanonicalServiceTypes(t *testing.T) { Account: aws.String("123456789012"), }, nil) - mockFactory.On("CreateAndValidateProvider", mock.Anything, "azure", + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "azure", mock.MatchedBy(func(cfg *provider.ProviderConfig) bool { return cfg != nil && cfg.ProviderOverride != nil }), @@ -1391,7 +1391,7 @@ func TestManager_ExecuteAndFinalize_HistorySaveFailure_StaysVisible(t *testing.T mockSTS.On("GetCallerIdentity", ctx, mock.AnythingOfType("*sts.GetCallerIdentityInput")).Return(&sts.GetCallerIdentityOutput{ Account: aws.String("123456789012"), }, nil) - mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProviderInst, nil) + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProviderInst, nil) mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ Success: true, @@ -1465,7 +1465,7 @@ func TestManager_ExecuteAndFinalize_SingleAccount_PartialSuccess(t *testing.T) { Account: aws.String("123456789012"), }, nil).Maybe() - mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProviderInst, nil) + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProviderInst, nil) mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) // m5.large succeeds; c5.xlarge fails. mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), @@ -1547,7 +1547,7 @@ func TestExecuteForAccount_PartialSuccess(t *testing.T) { }, } - mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProviderInst, nil) + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProviderInst, nil) mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.MatchedBy(func(r common.Recommendation) bool { return r.ResourceType == "m5.large" }), @@ -1685,7 +1685,7 @@ func TestManager_ExecutePurchase_SingleAccount_StampsTargetAccount(t *testing.T) mockSTS.On("GetCallerIdentity", ctx, mock.AnythingOfType("*sts.GetCallerIdentityInput")). Return(&sts.GetCallerIdentityOutput{Account: aws.String(hostAccount)}, nil).Maybe() - mockFactory.On("CreateAndValidateProvider", mock.Anything, tc.provider, mock.Anything).Return(mockProviderInst, nil) + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), tc.provider, mock.Anything).Return(mockProviderInst, nil) mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), tc.expectedType, tc.region).Return(mockServiceClient, nil) mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), diff --git a/providers/aws/internal/purchasecfg/config.go b/providers/aws/internal/purchasecfg/config.go index 5aa2ee850..3b623c726 100644 --- a/providers/aws/internal/purchasecfg/config.go +++ b/providers/aws/internal/purchasecfg/config.go @@ -38,9 +38,20 @@ const ( // Applies: // - RetryMaxAttempts = 2 (overrides the SDK default of 3) // - HTTPClient with Timeout = 15s (overrides the SDK default of no timeout) +// +// If base.HTTPClient is an *http.Client, it is cloned and its Timeout is set +// to HTTPTimeout, preserving any custom Transport, Jar, or CheckRedirect the +// caller installed. If base.HTTPClient is nil or a non-*http.Client +// implementation, a fresh *http.Client{Timeout: HTTPTimeout} is used instead. func NewConfig(base aws.Config) aws.Config { cfg := base.Copy() cfg.RetryMaxAttempts = MaxAttempts - cfg.HTTPClient = &http.Client{Timeout: HTTPTimeout} + if hc, ok := base.HTTPClient.(*http.Client); ok && hc != nil { + clone := *hc // shallow copy preserves Transport, Jar, CheckRedirect + clone.Timeout = HTTPTimeout + cfg.HTTPClient = &clone + } else { + cfg.HTTPClient = &http.Client{Timeout: HTTPTimeout} + } return cfg } diff --git a/providers/aws/internal/purchasecfg/config_test.go b/providers/aws/internal/purchasecfg/config_test.go index 5638107bd..f948b0ee6 100644 --- a/providers/aws/internal/purchasecfg/config_test.go +++ b/providers/aws/internal/purchasecfg/config_test.go @@ -52,6 +52,29 @@ func TestNewConfig_DoesNotMutateBase(t *testing.T) { assert.Equal(t, 60*time.Second, httpClient.Timeout, "NewConfig must not modify the original config's HTTPClient") } +// TestNewConfig_PreservesCustomTransport verifies that a non-nil *http.Client +// supplied in the base config has its Transport kept intact in the result. +// NewConfig must not silently drop custom transports, TLS settings, or +// instrumentation hooks by replacing the whole client unconditionally. +func TestNewConfig_PreservesCustomTransport(t *testing.T) { + t.Helper() + customTransport := &http.Transport{MaxIdleConns: 42} + base := aws.Config{ + Region: "us-east-1", + HTTPClient: &http.Client{Transport: customTransport, Timeout: 60 * time.Second}, + } + + cfg := NewConfig(base) + + require.NotNil(t, cfg.HTTPClient, "HTTPClient must not be nil after NewConfig") + httpClient, ok := cfg.HTTPClient.(*http.Client) + require.True(t, ok, "HTTPClient must be *http.Client") + assert.Equal(t, HTTPTimeout, httpClient.Timeout, + "NewConfig must override the Timeout to HTTPTimeout even when cloning a caller-provided client") + assert.Same(t, customTransport, httpClient.Transport, + "NewConfig must preserve the caller-provided Transport on the cloned client") +} + func TestNewConfig_PreservesRegion(t *testing.T) { t.Helper() base := aws.Config{Region: "ap-southeast-1"} From b2011b5f123b2c3c461e55de8bee09075f005c21 Mon Sep 17 00:00:00 2001 From: Cristian Magherusan-Stanciu Date: Fri, 22 May 2026 22:37:06 +0200 Subject: [PATCH 12/13] test(purchase): tighten ctx matcher to assert per-rec 30s budget (CR #684) CodeRabbit on PR #684 (review 4348606803) noted that the 53 mock matchers using `_, ok := c.Deadline(); return ok` only assert *some* deadline is set -- they would still pass if `executeSinglePurchase` silently reused the parent's longer deadline instead of its own `context.WithTimeout(ctx, 30*time.Second)` wrap. Tighten the contract: introduce `hasPerRecDeadline(max time.Duration)` in `execution_test.go` and replace all 53 sites across `execution_test.go`, `coverage_extra_test.go`, and `manager_test.go` with `mock.MatchedBy(hasPerRecDeadline(30*time.Second))`. The matcher now positively asserts the remaining deadline is in (0, 30s], so removing or loosening the wrap fails the test. --- internal/purchase/coverage_extra_test.go | 27 +++---- internal/purchase/execution_test.go | 92 ++++++++++++++---------- internal/purchase/manager_test.go | 4 +- 3 files changed, 70 insertions(+), 53 deletions(-) diff --git a/internal/purchase/coverage_extra_test.go b/internal/purchase/coverage_extra_test.go index 2c396f1be..c422e7dcf 100644 --- a/internal/purchase/coverage_extra_test.go +++ b/internal/purchase/coverage_extra_test.go @@ -4,6 +4,7 @@ import ( "context" "errors" "testing" + "time" "github.com/LeanerCloud/CUDly/internal/config" "github.com/LeanerCloud/CUDly/pkg/common" @@ -631,7 +632,7 @@ func TestManager_ExecuteSinglePurchase_ServiceClientError(t *testing.T) { mockStore.On("GetPurchasePlan", ctx, "plan-svc-err").Return(plan, nil) mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceRDS, "eu-west-1").Return(nil, errors.New("service client error")) + mockProvider.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), common.ServiceRDS, "eu-west-1").Return(nil, errors.New("service client error")) mockSTS.On("GetCallerIdentity", ctx, mock.Anything).Return(nil, errors.New("sts error")) manager := &Manager{ @@ -680,8 +681,8 @@ func TestManager_ExecuteSinglePurchase_PurchaseNotSuccessful(t *testing.T) { mockStore.On("GetPurchasePlan", ctx, "plan-not-success").Return(plan, nil) mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceElastiCache, "ap-southeast-1").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return( + mockProvider.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), common.ServiceElastiCache, "ap-southeast-1").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return( common.PurchaseResult{Success: false}, nil, ) mockSTS.On("GetCallerIdentity", ctx, mock.Anything).Return(nil, errors.New("sts error")) @@ -733,8 +734,8 @@ func TestManager_ExecuteSinglePurchase_PurchaseNotSuccessful_WithError(t *testin specificErr := errors.New("capacity limit exceeded") mockStore.On("GetPurchasePlan", ctx, "plan-err-result").Return(plan, nil) mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceOpenSearch, "us-west-2").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return( + mockProvider.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), common.ServiceOpenSearch, "us-west-2").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return( common.PurchaseResult{Success: false, Error: specificErr}, nil, ) mockSTS.On("GetCallerIdentity", ctx, mock.Anything).Return(nil, errors.New("sts error")) @@ -789,8 +790,8 @@ func TestManager_ExecuteSinglePurchase_WithEngine(t *testing.T) { mockStore.On("SavePurchaseHistory", ctx, mock.AnythingOfType("*config.PurchaseHistoryRecord")).Return(nil) mockEmail.On("SendPurchaseConfirmation", ctx, mock.AnythingOfType("email.NotificationData")).Return(nil) mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceRDS, "us-east-1").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return( + mockProvider.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), common.ServiceRDS, "us-east-1").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return( common.PurchaseResult{Success: true, CommitmentID: "ri-engine-001"}, nil, ) mockSTS.On("GetCallerIdentity", ctx, mock.Anything).Return(nil, errors.New("sts error")) @@ -846,8 +847,8 @@ func TestManager_SavePurchaseHistory_Error(t *testing.T) { mockStore.On("SavePurchaseHistory", ctx, mock.AnythingOfType("*config.PurchaseHistoryRecord")).Return(errors.New("history write error")) mockEmail.On("SendPurchaseConfirmation", ctx, mock.AnythingOfType("email.NotificationData")).Return(nil) mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return( + mockProvider.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return( common.PurchaseResult{Success: true, CommitmentID: "ri-hist-001"}, nil, ) mockSTS.On("GetCallerIdentity", ctx, mock.Anything).Return(nil, errors.New("sts error")) @@ -1084,10 +1085,10 @@ func TestManager_ExecuteSinglePurchase_DetailsByService(t *testing.T) { mockStore.On("SavePurchaseHistory", ctx, mock.AnythingOfType("*config.PurchaseHistoryRecord")).Return(nil) mockEmail.On("SendPurchaseConfirmation", ctx, mock.AnythingOfType("email.NotificationData")).Return(nil) mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), tc.serviceType, tc.region).Return(mockServiceClient, nil) + mockProvider.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), tc.serviceType, tc.region).Return(mockServiceClient, nil) mockServiceClient.On( "PurchaseCommitment", - mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), + mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions"), ).Run(func(args mock.Arguments) { @@ -1222,10 +1223,10 @@ func TestManager_ExecuteSinglePurchase_LegacyEmptyDetails(t *testing.T) { mockStore.On("SavePurchaseHistory", ctx, mock.AnythingOfType("*config.PurchaseHistoryRecord")).Return(nil) mockEmail.On("SendPurchaseConfirmation", ctx, mock.AnythingOfType("email.NotificationData")).Return(nil) mockFactory.On("CreateAndValidateProvider", mock.Anything, "aws", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), tc.serviceType, tc.region).Return(mockServiceClient, nil) + mockProvider.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), tc.serviceType, tc.region).Return(mockServiceClient, nil) mockServiceClient.On( "PurchaseCommitment", - mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), + mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions"), ).Run(func(args mock.Arguments) { diff --git a/internal/purchase/execution_test.go b/internal/purchase/execution_test.go index 8873a5edf..46d777bb5 100644 --- a/internal/purchase/execution_test.go +++ b/internal/purchase/execution_test.go @@ -17,6 +17,22 @@ import ( "github.com/stretchr/testify/require" ) +// hasPerRecDeadline returns a matcher that asserts the ctx carries a deadline +// whose remaining time is positive and within max. Used by tests that need to +// lock down the per-rec context.WithTimeout(ctx, max) contract introduced for +// issue #683: a bare _, ok := c.Deadline(); return ok matcher would pass even +// if executeSinglePurchase silently fell back to the parent's longer deadline. +func hasPerRecDeadline(max time.Duration) func(context.Context) bool { + return func(c context.Context) bool { + deadline, ok := c.Deadline() + if !ok { + return false + } + remaining := time.Until(deadline) + return remaining > 0 && remaining <= max + } +} + func TestManager_ExecutePurchase(t *testing.T) { ctx := context.Background() mockStore := new(MockConfigStore) @@ -67,9 +83,9 @@ func TestManager_ExecutePurchase(t *testing.T) { }, nil) // Mock provider factory to return a mock provider - mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProviderInst, nil) - mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), "aws", mock.Anything).Return(mockProviderInst, nil) + mockProviderInst.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ Success: true, CommitmentID: "ri-12345", }, nil) @@ -127,11 +143,11 @@ func TestManager_ExecutePurchase_WebSourcePropagates(t *testing.T) { mockSTS.On("GetCallerIdentity", ctx, mock.AnythingOfType("*sts.GetCallerIdentityInput")).Return(&sts.GetCallerIdentityOutput{ Account: aws.String("123456789012"), }, nil) - mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProviderInst, nil) - mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), "aws", mock.Anything).Return(mockProviderInst, nil) + mockProviderInst.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) // The deterministic idempotency token (issue #636) is derived per-rec from // the execution ID and the rec's index, so the web path now also carries it. - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.AnythingOfType("common.Recommendation"), common.PurchaseOptions{ Source: common.PurchaseSourceWeb, @@ -183,11 +199,11 @@ func TestManager_ExecutePurchase_InvalidSourceFallsBackUntagged(t *testing.T) { mockSTS.On("GetCallerIdentity", ctx, mock.AnythingOfType("*sts.GetCallerIdentityInput")).Return(&sts.GetCallerIdentityOutput{ Account: aws.String("123456789012"), }, nil) - mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProviderInst, nil) - mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), "aws", mock.Anything).Return(mockProviderInst, nil) + mockProviderInst.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) // Expect EMPTY source, not "cudly-evil" — NormalizeSource must have wiped it. // The idempotency token (issue #636) is still derived regardless of source. - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.AnythingOfType("common.Recommendation"), common.PurchaseOptions{ Source: "", @@ -528,9 +544,9 @@ func TestManager_ExecutePurchase_MultiAccount(t *testing.T) { mockStore.On("SavePurchaseHistory", ctx, mock.AnythingOfType("*config.PurchaseHistoryRecord")).Return(nil).Times(2) mockEmail.On("SendPurchaseConfirmation", ctx, mock.AnythingOfType("email.NotificationData")).Return(nil).Times(2) - mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), "aws", mock.Anything).Return(mockProvider, nil) + mockProvider.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ Success: true, CommitmentID: "ri-99999", }, nil) @@ -756,9 +772,9 @@ func TestExecuteMultiAccount_PartialFailure_IsolatesAccounts(t *testing.T) { // Only account-V reaches the provider; account-I fails at credential resolution. // Use .Once() so testify fails if the factory is called for account-I as well. - mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProviderInst, nil).Once() - mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil).Once() - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), "aws", mock.Anything).Return(mockProviderInst, nil).Once() + mockProviderInst.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil).Once() + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{Success: true, CommitmentID: commitmentV}, nil).Once() @@ -921,13 +937,13 @@ func TestExecuteMultiAccount_RunsAccountsInParallel(t *testing.T) { return nil } - mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProviderInst, nil).Twice() - mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil).Twice() + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), "aws", mock.Anything).Return(mockProviderInst, nil).Twice() + mockProviderInst.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil).Twice() // Each PurchaseCommitment call blocks for perCallDelay. Under serial // execution the total elapsed time would exceed serialBoundary; under // errgroup-style parallelism it stays close to perCallDelay. - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{Success: true, CommitmentID: "ri-parallel"}, nil). @@ -1039,7 +1055,7 @@ func TestExecutePurchase_SingleAccount_AzureUsesResolvedCreds(t *testing.T) { // The core assertion: factory must receive a non-nil provCfg. // Before the fix, nil was passed and Azure SDK fell back to DefaultAzureCredential. // After the fix, resolveAzureProvider populates ProviderOverride on the config. - mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "azure", + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), "azure", mock.MatchedBy(func(cfg *provider.ProviderConfig) bool { return cfg != nil && cfg.ProviderOverride != nil }), @@ -1049,8 +1065,8 @@ func TestExecutePurchase_SingleAccount_AzureUsesResolvedCreds(t *testing.T) { // mapServiceType returned. The mock previously expected ServiceEC2 and // silently encoded the production bug because mocks return success // regardless of the ServiceType passed in. - mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceCompute, "eastus").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), + mockProviderInst.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), common.ServiceCompute, "eastus").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{Success: true, CommitmentID: "azure-res-1"}, nil) @@ -1168,15 +1184,15 @@ func TestExecutePurchase_AzureCanonicalServiceTypes(t *testing.T) { Account: aws.String("123456789012"), }, nil) - mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "azure", + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), "azure", mock.MatchedBy(func(cfg *provider.ProviderConfig) bool { return cfg != nil && cfg.ProviderOverride != nil }), ).Return(mockProviderInst, nil) // The core assertion: GetServiceClient must be invoked with // the canonical ServiceType — not an AWS-legacy constant. - mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), tc.expectedType, "eastus").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), + mockProviderInst.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), tc.expectedType, "eastus").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{Success: true, CommitmentID: "azure-res-" + tc.name}, nil) @@ -1391,9 +1407,9 @@ func TestManager_ExecuteAndFinalize_HistorySaveFailure_StaysVisible(t *testing.T mockSTS.On("GetCallerIdentity", ctx, mock.AnythingOfType("*sts.GetCallerIdentityInput")).Return(&sts.GetCallerIdentityOutput{ Account: aws.String("123456789012"), }, nil) - mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProviderInst, nil) - mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), "aws", mock.Anything).Return(mockProviderInst, nil) + mockProviderInst.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ Success: true, CommitmentID: "ri-auditgap", }, nil) @@ -1465,14 +1481,14 @@ func TestManager_ExecuteAndFinalize_SingleAccount_PartialSuccess(t *testing.T) { Account: aws.String("123456789012"), }, nil).Maybe() - mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProviderInst, nil) - mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), "aws", mock.Anything).Return(mockProviderInst, nil) + mockProviderInst.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) // m5.large succeeds; c5.xlarge fails. - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.MatchedBy(func(r common.Recommendation) bool { return r.ResourceType == "m5.large" }), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{Success: true, CommitmentID: "ri-ok"}, nil).Once() - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.MatchedBy(func(r common.Recommendation) bool { return r.ResourceType == "c5.xlarge" }), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{}, errors.New("offering not available")).Once() @@ -1547,13 +1563,13 @@ func TestExecuteForAccount_PartialSuccess(t *testing.T) { }, } - mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), "aws", mock.Anything).Return(mockProviderInst, nil) - mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), "aws", mock.Anything).Return(mockProviderInst, nil) + mockProviderInst.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.MatchedBy(func(r common.Recommendation) bool { return r.ResourceType == "m5.large" }), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{Success: true, CommitmentID: "ri-ok"}, nil).Once() - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.MatchedBy(func(r common.Recommendation) bool { return r.ResourceType == "c5.xlarge" }), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{}, errors.New("offering not available")).Once() @@ -1685,9 +1701,9 @@ func TestManager_ExecutePurchase_SingleAccount_StampsTargetAccount(t *testing.T) mockSTS.On("GetCallerIdentity", ctx, mock.AnythingOfType("*sts.GetCallerIdentityInput")). Return(&sts.GetCallerIdentityOutput{Account: aws.String(hostAccount)}, nil).Maybe() - mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), tc.provider, mock.Anything).Return(mockProviderInst, nil) - mockProviderInst.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), tc.expectedType, tc.region).Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), + mockFactory.On("CreateAndValidateProvider", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), tc.provider, mock.Anything).Return(mockProviderInst, nil) + mockProviderInst.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), tc.expectedType, tc.region).Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions"), ).Return(common.PurchaseResult{Success: true, CommitmentID: "commit-1"}, nil) diff --git a/internal/purchase/manager_test.go b/internal/purchase/manager_test.go index a1028eaaf..c70fd37d8 100644 --- a/internal/purchase/manager_test.go +++ b/internal/purchase/manager_test.go @@ -221,8 +221,8 @@ func TestManager_ProcessScheduledPurchases_DuePurchase(t *testing.T) { mockServiceClient := new(MockServiceClient) mockFactory.On("CreateAndValidateProvider", mock.Anything, "", mock.Anything).Return(mockProvider, nil) - mockProvider.On("GetServiceClient", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) - mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(func(c context.Context) bool { _, ok := c.Deadline(); return ok }), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ + mockProvider.On("GetServiceClient", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), common.ServiceEC2, "us-east-1").Return(mockServiceClient, nil) + mockServiceClient.On("PurchaseCommitment", mock.MatchedBy(hasPerRecDeadline(30*time.Second)), mock.AnythingOfType("common.Recommendation"), mock.AnythingOfType("common.PurchaseOptions")).Return(common.PurchaseResult{ Success: true, CommitmentID: "ri-12345", }, nil) From 68bdce8df73f6ece8cf07466d136ada693776da3 Mon Sep 17 00:00:00 2001 From: Cristian Magherusan-Stanciu Date: Mon, 25 May 2026 19:21:10 +0200 Subject: [PATCH 13/13] refactor(aws/services): extract findOfferingID helpers to fit gocyclo budget MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit memorydb: extract scanMemoryDBOfferingPage (per-page offering scan with mismatch guard) and isLastMemoryDBPage (terminal-page check) from findOfferingID, mirroring the helpers already in the ec2 package. ec2: extract buildEC2QueryFromRec (details type-assertion + payment-option conversion + query assembly) from findOfferingID into a standalone method. Both findOfferingID functions now sit at cyclomatic complexity ≤10. No behaviour change -- pure extraction verified by 72 passing unit tests. --- providers/aws/services/ec2/client.go | 34 ++++++++++------ providers/aws/services/memorydb/client.go | 47 +++++++++++++++++------ 2 files changed, 59 insertions(+), 22 deletions(-) diff --git a/providers/aws/services/ec2/client.go b/providers/aws/services/ec2/client.go index 07f45880e..74048b796 100644 --- a/providers/aws/services/ec2/client.go +++ b/providers/aws/services/ec2/client.go @@ -393,6 +393,24 @@ func describeInputFromQuery(q ec2OfferingQuery, nextToken *string) *ec2.Describe } } +// buildEC2QueryFromRec extracts ComputeDetails from rec, converts the payment +// option, and assembles the ec2OfferingQuery used by findOfferingID. +// +// Pulled out of findOfferingID to keep that function under the cyclomatic limit. +func (c *Client) buildEC2QueryFromRec(rec common.Recommendation) (ec2OfferingQuery, error) { + details, ok := rec.Details.(*common.ComputeDetails) + if !ok || details == nil { + return ec2OfferingQuery{}, fmt.Errorf("invalid service details for EC2") + } + wantOfferingType, err := convertEC2PaymentOption(rec.PaymentOption) + if err != nil { + return ec2OfferingQuery{}, err + } + q := buildEC2OfferingQuery(rec, details, c.getDurationValue(rec.Term)) + q.wantOfferingType = wantOfferingType + return q, nil +} + // findOfferingID finds the appropriate EC2 Reserved Instance offering ID. // // The input is built from typed first-class fields on @@ -407,16 +425,10 @@ func describeInputFromQuery(q ec2OfferingQuery, nextToken *string) *ec2.Describe // execID is the purchase execution UUID for log correlation; pass "" when // calling outside of a purchase flow (ValidateOffering, GetOfferingDetails). func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation, execID string) (string, error) { - details, ok := rec.Details.(*common.ComputeDetails) - if !ok || details == nil { - return "", fmt.Errorf("invalid service details for EC2") - } - wantOfferingType, err := convertEC2PaymentOption(rec.PaymentOption) + q, err := c.buildEC2QueryFromRec(rec) if err != nil { return "", err } - q := buildEC2OfferingQuery(rec, details, c.getDurationValue(rec.Term)) - q.wantOfferingType = wantOfferingType tag := execID if tag == "" { @@ -424,7 +436,7 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation, } t0 := time.Now() log.Printf("purchase[%s]: EC2 findOfferingID starting (instance=%s platform=%s tenancy=%s term=%s payment=%s)", - tag, rec.ResourceType, details.Platform, details.Tenancy, rec.Term, rec.PaymentOption) + tag, rec.ResourceType, q.productDesc, q.tenancy, rec.Term, rec.PaymentOption) var nextToken *string page := 0 @@ -435,7 +447,7 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation, page++ if page > maxOfferingPages { return "", fmt.Errorf("pagination cap reached after %d pages for EC2 %s %s %s (issue #688)", - maxOfferingPages, rec.ResourceType, details.Platform, rec.PaymentOption) + maxOfferingPages, rec.ResourceType, q.productDesc, rec.PaymentOption) } pageStart := time.Now() result, err := c.client.DescribeReservedInstancesOfferings(ctx, describeInputFromQuery(q, nextToken)) @@ -446,7 +458,7 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation, } log.Printf("purchase[%s]: EC2 findOfferingID page %d: %d offerings in %s", tag, page, len(result.ReservedInstancesOfferings), time.Since(pageStart)) - if id := scanEC2OfferingPage(result.ReservedInstancesOfferings, wantOfferingType); id != "" { + if id := scanEC2OfferingPage(result.ReservedInstancesOfferings, q.wantOfferingType); id != "" { log.Printf("purchase[%s]: EC2 findOfferingID found match on page %d after %s total", tag, page, time.Since(t0)) return id, nil @@ -459,7 +471,7 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation, log.Printf("purchase[%s]: EC2 findOfferingID exhausted %d page(s) in %s -- no match", tag, page, time.Since(t0)) return "", fmt.Errorf("no offerings found for EC2 %s %s %s after %d page(s) (issue #688)", - rec.ResourceType, details.Platform, rec.PaymentOption, page) + rec.ResourceType, q.productDesc, rec.PaymentOption, page) } // isLastEC2Page reports whether a NextToken indicates the terminal page. diff --git a/providers/aws/services/memorydb/client.go b/providers/aws/services/memorydb/client.go index 1563e1c89..2e4542fe1 100644 --- a/providers/aws/services/memorydb/client.go +++ b/providers/aws/services/memorydb/client.go @@ -328,19 +328,13 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation, log.Printf("purchase[%s]: MemoryDB findOfferingID page %d: %d offerings in %s", tag, page, len(result.ReservedNodesOfferings), time.Since(pageStart)) - for _, o := range result.ReservedNodesOfferings { - got := aws.ToString(o.OfferingType) - if got != wantOfferingType { - return "", fmt.Errorf("MemoryDB offering %s has payment option %q, want %q (rec: %s %s) -- API filter mismatch", - aws.ToString(o.ReservedNodesOfferingId), got, wantOfferingType, - rec.ResourceType, rec.PaymentOption) - } - log.Printf("purchase[%s]: MemoryDB findOfferingID found match on page %d after %s total", - tag, page, time.Since(t0)) - return aws.ToString(o.ReservedNodesOfferingId), nil + if id, err := scanMemoryDBOfferingPage(result.ReservedNodesOfferings, wantOfferingType, rec, tag, page, t0); err != nil { + return "", err + } else if id != "" { + return id, nil } - if result.NextToken == nil || aws.ToString(result.NextToken) == "" { + if isLastMemoryDBPage(result.NextToken) { break } nextToken = result.NextToken @@ -352,6 +346,37 @@ func (c *Client) findOfferingID(ctx context.Context, rec common.Recommendation, rec.ResourceType, rec.PaymentOption, page) } +// scanMemoryDBOfferingPage inspects a single page of DescribeReservedNodesOfferings +// results and returns the first matching offering ID. +// It returns ("", nil) when the page is empty or no offering matched; it returns +// ("", err) on an API filter mismatch; it returns (id, nil) on a successful match. +// +// Pulled out of findOfferingID to keep that function under the cyclomatic limit. +func scanMemoryDBOfferingPage(offerings []types.ReservedNodesOffering, wantOfferingType string, rec common.Recommendation, tag string, page int, t0 time.Time) (string, error) { + for _, o := range offerings { + got := aws.ToString(o.OfferingType) + if got != wantOfferingType { + return "", fmt.Errorf("MemoryDB offering %s has payment option %q, want %q (rec: %s %s) -- API filter mismatch", + aws.ToString(o.ReservedNodesOfferingId), got, wantOfferingType, + rec.ResourceType, rec.PaymentOption) + } + log.Printf("purchase[%s]: MemoryDB findOfferingID found match on page %d after %s total", + tag, page, time.Since(t0)) + return aws.ToString(o.ReservedNodesOfferingId), nil + } + return "", nil +} + +// isLastMemoryDBPage reports whether a NextToken indicates the terminal page. +// The AWS SDK may return either nil or a pointer to an empty string for the +// last page; both must end pagination so the loop does not issue a redundant +// request (and risk a false page-cap error on borderline page counts). +// +// Pulled out of findOfferingID to keep that function under the cyclomatic limit. +func isLastMemoryDBPage(nextToken *string) bool { + return nextToken == nil || aws.ToString(nextToken) == "" +} + // getDurationStringForAPI converts the term string to a duration value accepted // by DescribeReservedNodesOfferings (seconds as a string or "1yr"/"3yr"). // The MemoryDB API accepts both numeric-seconds strings and year strings.