From 902b1f896e4f44676e5c0712a65b2d2a7edee669 Mon Sep 17 00:00:00 2001 From: Erick Shaffer Date: Tue, 7 Jul 2026 21:18:35 -0600 Subject: [PATCH 1/3] fix: log fetches and mutation intents --- docs/bug-fixes.md | 8 ++ internal/application/sync/fetch.go | 127 +++++++++++++++++- internal/application/sync/orchestrator.go | 55 +++++--- .../application/sync/orchestrator_test.go | 36 ++++- .../application/sync/process_order_test.go | 21 +++ internal/application/sync/types.go | 19 ++- internal/infrastructure/storage/interfaces.go | 6 + .../00010_add_provider_fetch_logs.sql | 41 ++++++ .../infrastructure/storage/migrations_test.go | 8 +- internal/infrastructure/storage/mock.go | 63 ++++++--- internal/infrastructure/storage/models.go | 16 +++ internal/infrastructure/storage/sqlite.go | 88 +++++++++++- .../infrastructure/storage/storage_test.go | 32 +++++ 13 files changed, 468 insertions(+), 52 deletions(-) create mode 100644 internal/infrastructure/storage/migrations/00010_add_provider_fetch_logs.sql diff --git a/docs/bug-fixes.md b/docs/bug-fixes.md index b8326dc..0be2d77 100644 --- a/docs/bug-fixes.md +++ b/docs/bug-fixes.md @@ -40,6 +40,14 @@ Added append-only `processing_attempts`, `order_transactions`, match diagnostics - `go test ./internal/infrastructure/storage ./internal/application/sync/handlers ./internal/application/sync -run 'TestStorage_SaveRecord_DoesNotDowngradeSuccessWithFailure|TestStorage_SaveRecord_AppendsAttemptHistory|TestStorage_OrderTransactions_MultipleRowsPerOrder|TestSimpleHandler_ProcessOrder_ReconcilesAlreadySplitTransactions|TestMonarchAdapter_LogAPICallIncludesOrderAndTransaction' -count=1` passes. - `go test ./...` passes. +**Follow-up Audit Hardening:** +Added provider fetch snapshots and pre-call Monarch mutation intent logs so future investigations can distinguish "we intended to write this" from "the write completed" and can inspect the provider/Monarch fetch payloads that led to a decision. + +**Follow-up Verification:** +- `TestStorage_ProviderFetchLog_RoundTrip` verifies provider fetch logs are durable. +- `TestOrchestrator_fetchOrders_LogsProviderFetch` verifies provider order fetches are logged by the orchestrator. +- `TestMonarchAdapter_LogAPICallRecordsIntentAndCompletion` verifies mutation intent and completion are recorded separately. + --- ### 2026-07-02: Dependabot PR tests failed because Codecov upload required a token diff --git a/internal/application/sync/fetch.go b/internal/application/sync/fetch.go index 8532354..c2ade19 100644 --- a/internal/application/sync/fetch.go +++ b/internal/application/sync/fetch.go @@ -2,13 +2,15 @@ package sync import ( "context" + "encoding/json" "fmt" "strings" "time" - "github.com/eshaffer321/monarch-go/v2/pkg/monarch" "github.com/eshaffer321/itemize/internal/adapters/providers" "github.com/eshaffer321/itemize/internal/domain/categorizer" + "github.com/eshaffer321/itemize/internal/infrastructure/storage" + "github.com/eshaffer321/monarch-go/v2/pkg/monarch" ) // Data fetching functions for the sync orchestrator. @@ -24,12 +26,24 @@ func (o *Orchestrator) fetchOrders(ctx context.Context, opts Options) ([]provide "end_date", endDate.Format("2006-01-02"), ) - orders, err := o.provider.FetchOrders(ctx, providers.FetchOptions{ + fetchOpts := providers.FetchOptions{ StartDate: startDate, EndDate: endDate, MaxOrders: opts.MaxOrders, IncludeDetails: true, - }) + } + started := time.Now() + orders, err := o.provider.FetchOrders(ctx, fetchOpts) + var response any + if o.storage != nil { + response = summarizeOrdersForFetchLog(orders) + } + o.logProviderFetch("orders", map[string]any{ + "start_date": startDate.Format("2006-01-02"), + "end_date": endDate.Format("2006-01-02"), + "max_orders": opts.MaxOrders, + "include_details": true, + }, response, err, time.Since(started), len(orders), 0) if err != nil { return nil, fmt.Errorf("failed to fetch orders: %w", err) } @@ -46,11 +60,18 @@ func (o *Orchestrator) fetchMonarchTransactions(ctx context.Context, opts Option endDate := time.Now() startDate := endDate.AddDate(0, 0, -opts.LookbackDays) + request := map[string]any{ + "start_date": startDate.AddDate(0, 0, -7).Format("2006-01-02"), + "end_date": endDate.Format("2006-01-02"), + "limit": 500, + } + started := time.Now() txList, err := o.clients.Monarch.Transactions.Query(). Between(startDate.AddDate(0, 0, -7), endDate). // Add buffer for date matching Limit(500). Execute(ctx) if err != nil { + o.logProviderFetch("monarch_transactions", request, nil, err, time.Since(started), 0, 0) return nil, fmt.Errorf("failed to fetch transactions: %w", err) } @@ -71,6 +92,11 @@ func (o *Orchestrator) fetchMonarchTransactions(ctx context.Context, opts Option "total", len(txList.Transactions), "provider_transactions", len(providerTransactions), ) + o.logProviderFetch("monarch_transactions", request, map[string]any{ + "total_count": len(txList.Transactions), + "provider_count": len(providerTransactions), + "provider_transactions": summarizeTransactionsForFetchLog(providerTransactions), + }, nil, time.Since(started), 0, len(providerTransactions)) return providerTransactions, nil } @@ -79,7 +105,11 @@ func (o *Orchestrator) fetchMonarchTransactions(ctx context.Context, opts Option func (o *Orchestrator) fetchCategories(ctx context.Context) ([]categorizer.Category, []*monarch.TransactionCategory, error) { o.logger.Debug("Loading Monarch categories") + started := time.Now() categories, err := o.clients.Monarch.Transactions.Categories().List(ctx) + o.logProviderFetch("monarch_categories", map[string]any{}, map[string]any{ + "category_count": len(categories), + }, err, time.Since(started), 0, 0) if err != nil { return nil, nil, fmt.Errorf("failed to load categories: %w", err) } @@ -97,3 +127,94 @@ func (o *Orchestrator) fetchCategories(ctx context.Context) ([]categorizer.Categ return catCategories, categories, nil } + +type orderFetchSummary struct { + ID string `json:"id"` + Date string `json:"date"` + Total float64 `json:"total"` + Subtotal float64 `json:"subtotal"` + Tax float64 `json:"tax"` + Tip float64 `json:"tip"` + FeeTotal float64 `json:"fee_total"` + ItemCount int `json:"item_count"` + RawOrderJSON string `json:"raw_order_json,omitempty"` +} + +type transactionFetchSummary struct { + ID string `json:"id"` + Date string `json:"date"` + Amount float64 `json:"amount"` + MerchantName string `json:"merchant_name,omitempty"` + PlaidName string `json:"plaid_name,omitempty"` + Pending bool `json:"pending"` + HasSplits bool `json:"has_splits"` + IsSplitTransaction bool `json:"is_split_transaction"` +} + +func summarizeOrdersForFetchLog(orders []providers.Order) []orderFetchSummary { + summaries := make([]orderFetchSummary, 0, len(orders)) + for _, order := range orders { + summary := orderFetchSummary{ + ID: order.GetID(), + Date: order.GetDate().Format("2006-01-02"), + Total: order.GetTotal(), + Subtotal: order.GetSubtotal(), + Tax: order.GetTax(), + Tip: order.GetTip(), + FeeTotal: order.GetFees(), + ItemCount: len(order.GetItems()), + } + if raw := order.GetRawData(); raw != nil { + if data, err := json.Marshal(raw); err == nil { + summary.RawOrderJSON = string(data) + } + } + summaries = append(summaries, summary) + } + return summaries +} + +func summarizeTransactionsForFetchLog(txns []*monarch.Transaction) []transactionFetchSummary { + summaries := make([]transactionFetchSummary, 0, len(txns)) + for _, tx := range txns { + summary := transactionFetchSummary{ + ID: tx.ID, + Date: tx.Date.Format("2006-01-02"), + Amount: tx.Amount, + PlaidName: tx.PlaidName, + Pending: tx.Pending, + HasSplits: tx.HasSplits, + IsSplitTransaction: tx.IsSplitTransaction, + } + if tx.Merchant != nil { + summary.MerchantName = tx.Merchant.Name + } + summaries = append(summaries, summary) + } + return summaries +} + +func (o *Orchestrator) logProviderFetch(fetchType string, request, response any, fetchErr error, duration time.Duration, orderCount, transactionCount int) { + if o.storage == nil { + return + } + requestJSON, _ := json.Marshal(request) + responseJSON, _ := json.Marshal(response) + errText := "" + if fetchErr != nil { + errText = fetchErr.Error() + } + if err := o.storage.LogProviderFetch(&storage.ProviderFetchLog{ + RunID: o.runID, + Provider: o.provider.DisplayName(), + FetchType: fetchType, + RequestJSON: string(requestJSON), + ResponseJSON: string(responseJSON), + Error: errText, + DurationMs: duration.Milliseconds(), + OrderCount: orderCount, + TransactionCount: transactionCount, + }); err != nil { + o.logger.Warn("Failed to log provider fetch", "fetch_type", fetchType, "error", err) + } +} diff --git a/internal/application/sync/orchestrator.go b/internal/application/sync/orchestrator.go index 9801e8e..c73d71c 100644 --- a/internal/application/sync/orchestrator.go +++ b/internal/application/sync/orchestrator.go @@ -107,46 +107,50 @@ func (o *Orchestrator) Run(ctx context.Context, opts Options) (*Result, error) { "force", opts.Force, ) - // 1. Fetch orders from provider + // 1. Start sync run tracking before external fetches so fetch logs are tied to a run. + if o.storage != nil { + var err error + o.runID, err = o.storage.StartSyncRun(o.provider.DisplayName(), opts.LookbackDays, opts.DryRun) + if err != nil { + o.logger.Warn("Failed to start sync run tracking", "error", err) + } + if o.consolidator != nil { + o.consolidator.SetRunID(o.runID) + } + if o.monarchAdapter != nil { + o.monarchAdapter.runID = o.runID + } + // Set up ledger storage for Walmart handler + if o.walmartHandler != nil { + o.walmartHandler.SetLedgerStorage(&ledgerStorageAdapter{repo: o.storage}, o.runID) + } + } + + // 2. Fetch orders from provider orders, err := o.fetchOrders(ctx, opts) if err != nil { + o.completeFailedRun(1) return nil, err } - // 2. Fetch Monarch transactions (if clients configured) + // 3. Fetch Monarch transactions (if clients configured) if o.clients == nil { return result, nil // Testing mode } providerTransactions, err := o.fetchMonarchTransactions(ctx, opts) if err != nil { + o.completeFailedRun(1) return nil, err } - // 3. Get Monarch categories + // 4. Get Monarch categories catCategories, monarchCategories, err := o.fetchCategories(ctx) if err != nil { + o.completeFailedRun(1) return nil, err } - // 4. Start sync run tracking - if o.storage != nil { - o.runID, err = o.storage.StartSyncRun(o.provider.DisplayName(), opts.LookbackDays, opts.DryRun) - if err != nil { - o.logger.Warn("Failed to start sync run tracking", "error", err) - } - if o.consolidator != nil { - o.consolidator.SetRunID(o.runID) - } - if o.monarchAdapter != nil { - o.monarchAdapter.runID = o.runID - } - // Set up ledger storage for Walmart handler - if o.walmartHandler != nil { - o.walmartHandler.SetLedgerStorage(&ledgerStorageAdapter{repo: o.storage}, o.runID) - } - } - // 5. Process orders usedTransactionIDs := make(map[string]bool) @@ -189,3 +193,12 @@ func (o *Orchestrator) Run(ctx context.Context, opts Options) (*Result, error) { return result, nil } + +func (o *Orchestrator) completeFailedRun(errorCount int) { + if o.storage == nil || o.runID <= 0 { + return + } + if err := o.storage.CompleteSyncRun(o.runID, 0, 0, 0, errorCount); err != nil { + o.logger.Warn("Failed to complete failed sync run tracking", "error", err) + } +} diff --git a/internal/application/sync/orchestrator_test.go b/internal/application/sync/orchestrator_test.go index 47a0191..944254c 100644 --- a/internal/application/sync/orchestrator_test.go +++ b/internal/application/sync/orchestrator_test.go @@ -8,10 +8,12 @@ import ( "testing" "time" - "github.com/eshaffer321/monarch-go/v2/pkg/monarch" "github.com/eshaffer321/itemize/internal/adapters/providers" + "github.com/eshaffer321/itemize/internal/infrastructure/storage" + "github.com/eshaffer321/monarch-go/v2/pkg/monarch" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/mock" + "github.com/stretchr/testify/require" ) // MockProvider implements providers.OrderProvider for testing @@ -464,3 +466,35 @@ func TestOrchestrator_fetchOrders(t *testing.T) { }) } } + +func TestOrchestrator_fetchOrders_LogsProviderFetch(t *testing.T) { + mockProvider := new(MockProvider) + mockProvider.On("DisplayName").Return("Costco") + mockProvider.On("FetchOrders", mock.Anything, mock.Anything).Return([]providers.Order{ + &mockSimpleOrder{ + id: "receipt-1", + date: time.Date(2026, 7, 7, 0, 0, 0, 0, time.UTC), + total: 12.34, + subtotal: 11.00, + tax: 1.34, + providerName: "Costco", + }, + }, nil) + + store := storage.NewMockRepository() + logger := slog.New(slog.NewTextHandler(os.Stderr, nil)) + orchestrator := NewOrchestrator(mockProvider, nil, store, logger) + orchestrator.runID = 77 + + orders, err := orchestrator.fetchOrders(context.Background(), Options{LookbackDays: 14}) + require.NoError(t, err) + require.Len(t, orders, 1) + + logs, err := store.GetProviderFetchesByRunID(77) + require.NoError(t, err) + require.Len(t, logs, 1) + assert.Equal(t, "Costco", logs[0].Provider) + assert.Equal(t, "orders", logs[0].FetchType) + assert.Equal(t, 1, logs[0].OrderCount) + assert.Contains(t, logs[0].ResponseJSON, "receipt-1") +} diff --git a/internal/application/sync/process_order_test.go b/internal/application/sync/process_order_test.go index 0aca508..b657035 100644 --- a/internal/application/sync/process_order_test.go +++ b/internal/application/sync/process_order_test.go @@ -183,6 +183,27 @@ func TestMonarchAdapter_LogAPICallIncludesOrderAndTransaction(t *testing.T) { assert.Contains(t, calls[0].RequestJSON, "split_count") } +func TestMonarchAdapter_LogAPICallRecordsIntentAndCompletion(t *testing.T) { + store := storage.NewMockRepository() + adapter := &monarchAdapter{ + storage: store, + runID: 99, + } + + ctx := withAuditContext(context.Background(), "ORDER-INTENT", false) + adapter.logAPICallIntent(ctx, "txn-intent", "Transactions.Update", map[string]any{"category": "groceries"}) + adapter.logAPICallCompletion(ctx, "txn-intent", "Transactions.Update", map[string]any{"id": "txn-intent"}, nil, 25*time.Millisecond) + + calls, err := store.GetAPICallsByOrderID("ORDER-INTENT") + require.NoError(t, err) + require.Len(t, calls, 2) + assert.Equal(t, "intent", calls[0].Phase) + assert.Equal(t, "completed", calls[1].Phase) + assert.Equal(t, "txn-intent", calls[0].TransactionID) + assert.Contains(t, calls[0].RequestJSON, "groceries") + assert.Contains(t, calls[1].ResponseJSON, "txn-intent") +} + // ============================================================================= // Test: Generic Order Matching (Costco-like providers) // ============================================================================= diff --git a/internal/application/sync/types.go b/internal/application/sync/types.go index 2bd92af..c1e7eb2 100644 --- a/internal/application/sync/types.go +++ b/internal/application/sync/types.go @@ -186,21 +186,35 @@ type monarchAdapter struct { } func (a *monarchAdapter) UpdateTransaction(ctx context.Context, id string, params *monarch.UpdateTransactionParams) error { + a.logAPICallIntent(ctx, id, "Transactions.Update", params) start := time.Now() updated, err := a.client.Transactions.Update(ctx, id, params) - a.logAPICall(ctx, id, "Transactions.Update", params, updated, err, time.Since(start)) + a.logAPICallCompletion(ctx, id, "Transactions.Update", updated, err, time.Since(start)) return err } func (a *monarchAdapter) UpdateSplits(ctx context.Context, id string, splits []*monarch.TransactionSplit) error { + a.logAPICallIntent(ctx, id, "Transactions.UpdateSplits", splits) start := time.Now() err := a.client.Transactions.UpdateSplits(ctx, id, splits) response := map[string]any{"ok": err == nil, "split_count": len(splits)} - a.logAPICall(ctx, id, "Transactions.UpdateSplits", splits, response, err, time.Since(start)) + a.logAPICallCompletion(ctx, id, "Transactions.UpdateSplits", response, err, time.Since(start)) return err } func (a *monarchAdapter) logAPICall(ctx context.Context, transactionID, method string, request, response any, callErr error, duration time.Duration) { + a.logAPICallPhase(ctx, transactionID, method, "completed", request, response, callErr, duration) +} + +func (a *monarchAdapter) logAPICallIntent(ctx context.Context, transactionID, method string, request any) { + a.logAPICallPhase(ctx, transactionID, method, "intent", request, nil, nil, 0) +} + +func (a *monarchAdapter) logAPICallCompletion(ctx context.Context, transactionID, method string, response any, callErr error, duration time.Duration) { + a.logAPICallPhase(ctx, transactionID, method, "completed", nil, response, callErr, duration) +} + +func (a *monarchAdapter) logAPICallPhase(ctx context.Context, transactionID, method, phase string, request, response any, callErr error, duration time.Duration) { if a == nil || a.storage == nil { return } @@ -216,6 +230,7 @@ func (a *monarchAdapter) logAPICall(ctx context.Context, transactionID, method s RunID: a.runID, OrderID: auditOrderID(ctx), TransactionID: transactionID, + Phase: phase, Method: method, RequestJSON: string(requestJSON), ResponseJSON: string(responseJSON), diff --git a/internal/infrastructure/storage/interfaces.go b/internal/infrastructure/storage/interfaces.go index 0c5c050..7669bd7 100644 --- a/internal/infrastructure/storage/interfaces.go +++ b/internal/infrastructure/storage/interfaces.go @@ -111,6 +111,12 @@ type APICallRepository interface { // GetAPICallsByRunID retrieves all API calls for a specific sync run GetAPICallsByRunID(runID int64) ([]APICall, error) + + // LogProviderFetch logs an external provider/Monarch fetch snapshot. + LogProviderFetch(fetch *ProviderFetchLog) error + + // GetProviderFetchesByRunID retrieves provider fetch logs for a sync run. + GetProviderFetchesByRunID(runID int64) ([]ProviderFetchLog, error) } // LedgerRepository handles order ledger storage and history diff --git a/internal/infrastructure/storage/migrations/00010_add_provider_fetch_logs.sql b/internal/infrastructure/storage/migrations/00010_add_provider_fetch_logs.sql new file mode 100644 index 0000000..0974829 --- /dev/null +++ b/internal/infrastructure/storage/migrations/00010_add_provider_fetch_logs.sql @@ -0,0 +1,41 @@ +-- +goose Up +-- Store provider fetch snapshots and distinguish API-call intent from completion. + +-- +goose StatementBegin +ALTER TABLE api_calls ADD COLUMN phase TEXT DEFAULT 'completed'; +-- +goose StatementEnd + +-- +goose StatementBegin +CREATE TABLE IF NOT EXISTS provider_fetches ( + id INTEGER PRIMARY KEY AUTOINCREMENT, + run_id INTEGER, + provider TEXT NOT NULL, + fetch_type TEXT NOT NULL, + request_json TEXT, + response_json TEXT, + error TEXT, + duration_ms INTEGER, + order_count INTEGER DEFAULT 0, + transaction_count INTEGER DEFAULT 0, + created_at TIMESTAMP DEFAULT CURRENT_TIMESTAMP, + FOREIGN KEY (run_id) REFERENCES sync_runs(id) +); +-- +goose StatementEnd + +-- +goose StatementBegin +CREATE INDEX IF NOT EXISTS idx_provider_fetches_run_id + ON provider_fetches(run_id); +-- +goose StatementEnd + +-- +goose StatementBegin +CREATE INDEX IF NOT EXISTS idx_provider_fetches_provider + ON provider_fetches(provider); +-- +goose StatementEnd + +-- +goose StatementBegin +CREATE INDEX IF NOT EXISTS idx_provider_fetches_created_at + ON provider_fetches(created_at DESC); +-- +goose StatementEnd + +-- +goose Down +-- SQLite cannot drop columns directly. Leave nullable columns/tables in place. diff --git a/internal/infrastructure/storage/migrations_test.go b/internal/infrastructure/storage/migrations_test.go index a6ca9a7..d37bc8e 100644 --- a/internal/infrastructure/storage/migrations_test.go +++ b/internal/infrastructure/storage/migrations_test.go @@ -14,7 +14,7 @@ import ( // expectedMigrationCount is the number of migrations we expect to have // Update this when adding new migrations // Note: goose adds a version 0 entry when initializing, so total count is migrations + 1 -const expectedMigrationCount = 9 +const expectedMigrationCount = 10 const gooseVersionCount = expectedMigrationCount + 1 // includes goose's version 0 entry // TestMigrations_FreshDatabase tests running migrations on a fresh database @@ -107,6 +107,12 @@ func TestMigrations_Schema(t *testing.T) { err = store.db.QueryRow("SELECT transaction_id, dry_run FROM api_calls LIMIT 0").Scan() assert.True(t, err == nil || err == sql.ErrNoRows, "api_calls mutation diagnostic columns should exist") + + err = store.db.QueryRow("SELECT phase FROM api_calls LIMIT 0").Scan() + assert.True(t, err == nil || err == sql.ErrNoRows, "api_calls.phase should exist") + + err = store.db.QueryRow("SELECT COUNT(*) FROM provider_fetches").Scan(new(int)) + assert.NoError(t, err, "provider_fetches table should exist") } // TestMigrations_ForeignKeyConstraints tests that foreign keys are enforced diff --git a/internal/infrastructure/storage/mock.go b/internal/infrastructure/storage/mock.go index 5447867..c6b69c9 100644 --- a/internal/infrastructure/storage/mock.go +++ b/internal/infrastructure/storage/mock.go @@ -3,16 +3,17 @@ package storage // MockRepository is an in-memory implementation of Repository for testing. // It stores all data in maps and slices, making tests fast and isolated. type MockRepository struct { - records map[string]*ProcessingRecord - attempts map[string][]ProcessingAttempt - orderTxns map[string][]OrderTransaction - syncRuns map[int64]*mockSyncRun - apiCalls []APICall - ledgers map[string][]*OrderLedger // Keyed by order_id - ledgerCharges map[int64][]LedgerCharge // Keyed by ledger_id - nextRunID int64 - nextLedgerID int64 - nextChargeID int64 + records map[string]*ProcessingRecord + attempts map[string][]ProcessingAttempt + orderTxns map[string][]OrderTransaction + syncRuns map[int64]*mockSyncRun + apiCalls []APICall + providerFetches []ProviderFetchLog + ledgers map[string][]*OrderLedger // Keyed by order_id + ledgerCharges map[int64][]LedgerCharge // Keyed by ledger_id + nextRunID int64 + nextLedgerID int64 + nextChargeID int64 // Hooks for test assertions SaveRecordCalled bool @@ -48,16 +49,17 @@ type mockSyncRun struct { // NewMockRepository creates a new mock repository for testing func NewMockRepository() *MockRepository { return &MockRepository{ - records: make(map[string]*ProcessingRecord), - attempts: make(map[string][]ProcessingAttempt), - orderTxns: make(map[string][]OrderTransaction), - syncRuns: make(map[int64]*mockSyncRun), - apiCalls: make([]APICall, 0), - ledgers: make(map[string][]*OrderLedger), - ledgerCharges: make(map[int64][]LedgerCharge), - nextRunID: 1, - nextLedgerID: 1, - nextChargeID: 1, + records: make(map[string]*ProcessingRecord), + attempts: make(map[string][]ProcessingAttempt), + orderTxns: make(map[string][]OrderTransaction), + syncRuns: make(map[int64]*mockSyncRun), + apiCalls: make([]APICall, 0), + providerFetches: make([]ProviderFetchLog, 0), + ledgers: make(map[string][]*OrderLedger), + ledgerCharges: make(map[int64][]LedgerCharge), + nextRunID: 1, + nextLedgerID: 1, + nextChargeID: 1, } } @@ -247,6 +249,26 @@ func (m *MockRepository) GetAPICallsByRunID(runID int64) ([]APICall, error) { return result, nil } +// LogProviderFetch logs a provider fetch snapshot. +func (m *MockRepository) LogProviderFetch(fetch *ProviderFetchLog) error { + if fetch == nil { + return nil + } + m.providerFetches = append(m.providerFetches, *fetch) + return nil +} + +// GetProviderFetchesByRunID retrieves provider fetch snapshots for a run. +func (m *MockRepository) GetProviderFetchesByRunID(runID int64) ([]ProviderFetchLog, error) { + var result []ProviderFetchLog + for _, fetch := range m.providerFetches { + if fetch.RunID == runID { + result = append(result, fetch) + } + } + return result, nil +} + // ListOrders returns orders matching the given filters with pagination func (m *MockRepository) ListOrders(filters OrderFilters) (*OrderListResult, error) { // Collect matching records @@ -436,6 +458,7 @@ func (m *MockRepository) Reset() { m.orderTxns = make(map[string][]OrderTransaction) m.syncRuns = make(map[int64]*mockSyncRun) m.apiCalls = make([]APICall, 0) + m.providerFetches = make([]ProviderFetchLog, 0) m.ledgers = make(map[string][]*OrderLedger) m.ledgerCharges = make(map[int64][]LedgerCharge) m.nextRunID = 1 diff --git a/internal/infrastructure/storage/models.go b/internal/infrastructure/storage/models.go index ad1674a..0c84cb8 100644 --- a/internal/infrastructure/storage/models.go +++ b/internal/infrastructure/storage/models.go @@ -147,6 +147,7 @@ type APICall struct { RunID int64 OrderID string TransactionID string + Phase string Method string RequestJSON string ResponseJSON string @@ -155,6 +156,21 @@ type APICall struct { DryRun bool } +// ProviderFetchLog captures a provider/Monarch fetch request and summarized response. +type ProviderFetchLog struct { + ID int64 `json:"id"` + RunID int64 `json:"run_id,omitempty"` + Provider string `json:"provider"` + FetchType string `json:"fetch_type"` + RequestJSON string `json:"request_json,omitempty"` + ResponseJSON string `json:"response_json,omitempty"` + Error string `json:"error,omitempty"` + DurationMs int64 `json:"duration_ms"` + OrderCount int `json:"order_count"` + TransactionCount int `json:"transaction_count"` + CreatedAt string `json:"created_at,omitempty"` +} + // LedgerState represents the current state of an order's ledger type LedgerState string diff --git a/internal/infrastructure/storage/sqlite.go b/internal/infrastructure/storage/sqlite.go index 12a98fb..8e0b808 100644 --- a/internal/infrastructure/storage/sqlite.go +++ b/internal/infrastructure/storage/sqlite.go @@ -713,10 +713,15 @@ func (s *Storage) CompleteSyncRun(runID int64, ordersFound, processed, skipped, func (s *Storage) LogAPICall(call *APICall) error { query := ` INSERT INTO api_calls - (run_id, order_id, method, request_json, response_json, error, duration_ms, transaction_id, dry_run) - VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?) + (run_id, order_id, method, request_json, response_json, error, duration_ms, transaction_id, dry_run, phase) + VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) ` + phase := call.Phase + if phase == "" { + phase = "completed" + } + _, err := s.db.Exec(query, call.RunID, call.OrderID, @@ -727,6 +732,7 @@ func (s *Storage) LogAPICall(call *APICall) error { call.DurationMs, nullString(call.TransactionID), call.DryRun, + phase, ) return err @@ -736,7 +742,7 @@ func (s *Storage) LogAPICall(call *APICall) error { func (s *Storage) GetAPICallsByOrderID(orderID string) ([]APICall, error) { query := ` SELECT run_id, order_id, method, request_json, response_json, error, duration_ms, timestamp, - transaction_id, dry_run + transaction_id, dry_run, phase FROM api_calls WHERE order_id = ? ORDER BY timestamp ASC @@ -764,6 +770,7 @@ func (s *Storage) GetAPICallsByOrderID(orderID string) ([]APICall, error) { ×tamp, &transactionID, &call.DryRun, + &call.Phase, ) if err != nil { return nil, err @@ -781,7 +788,7 @@ func (s *Storage) GetAPICallsByOrderID(orderID string) ([]APICall, error) { func (s *Storage) GetAPICallsByRunID(runID int64) ([]APICall, error) { query := ` SELECT run_id, order_id, method, request_json, response_json, error, duration_ms, timestamp, - transaction_id, dry_run + transaction_id, dry_run, phase FROM api_calls WHERE run_id = ? ORDER BY timestamp ASC @@ -809,6 +816,7 @@ func (s *Storage) GetAPICallsByRunID(runID int64) ([]APICall, error) { ×tamp, &transactionID, &call.DryRun, + &call.Phase, ) if err != nil { return nil, err @@ -822,6 +830,78 @@ func (s *Storage) GetAPICallsByRunID(runID int64) ([]APICall, error) { return calls, rows.Err() } +// LogProviderFetch logs an external provider/Monarch fetch snapshot. +func (s *Storage) LogProviderFetch(fetch *ProviderFetchLog) error { + if fetch == nil { + return nil + } + query := ` + INSERT INTO provider_fetches + (run_id, provider, fetch_type, request_json, response_json, error, duration_ms, order_count, transaction_count) + VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?) + ` + _, err := s.db.Exec(query, + nullInt64(fetch.RunID), + fetch.Provider, + fetch.FetchType, + nullString(fetch.RequestJSON), + nullString(fetch.ResponseJSON), + nullString(fetch.Error), + fetch.DurationMs, + fetch.OrderCount, + fetch.TransactionCount, + ) + return err +} + +// GetProviderFetchesByRunID retrieves provider fetch logs for a sync run. +func (s *Storage) GetProviderFetchesByRunID(runID int64) ([]ProviderFetchLog, error) { + query := ` + SELECT id, COALESCE(run_id, 0), provider, fetch_type, request_json, response_json, + error, duration_ms, order_count, transaction_count, created_at + FROM provider_fetches + WHERE run_id = ? + ORDER BY id ASC + ` + rows, err := s.db.Query(query, runID) + if err != nil { + return nil, err + } + defer func() { _ = rows.Close() }() + + var fetches []ProviderFetchLog + for rows.Next() { + var fetch ProviderFetchLog + var requestJSON, responseJSON, errorText sql.NullString + if err := rows.Scan( + &fetch.ID, + &fetch.RunID, + &fetch.Provider, + &fetch.FetchType, + &requestJSON, + &responseJSON, + &errorText, + &fetch.DurationMs, + &fetch.OrderCount, + &fetch.TransactionCount, + &fetch.CreatedAt, + ); err != nil { + return nil, err + } + if requestJSON.Valid { + fetch.RequestJSON = requestJSON.String + } + if responseJSON.Valid { + fetch.ResponseJSON = responseJSON.String + } + if errorText.Valid { + fetch.Error = errorText.String + } + fetches = append(fetches, fetch) + } + return fetches, rows.Err() +} + // ListOrders returns orders matching the given filters with pagination func (s *Storage) ListOrders(filters OrderFilters) (*OrderListResult, error) { // Set defaults diff --git a/internal/infrastructure/storage/storage_test.go b/internal/infrastructure/storage/storage_test.go index 3713535..ff71077 100644 --- a/internal/infrastructure/storage/storage_test.go +++ b/internal/infrastructure/storage/storage_test.go @@ -383,6 +383,38 @@ func TestStorage_OrderTransactions_MultipleRowsPerOrder(t *testing.T) { assert.Contains(t, txns[1].Notes, "CANTALOUPE") } +func TestStorage_ProviderFetchLog_RoundTrip(t *testing.T) { + tmpDB := createTempDB(t) + defer os.Remove(tmpDB) + + store, err := NewStorage(tmpDB) + require.NoError(t, err) + defer store.Close() + + runID, err := store.StartSyncRun("Costco", 14, false) + require.NoError(t, err) + + fetch := &ProviderFetchLog{ + RunID: runID, + Provider: "Costco", + FetchType: "orders", + RequestJSON: `{"lookback_days":14}`, + ResponseJSON: `[{"id":"receipt-1"}]`, + OrderCount: 1, + DurationMs: 250, + } + require.NoError(t, store.LogProviderFetch(fetch)) + + logs, err := store.GetProviderFetchesByRunID(runID) + require.NoError(t, err) + require.Len(t, logs, 1) + assert.Equal(t, "Costco", logs[0].Provider) + assert.Equal(t, "orders", logs[0].FetchType) + assert.Equal(t, `[{"id":"receipt-1"}]`, logs[0].ResponseJSON) + assert.Equal(t, 1, logs[0].OrderCount) + assert.Equal(t, int64(250), logs[0].DurationMs) +} + func TestStorage_IsProcessed(t *testing.T) { tmpDB := createTempDB(t) defer os.Remove(tmpDB) From fb5d7e64aad997dec4300956f14a603c1cf2f1bd Mon Sep 17 00:00:00 2001 From: Erick Shaffer Date: Tue, 7 Jul 2026 21:20:19 -0600 Subject: [PATCH 2/3] fix: satisfy audit logging lint --- internal/application/sync/process_order_test.go | 6 +++--- internal/application/sync/types.go | 4 ---- internal/infrastructure/storage/mock.go | 2 +- 3 files changed, 4 insertions(+), 8 deletions(-) diff --git a/internal/application/sync/process_order_test.go b/internal/application/sync/process_order_test.go index b657035..cdb29d9 100644 --- a/internal/application/sync/process_order_test.go +++ b/internal/application/sync/process_order_test.go @@ -164,8 +164,7 @@ func TestMonarchAdapter_LogAPICallIncludesOrderAndTransaction(t *testing.T) { } ctx := withAuditContext(context.Background(), "ORDER-AUDIT", false) - adapter.logAPICall(ctx, "txn-123", "Transactions.UpdateSplits", - map[string]any{"split_count": 2}, + adapter.logAPICallCompletion(ctx, "txn-123", "Transactions.UpdateSplits", map[string]any{"ok": true}, nil, 150*time.Millisecond, @@ -178,9 +177,10 @@ func TestMonarchAdapter_LogAPICallIncludesOrderAndTransaction(t *testing.T) { assert.Equal(t, "ORDER-AUDIT", calls[0].OrderID) assert.Equal(t, "txn-123", calls[0].TransactionID) assert.Equal(t, "Transactions.UpdateSplits", calls[0].Method) + assert.Equal(t, "completed", calls[0].Phase) assert.Equal(t, int64(150), calls[0].DurationMs) assert.False(t, calls[0].DryRun) - assert.Contains(t, calls[0].RequestJSON, "split_count") + assert.Contains(t, calls[0].ResponseJSON, "ok") } func TestMonarchAdapter_LogAPICallRecordsIntentAndCompletion(t *testing.T) { diff --git a/internal/application/sync/types.go b/internal/application/sync/types.go index c1e7eb2..23be552 100644 --- a/internal/application/sync/types.go +++ b/internal/application/sync/types.go @@ -202,10 +202,6 @@ func (a *monarchAdapter) UpdateSplits(ctx context.Context, id string, splits []* return err } -func (a *monarchAdapter) logAPICall(ctx context.Context, transactionID, method string, request, response any, callErr error, duration time.Duration) { - a.logAPICallPhase(ctx, transactionID, method, "completed", request, response, callErr, duration) -} - func (a *monarchAdapter) logAPICallIntent(ctx context.Context, transactionID, method string, request any) { a.logAPICallPhase(ctx, transactionID, method, "intent", request, nil, nil, 0) } diff --git a/internal/infrastructure/storage/mock.go b/internal/infrastructure/storage/mock.go index c6b69c9..e176bbe 100644 --- a/internal/infrastructure/storage/mock.go +++ b/internal/infrastructure/storage/mock.go @@ -431,8 +431,8 @@ func (m *MockRepository) GetSyncRun(runID int64) (*SyncRun, error) { // AddRecord adds a record directly (for test setup) func (m *MockRepository) AddRecord(record *ProcessingRecord) { - m.records[record.OrderID] = record if record != nil { + m.records[record.OrderID] = record m.attempts[record.OrderID] = append(m.attempts[record.OrderID], ProcessingAttempt{ProcessingRecord: *record}) } } From 9e9613271e5070e1331cc381b5c2bc47712288ce Mon Sep 17 00:00:00 2001 From: Erick Shaffer Date: Tue, 7 Jul 2026 21:22:35 -0600 Subject: [PATCH 3/3] chore: add local pre-commit hooks --- .githooks/pre-commit | 4 +++ Makefile | 65 +++++++++++++++++++++++++++++++++++++++---- README.md | 12 ++++++++ scripts/pre-commit.sh | 10 +++++++ 4 files changed, 86 insertions(+), 5 deletions(-) create mode 100755 .githooks/pre-commit create mode 100755 scripts/pre-commit.sh diff --git a/.githooks/pre-commit b/.githooks/pre-commit new file mode 100755 index 0000000..2c7dc39 --- /dev/null +++ b/.githooks/pre-commit @@ -0,0 +1,4 @@ +#!/usr/bin/env bash +set -euo pipefail + +exec scripts/pre-commit.sh diff --git a/Makefile b/Makefile index 34b6595..0277430 100644 --- a/Makefile +++ b/Makefile @@ -1,6 +1,7 @@ # Variables BINARY_NAME=itemize -GO_FILES=$(shell find . -name '*.go' -type f -not -path "./vendor/*") +GO_FILES=$(shell git ls-files '*.go') +STAGED_GO_FILES=$(shell git diff --cached --name-only --diff-filter=ACMR -- '*.go') COVERAGE_FILE=coverage.out COVERAGE_HTML=coverage.html @@ -19,7 +20,7 @@ GREEN=\033[0;32m YELLOW=\033[1;33m NC=\033[0m # No Color -.PHONY: all build clean test coverage fmt vet deps help install-tools pre-commit release version run-costco +.PHONY: all build clean test coverage fmt check-fmt check-fmt-staged lint vet deps help install-tools install-hooks pre-commit pre-commit-local release version run-costco ## help: Display this help message help: @@ -74,6 +75,45 @@ fmt: fi @echo "$(GREEN)Formatting complete!$(NC)" +## check-fmt: Verify Go files are gofmt-formatted +check-fmt: + @echo "$(GREEN)Checking Go formatting...$(NC)" + @unformatted="$$(gofmt -l $(GO_FILES))"; \ + if [ -n "$$unformatted" ]; then \ + echo "$(RED)Go files need formatting:$(NC)"; \ + echo "$$unformatted"; \ + echo "Run: make fmt"; \ + exit 1; \ + fi + @echo "$(GREEN)Formatting check passed!$(NC)" + +## check-fmt-staged: Verify staged Go files are gofmt-formatted +check-fmt-staged: + @echo "$(GREEN)Checking staged Go formatting...$(NC)" + @if [ -n "$(STAGED_GO_FILES)" ]; then \ + unformatted="$$(gofmt -l $(STAGED_GO_FILES))"; \ + if [ -n "$$unformatted" ]; then \ + echo "$(RED)Staged Go files need formatting:$(NC)"; \ + echo "$$unformatted"; \ + echo "Run: gofmt -w $$unformatted"; \ + exit 1; \ + fi; \ + else \ + echo "$(YELLOW)No staged Go files to check.$(NC)"; \ + fi + @echo "$(GREEN)Staged formatting check passed!$(NC)" + +## lint: Run golangci-lint using the repo config +lint: + @echo "$(GREEN)Running golangci-lint...$(NC)" + @if ! command -v golangci-lint >/dev/null 2>&1; then \ + echo "$(RED)golangci-lint is not installed.$(NC)"; \ + echo "Install v2.4.0+ or run: brew install golangci-lint"; \ + exit 1; \ + fi + golangci-lint run --timeout=5m + @echo "$(GREEN)Lint complete!$(NC)" + ## vet: Run go vet vet: @echo "$(GREEN)Running go vet...$(NC)" @@ -88,8 +128,14 @@ deps: $(GOMOD) tidy @echo "$(GREEN)Dependencies updated!$(NC)" -## pre-commit: Run pre-commit checks (fmt, vet, test) -pre-commit: fmt vet test +## pre-commit-local: Run local pre-commit checks without modifying files +pre-commit-local: check-fmt-staged lint vet + @echo "$(GREEN)Running tests...$(NC)" + $(GOTEST) ./... + @echo "$(GREEN)Pre-commit checks passed!$(NC)" + +## pre-commit: Run full pre-commit checks (format, lint, vet, race tests) +pre-commit: fmt lint vet test @echo "$(GREEN)Pre-commit checks passed!$(NC)" ## release: Build release binaries for multiple platforms @@ -116,11 +162,20 @@ run-costco: @echo "$(GREEN)Running Costco sync (dry-run)...$(NC)" $(GOCMD) run ./cmd/itemize costco -dry-run -verbose -## install-tools: Install development tools (goimports) +## install-hooks: Install versioned git hooks for this checkout +install-hooks: + @echo "$(GREEN)Installing git hooks...$(NC)" + @git config core.hooksPath .githooks + @chmod +x .githooks/pre-commit scripts/pre-commit.sh + @echo "$(GREEN)Git hooks installed. Use ITEMIZE_SKIP_PRECOMMIT=1 to bypass once.$(NC)" + +## install-tools: Install development tools (goimports, golangci-lint) install-tools: @echo "$(GREEN)Installing development tools...$(NC)" @echo "Installing goimports..." @go install golang.org/x/tools/cmd/goimports@latest + @echo "Installing golangci-lint..." + @go install github.com/golangci/golangci-lint/v2/cmd/golangci-lint@v2.4.0 @echo "$(GREEN)Tools installation complete!$(NC)" # Default target diff --git a/README.md b/README.md index 6ccbaf7..d60867d 100644 --- a/README.md +++ b/README.md @@ -46,6 +46,18 @@ cd itemize go build -o itemize ./cmd/itemize/ ``` +#### Contributor checks + +Install local tools and hooks before committing: + +```bash +make install-tools +make install-hooks +``` + +The pre-commit hook runs formatting checks, `golangci-lint`, `go vet`, and `go test ./...`. +To bypass once in an emergency, run `ITEMIZE_SKIP_PRECOMMIT=1 git commit ...`. + ### Configure Set environment variables: diff --git a/scripts/pre-commit.sh b/scripts/pre-commit.sh new file mode 100755 index 0000000..378b09b --- /dev/null +++ b/scripts/pre-commit.sh @@ -0,0 +1,10 @@ +#!/usr/bin/env bash +set -euo pipefail + +if [[ "${ITEMIZE_SKIP_PRECOMMIT:-}" == "1" ]]; then + echo "ITEMIZE_SKIP_PRECOMMIT=1 set; skipping local checks." + exit 0 +fi + +echo "Running itemize pre-commit checks..." +make pre-commit-local