fix(cmd): stop the run when an audit record cannot be written

CHANGELOG.md

@@ -7,6 +7,15 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/).
 
 ### Fixed
 
+- A `--purchase` run now stops, and exits 1, when an audit record cannot be
+  written durably (disk full, log removed or made unwritable mid-run) instead
+  of warning and buying more with no audit trail. The audit log is also probed
+  before each real purchase, so a log that broke after the start-of-run check
+  stops the run before buying. The report and summary for what already ran are
+  still written, and the message says how many recommendations were attempted
+  and to verify in AWS before re-running. Applies to the main pipeline and
+  `--input-csv`; dry runs still only warn (#2103).
+
 - Stop silently disabling the extended-support exclusion when AWS queries
   fail. A failed engine lifecycle query or region listing now aborts the run
   before any purchase; an RDS recommendation in a region whose instance

cmd/audit_stop_2103_test.go

@@ -0,0 +1,226 @@
+package main
+
+import (
+	"context"
+	"errors"
+	"net/http"
+	"os"
+	"path/filepath"
+	"strings"
+	"testing"
+
+	"github.com/LeanerCloud/cloud-commitments-go/pkg/common"
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/mock"
+	"github.com/stretchr/testify/require"
+)
+
+// spHook answers the Savings Plan calls of a successful purchase.
+func spHook() *hookTransport {
+	h := &hookTransport{}
+	h.handle = func(r *http.Request) (int, string) {
+		switch {
+		case strings.HasSuffix(r.URL.Path, "/CreateSavingsPlan"):
+			return http.StatusOK, `{"savingsPlanId":"sp-111"}`
+		case strings.HasSuffix(r.URL.Path, "/DescribeSavingsPlans"):
+			return http.StatusOK, `{"savingsPlans":[]}`
+		}
+		return http.StatusBadRequest, `{"__type":"ValidationException","message":"unexpected call"}`
+	}
+	return h
+}
+
+// failAuditWrites makes every audit write fail, as a full disk would.
+func failAuditWrites(t *testing.T) {
+	t.Helper()
+	orig := writeAuditRecordFn
+	writeAuditRecordFn = func(common.AuditRecord, string) error {
+		return errors.New("no space left on device")
+	}
+	t.Cleanup(func() { writeAuditRecordFn = orig })
+}
+
+func auditCfg(t *testing.T) Config {
+	t.Helper()
+	dir := t.TempDir()
+	return Config{AuditLog: filepath.Join(dir, "audit.jsonl"), CSVOutput: filepath.Join(dir, "report.csv")}
+}
+
+func TestExecuteAndReport_AuditWriteFailureStopsFurtherPurchases(t *testing.T) {
+	t.Setenv("DISABLE_PURCHASE_DELAY", "true")
+	out := captureAppLog(t)
+	cfg := auditCfg(t)
+	failAuditWrites(t)
+	h := spHook()
+	recs := []common.Recommendation{offeringSP("o-1", 1), offeringSP("o-2", 2), offeringSP("o-3", 3)}
+
+	err := executeAndReport(context.Background(), hookedAWSConfig(h), recs, false, "run-1", cfg, nil)
+
+	require.ErrorIs(t, err, errAuditTrailLost)
+	assert.Equal(t, 1, h.count("/CreateSavingsPlan"), "no purchase may follow an unaudited one")
+	assert.Positive(t, h.count("/DescribeSavingsPlans"), "the duplicate check ran before the purchase")
+	assert.Contains(t, out.String(), "missing or not durable")
+	assert.Contains(t, out.String(), "1 of 3")
+	assert.Contains(t, out.String(), "(commitment sp-111)")
+	report, rerr := os.ReadFile(cfg.CSVOutput)
+	require.NoError(t, rerr)
+	assert.Contains(t, string(report), "sp-111", "the unaudited purchase still reaches the report")
+}
+
+func TestExecuteAndReport_AuditProbeFailureStopsBeforeBuying(t *testing.T) {
+	t.Setenv("DISABLE_PURCHASE_DELAY", "true")
+	captureAppLog(t)
+	cfg := auditCfg(t)
+	// The seam writes record 1, then the log path becomes a directory, which
+	// fails the open with EISDIR even when the tests run as root.
+	orig := writeAuditRecordFn
+	writeAuditRecordFn = func(rec common.AuditRecord, path string) error {
+		if err := orig(rec, path); err != nil {
+			return err
+		}
+		if err := os.Rename(path, path+".1"); err != nil {
+			return err
+		}
+		return os.Mkdir(path, 0o755)
+	}
+	t.Cleanup(func() { writeAuditRecordFn = orig })
+	h := spHook()
+	recs := []common.Recommendation{offeringSP("o-1", 1), offeringSP("o-2", 2)}
+
+	err := executeAndReport(context.Background(), hookedAWSConfig(h), recs, false, "run-1", cfg, nil)
+
+	require.ErrorIs(t, err, errAuditTrailLost)
+	assert.Contains(t, err.Error(), "probe")
+	assert.Equal(t, 1, h.count("/CreateSavingsPlan"), "purchase 2 must never be sent")
+	rows := auditRows(t, cfg.AuditLog+".1")
+	require.Len(t, rows, 1, "record 1 exists")
+}
+
+func TestProcessPurchaseLoop_AuditWriteFailureStopsFurtherPurchases(t *testing.T) {
+	t.Setenv("DISABLE_PURCHASE_DELAY", "true")
+	captureAppLog(t)
+	cfg := auditCfg(t)
+	failAuditWrites(t)
+	recs := []common.Recommendation{validEC2Rec(), validEC2Rec(), validEC2Rec()}
+	mockClient := &MockServiceClient{}
+	mockClient.On("PurchaseCommitment", mock.Anything, mock.Anything, mock.Anything).
+		Return(common.PurchaseResult{Success: true, CommitmentID: "ri-1"}, nil)
+
+	results, err := processPurchaseLoop(context.Background(), recs, "us-east-1", false, mockClient, cfg, "run-1")
+
+	require.ErrorIs(t, err, errAuditTrailLost)
+	require.Len(t, results, 1, "the unaudited result is still returned")
+	mockClient.AssertNumberOfCalls(t, "PurchaseCommitment", 1)
+}
+
+func TestRunCSVPurchases_AuditWriteFailureStopsAcrossRegionsAndServices(t *testing.T) {
+	t.Setenv("DISABLE_PURCHASE_DELAY", "true")
+	captureAppLog(t)
+	cfg := auditCfg(t)
+	failAuditWrites(t)
+	h := spHook()
+	ec2sp := offeringSP("o-3", 3)
+	ec2sp.Service = common.ServiceSavingsPlansEC2Instance
+	ec2sp.Details = &common.SavingsPlanDetails{PlanType: "EC2Instance", HourlyCommitment: 3, InstanceFamily: "m5", Region: "eu-west-1", OfferingID: "o-3"}
+	ec2sp2 := ec2sp
+	ec2sp2.Details = &common.SavingsPlanDetails{PlanType: "EC2Instance", HourlyCommitment: 4, InstanceFamily: "c5", Region: "eu-west-1", OfferingID: "o-4"}
+	recs := []common.Recommendation{offeringSP("o-1", 1), offeringSP("o-2", 2), ec2sp, ec2sp2}
+
+	err := runCSVPurchases(context.Background(), hookedAWSConfig(h), recs, false, cfg, "run-1")
+
+	require.ErrorIs(t, err, errAuditTrailLost)
+	assert.Equal(t, 1, h.count("/CreateSavingsPlan"), "whatever the map order, nothing is bought after the failure")
+}
+
+func TestProcessCSVService_AuditWriteFailureStopsRegionLoop(t *testing.T) {
+	t.Setenv("DISABLE_PURCHASE_DELAY", "true")
+	captureAppLog(t)
+	cfg := auditCfg(t)
+	failAuditWrites(t)
+	h := spHook()
+	byRegion := map[string][]common.Recommendation{
+		"a": {offeringSP("o-1", 1)},
+		"b": {offeringSP("o-2", 2)},
+	}
+
+	_, results, err := processCSVService(context.Background(), hookedAWSConfig(h), common.ServiceSavingsPlansCompute, byRegion, false, cfg, "run-1")
+
+	require.ErrorIs(t, err, errAuditTrailLost)
+	assert.Len(t, results, 1)
+	assert.Equal(t, 1, h.count("/CreateSavingsPlan"))
+}
+
+func TestAuditWriteFailureOnDryRunDoesNotStop(t *testing.T) {
+	captureAppLog(t)
+	cfg := auditCfg(t)
+	failAuditWrites(t)
+	recs := []common.Recommendation{validEC2Rec(), validEC2Rec(), validEC2Rec()}
+
+	results, err := processPurchaseLoop(context.Background(), recs, "us-east-1", true, &MockServiceClient{}, cfg, "run-1")
+
+	require.NoError(t, err)
+	assert.Len(t, results, 3)
+}
+
+// lockAuditAfterFirstPurchase makes the first CreateSavingsPlan call revoke
+// write access to the audit file and its directory, the real-shape failure.
+func lockAuditAfterFirstPurchase(t *testing.T, h *hookTransport, auditPath string) {
+	t.Helper()
+	inner := h.handle
+	h.handle = func(r *http.Request) (int, string) {
+		if strings.HasSuffix(r.URL.Path, "/CreateSavingsPlan") {
+			_ = os.Chmod(auditPath, 0o400)
+			_ = os.Chmod(filepath.Dir(auditPath), 0o500)
+			t.Cleanup(func() { _ = os.Chmod(filepath.Dir(auditPath), 0o700) })
+		}
+		return inner(r)
+	}
+}
+
+func TestRunCSVPurchases_AuditStopKeepsUnauditedPurchaseInReport(t *testing.T) {
+	if os.Geteuid() == 0 {
+		t.Skip("read-only permissions do not bind root")
+	}
+	t.Setenv("DISABLE_PURCHASE_DELAY", "true")
+	out := captureAppLog(t)
+	cfg := auditCfg(t)
+	cfg.CSVOutput = filepath.Join(t.TempDir(), "report.csv")
+	h := spHook()
+	lockAuditAfterFirstPurchase(t, h, cfg.AuditLog)
+	recs := []common.Recommendation{offeringSP("o-1", 1), offeringSP("o-2", 2), offeringSP("o-3", 3)}
+
+	err := runCSVPurchases(context.Background(), hookedAWSConfig(h), recs, false, cfg, "run-1")
+
+	require.ErrorIs(t, err, errAuditTrailLost)
+	assert.Equal(t, 1, h.count("/CreateSavingsPlan"))
+	report, rerr := os.ReadFile(cfg.CSVOutput)
+	require.NoError(t, rerr)
+	assert.Contains(t, string(report), "sp-111", "the unaudited purchase must stay in the CSV report")
+	assert.Contains(t, out.String(), "1 of 3")
+	assert.Contains(t, out.String(), "(commitment sp-111)")
+}
+
+func TestRunCSVPurchases_AuditProbeFailureStopsBeforeBuying(t *testing.T) {
+	t.Setenv("DISABLE_PURCHASE_DELAY", "true")
+	captureAppLog(t)
+	cfg := auditCfg(t)
+	orig := writeAuditRecordFn
+	writeAuditRecordFn = func(rec common.AuditRecord, path string) error {
+		if err := orig(rec, path); err != nil {
+			return err
+		}
+		if err := os.Rename(path, path+".1"); err != nil {
+			return err
+		}
+		return os.Mkdir(path, 0o755)
+	}
+	t.Cleanup(func() { writeAuditRecordFn = orig })
+	h := spHook()
+	recs := []common.Recommendation{offeringSP("o-1", 1), offeringSP("o-2", 2)}
+
+	err := runCSVPurchases(context.Background(), hookedAWSConfig(h), recs, false, cfg, "run-1")
+
+	require.ErrorIs(t, err, errAuditTrailLost)
+	assert.Contains(t, err.Error(), "probe")
+	assert.Equal(t, 1, h.count("/CreateSavingsPlan"), "purchase 2 must never be sent")
+}

cmd/cancellation_test.go

@@ -197,7 +197,7 @@ func TestProcessPurchaseLoop_AuditRecordWrittenBeforeDelay(t *testing.T) {
 	}
 	t.Cleanup(func() { waitBetweenPurchases = orig })
 
-	results := processPurchaseLoop(ctx, recs, "us-east-1", false, mockClient, cfg, "run-1")
+	results, _ := processPurchaseLoop(ctx, recs, "us-east-1", false, mockClient, cfg, "run-1")
 
 	require.Len(t, rowsAtWait, 1, "the purchase that just completed must already be audited when the delay starts")
 	require.Len(t, results, 1, "the second recommendation is not attempted after the interrupt")
@@ -297,7 +297,7 @@ func TestProcessPurchaseLoop_CancelDuringPurchaseDoesNotCancelTheInFlightCall(t
 		}).
 		Return(common.PurchaseResult{Success: true, CommitmentID: "ri-1"}, nil)
 
-	results := processPurchaseLoop(ctx, recs, "us-east-1", false, mockClient, cfg, "run-1")
+	results, _ := processPurchaseLoop(ctx, recs, "us-east-1", false, mockClient, cfg, "run-1")
 
 	require.NoError(t, ctxErrAtPurchase)
 	require.Len(t, results, 1)

cmd/interrupt.go

@@ -2,6 +2,7 @@ package main
 
 import (
 	"context"
+	"errors"
 	"fmt"
 	"os"
 	"time"
@@ -46,6 +47,30 @@ func printInterruptedSummary(attempted, total int, results []common.PurchaseResu
 	}
 }
 
+// errAuditTrailLost marks a real run whose audit record could not be written
+// durably (or whose log failed the pre-purchase probe). The run stops and
+// exits non-zero: continuing would buy with no reconcilable trail (#2103).
+var errAuditTrailLost = errors.New("audit trail lost")
+
+// writeAuditRecordFn is a seam so tests can fail a write after a purchase.
+var writeAuditRecordFn = common.WriteAuditRecord
+
+// auditStopMessage tells the operator what ran before the audit trail was
+// lost. The last result may be missing from, or not durable in, the log.
+func auditStopMessage(attempted, total int, results []common.PurchaseResult, cause error) string {
+	last := "no purchase was attempted"
+	if n := len(results); n > 0 {
+		r := results[n-1]
+		last = fmt.Sprintf("last attempted: %s %s", r.Recommendation.Service, r.Recommendation.ResourceType)
+		if r.Success {
+			last += " (commitment " + r.CommitmentID + ")"
+		} else {
+			last += " (errored: " + fmt.Sprint(r.Error) + ")"
+		}
+	}
+	return fmt.Sprintf("\n❌ Audit record missing or not durable: stopping. %d of %d recommendation(s) attempted, the rest were not purchased; %s. Verify in AWS before re-running, a re-run may buy again. Cause: %v\n", attempted, total, last, cause)
+}
+
 func unverifiedPurchaseLine(r common.PurchaseResult) string {
 	return fmt.Sprintf("purchase of %s %s errored (%v): verify in AWS before re-running", r.Recommendation.Service, r.Recommendation.ResourceType, r.Error)
 }