feat: add cart/auth/stripe metrics and slog-based log-level counter

Adds Prometheus instrumentation across the checkout funnel, auth flow,
Stripe calls, rate limiters, and HTTP middleware (inflight gauge, request
and response sizes). Introduces a slog handler that counts log lines by
level so the dashboard can show error/warn rates; existing log.Printf
calls are routed through slog and counted as info.

Backs the new "terminalshop — Service Overview" Grafana dashboard.

Co-Authored-By: Claude Opus 4.7 <noreply@anthropic.com>
This commit is contained in:
2026-05-01 13:38:24 +02:00
parent 9e9a8325a8
commit 8ca209a4cc
7 changed files with 236 additions and 5 deletions

View File

@@ -4,6 +4,7 @@ import (
"encoding/json"
"net/http"
"terminalShop/api/middleware"
"terminalShop/pkg/auth"
"terminalShop/pkg/database"
"terminalShop/pkg/models"
@@ -46,18 +47,21 @@ func (h *AuthHandler) GetToken(w http.ResponseWriter, r *http.Request) {
var req TokenRequest
if err := json.NewDecoder(r.Body).Decode(&req); err != nil {
middleware.RecordAuthAttempt("invalid_json")
utils.RespondError(w, http.StatusBadRequest, "INVALID_JSON", "invalid request body", nil)
return
}
// validate shared secret
if req.ClientSecret != h.authFingerprintKey {
middleware.RecordAuthAttempt("invalid_secret")
utils.RespondError(w, http.StatusUnauthorized, "INVALID_SECRET", "invalid client secret", nil)
return
}
// Return if no fingerprint is found
if req.Fingerprint == "" {
middleware.RecordAuthAttempt("missing_fingerprint")
utils.RespondError(w, http.StatusBadRequest, "MISSING_FINGERPRINT", "fingerprint is required", nil)
return
}
@@ -67,6 +71,7 @@ func (h *AuthHandler) GetToken(w http.ResponseWriter, r *http.Request) {
err := db.Where("ssh_key_fingerprint = ?", req.Fingerprint).First(&user).Error
if err == gorm.ErrRecordNotFound {
if req.SSHPublicKey == "" {
middleware.RecordAuthAttempt("user_not_found")
utils.RespondError(w, http.StatusUnauthorized, "USER_NOT_FOUND", "no user found for this fingerprint", nil)
return
}
@@ -75,20 +80,25 @@ func (h *AuthHandler) GetToken(w http.ResponseWriter, r *http.Request) {
SSHPublicKey: req.SSHPublicKey,
}
if err := db.Create(&user).Error; err != nil {
middleware.RecordAuthAttempt("error")
utils.RespondError(w, http.StatusInternalServerError, "DATABASE_ERROR", "failed to create user", nil)
return
}
middleware.RecordAuthAttempt("registered")
} else if err != nil {
middleware.RecordAuthAttempt("error")
utils.RespondError(w, http.StatusInternalServerError, "DATABASE_ERROR", "failed to look up user", nil)
return
}
token, err := h.jwtManager.GenerateToken(user.ID, user.Email, user.Name)
if err != nil {
middleware.RecordAuthAttempt("error")
utils.RespondError(w, http.StatusInternalServerError, "TOKEN_ERROR", "failed to generate token", nil)
return
}
middleware.RecordAuthAttempt("success")
utils.RespondSuccess(w, http.StatusOK, map[string]interface{}{
"access_token": token,
"token_type": "Bearer",

View File

@@ -4,6 +4,7 @@ import (
"encoding/json"
"fmt"
"net/http"
"time"
"github.com/stripe/stripe-go/v78"
"github.com/stripe/stripe-go/v78/paymentintent"
@@ -251,6 +252,7 @@ func (h *CartHandler) ConvertCart(w http.ResponseWriter, r *http.Request) {
cart, err := getOrCreateCart(userID)
if err != nil {
middleware.RecordCartConversion("cart_lookup_failed")
utils.RespondError(w, http.StatusInternalServerError, "CART_ERROR", "failed to get cart", nil)
return
}
@@ -259,34 +261,40 @@ func (h *CartHandler) ConvertCart(w http.ResponseWriter, r *http.Request) {
db.Where("cart_id = ? AND quantity > 0", cart.ID).Preload("Coffee").Find(&items)
if len(items) == 0 {
middleware.RecordCartConversion("validation_empty_cart")
utils.RespondError(w, http.StatusBadRequest, "VALIDATION_ERROR", "cart is empty", nil)
return
}
if cart.AddressID == nil {
middleware.RecordCartConversion("validation_missing_address")
utils.RespondError(w, http.StatusBadRequest, "VALIDATION_ERROR", "shipping address is required", nil)
return
}
if cart.CardID == nil {
middleware.RecordCartConversion("validation_missing_card")
utils.RespondError(w, http.StatusBadRequest, "VALIDATION_ERROR", "payment card is required", nil)
return
}
var address models.Address
if err := db.First(&address, *cart.AddressID).Error; err != nil {
middleware.RecordCartConversion("validation_invalid_address")
utils.RespondError(w, http.StatusBadRequest, "INVALID_ADDRESS", "shipping address not found", nil)
return
}
var card models.Card
if err := db.First(&card, *cart.CardID).Error; err != nil {
middleware.RecordCartConversion("validation_invalid_card")
utils.RespondError(w, http.StatusBadRequest, "INVALID_CARD", "payment card not found", nil)
return
}
var user models.User
if err := db.First(&user, userID).Error; err != nil {
middleware.RecordCartConversion("user_not_found")
utils.RespondError(w, http.StatusNotFound, "USER_NOT_FOUND", "user not found", nil)
return
}
@@ -295,6 +303,7 @@ func (h *CartHandler) ConvertCart(w http.ResponseWriter, r *http.Request) {
// Ensure the user has a Stripe customer (shared helper with cards handler).
if err := ensureStripeCustomer(db, &user); err != nil {
middleware.RecordCartConversion("stripe_customer_failed")
utils.RespondError(w, http.StatusInternalServerError, "STRIPE_ERROR", "failed to create stripe customer", nil)
return
}
@@ -343,6 +352,7 @@ func (h *CartHandler) ConvertCart(w http.ResponseWriter, r *http.Request) {
total := subtotal + cart.ShippingCost
if total < 50 {
middleware.RecordCartConversion("validation_min_amount")
utils.RespondError(w, http.StatusBadRequest, "VALIDATION_ERROR", "order total must be at least $0.50", nil)
return
}
@@ -369,6 +379,7 @@ func (h *CartHandler) ConvertCart(w http.ResponseWriter, r *http.Request) {
}
if err := db.Create(&order).Error; err != nil {
middleware.RecordCartConversion("db_create_order_failed")
utils.RespondError(w, http.StatusInternalServerError, "DATABASE_ERROR", "failed to create order", nil)
return
}
@@ -405,27 +416,35 @@ func (h *CartHandler) ConvertCart(w http.ResponseWriter, r *http.Request) {
"order_id": fmt.Sprintf("%d", order.ID),
}
stripeStart := time.Now()
pi, err := paymentintent.New(piParams)
stripeDur := time.Since(stripeStart).Seconds()
if err != nil {
middleware.ObserveStripeRequest("payment_intent_create", "error", stripeDur)
db.Model(&order).Update("status", models.OrderStatusFailed)
if stripeErr, ok := err.(*stripe.Error); ok {
switch stripeErr.Type {
case stripe.ErrorTypeCard:
middleware.RecordCartConversion("card_declined")
audit.OrderFailed(userID, order.ID, total, stripeErr.Msg)
utils.RespondError(w, http.StatusPaymentRequired, "CARD_DECLINED", stripeErr.Msg, nil)
case stripe.ErrorTypeInvalidRequest:
middleware.RecordCartConversion("stripe_invalid_request")
audit.OrderFailed(userID, order.ID, total, stripeErr.Msg)
utils.RespondError(w, http.StatusBadRequest, "INVALID_PAYMENT", stripeErr.Msg, nil)
default:
middleware.RecordCartConversion("stripe_error")
audit.OrderFailed(userID, order.ID, total, stripeErr.Error())
utils.RespondError(w, http.StatusInternalServerError, "PAYMENT_FAILED", "payment failed", nil)
}
return
}
middleware.RecordCartConversion("stripe_error")
audit.OrderFailed(userID, order.ID, total, err.Error())
utils.RespondError(w, http.StatusInternalServerError, "PAYMENT_FAILED", "payment failed", nil)
return
}
middleware.ObserveStripeRequest("payment_intent_create", "success", stripeDur)
// Commit payment ID and clear cart in a single transaction.
txErr := db.Transaction(func(tx *gorm.DB) error {
@@ -447,6 +466,7 @@ func (h *CartHandler) ConvertCart(w http.ResponseWriter, r *http.Request) {
// most dangerous failure mode: the customer paid but has no order.
// The reconciliation job will catch this within 5 minutes.
// The audit log entry below must be treated as a critical alert.
middleware.RecordCartConversion("payment_critical")
audit.PaymentCritical(order.ID, pi.ID, txErr)
utils.RespondError(w, http.StatusInternalServerError, "DATABASE_ERROR", "payment succeeded but failed to record order — please contact support", nil)
return
@@ -454,6 +474,8 @@ func (h *CartHandler) ConvertCart(w http.ResponseWriter, r *http.Request) {
audit.OrderPaid(userID, order.ID, total, pi.ID)
middleware.RecordOrderCreated(string(order.Status))
middleware.RecordCartConversion("success")
middleware.ObserveOrderValueCents(total)
if err := db.Preload("Items").First(&order, order.ID).Error; err != nil {
utils.RespondError(w, http.StatusInternalServerError, "INTERNAL_ERROR", "failed to preload items", nil)

View File

@@ -11,6 +11,7 @@ import (
"time"
"terminalShop/api/handlers"
"terminalShop/api/middleware"
"terminalShop/api/routes"
"terminalShop/pkg/auth"
"terminalShop/pkg/config"
@@ -21,6 +22,9 @@ import (
const version = "v0.1.0"
func main() {
observability.InitLogger()
middleware.SetBuildInfo(version)
ctx, cancel := context.WithCancel(context.Background())
defer cancel()
// Load configuration

View File

@@ -8,14 +8,15 @@ import (
"go.opentelemetry.io/otel/trace"
)
// responseWriter wraps http.ResponseWriter to capture status code
// responseWriter wraps http.ResponseWriter to capture status code and response size.
type responseWriter struct {
http.ResponseWriter
statusCode int
statusCode int
bytesWritten int64
}
func newResponseWriter(w http.ResponseWriter) *responseWriter {
return &responseWriter{w, http.StatusOK}
return &responseWriter{ResponseWriter: w, statusCode: http.StatusOK}
}
func (rw *responseWriter) WriteHeader(code int) {
@@ -23,6 +24,12 @@ func (rw *responseWriter) WriteHeader(code int) {
rw.ResponseWriter.WriteHeader(code)
}
func (rw *responseWriter) Write(b []byte) (int, error) {
n, err := rw.ResponseWriter.Write(b)
rw.bytesWritten += int64(n)
return n, err
}
// Logger logs HTTP requests
func Logger(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {

View File

@@ -29,6 +29,31 @@ var (
[]string{"method", "route"},
)
httpInflightRequests = promauto.NewGauge(
prometheus.GaugeOpts{
Name: "http_inflight_requests",
Help: "Number of HTTP requests currently being handled",
},
)
httpRequestSize = promauto.NewHistogramVec(
prometheus.HistogramOpts{
Name: "http_request_size_bytes",
Help: "HTTP request body size in bytes",
Buckets: prometheus.ExponentialBuckets(64, 4, 8),
},
[]string{"method", "route"},
)
httpResponseSize = promauto.NewHistogramVec(
prometheus.HistogramOpts{
Name: "http_response_size_bytes",
Help: "HTTP response body size in bytes",
Buckets: prometheus.ExponentialBuckets(64, 4, 8),
},
[]string{"method", "route"},
)
ordersCreatedTotal = promauto.NewCounterVec(
prometheus.CounterOpts{
Name: "orders_created_total",
@@ -36,14 +61,74 @@ var (
},
[]string{"status"},
)
cartConversionTotal = promauto.NewCounterVec(
prometheus.CounterOpts{
Name: "cart_conversion_total",
Help: "Cart checkout outcomes (success, validation_failed, card_declined, stripe_failed, db_failed, payment_critical)",
},
[]string{"outcome"},
)
orderValueDollars = promauto.NewHistogram(
prometheus.HistogramOpts{
Name: "order_value_dollars",
Help: "Distribution of completed order totals, in dollars",
Buckets: []float64{1, 5, 10, 20, 30, 50, 75, 100, 150, 250, 500, 1000},
},
)
stripeRequestDuration = promauto.NewHistogramVec(
prometheus.HistogramOpts{
Name: "stripe_request_duration_seconds",
Help: "Latency of outbound Stripe API calls",
Buckets: prometheus.DefBuckets,
},
[]string{"op", "outcome"},
)
authAttemptsTotal = promauto.NewCounterVec(
prometheus.CounterOpts{
Name: "auth_attempts_total",
Help: "Authentication attempts, by result (success, invalid_secret, missing_fingerprint, user_not_found, registered, error)",
},
[]string{"result"},
)
rateLimitRejectionsTotal = promauto.NewCounterVec(
prometheus.CounterOpts{
Name: "rate_limit_rejections_total",
Help: "Number of requests rejected by rate limiters",
},
[]string{"scope"},
)
logMessagesTotal = promauto.NewCounterVec(
prometheus.CounterOpts{
Name: "log_messages_total",
Help: "Total log lines emitted, labeled by level",
},
[]string{"level"},
)
buildInfo = promauto.NewGaugeVec(
prometheus.GaugeOpts{
Name: "terminalshop_build_info",
Help: "Build metadata; value is always 1, version is on the label",
},
[]string{"version"},
)
)
// Metrics records request count and latency for every request
// Metrics records request count, latency, sizes, and concurrency for every request.
func Metrics(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
start := time.Now()
wrapped := newResponseWriter(w)
httpInflightRequests.Inc()
defer httpInflightRequests.Dec()
next.ServeHTTP(wrapped, r)
route := chi.RouteContext(r.Context()).RoutePattern()
@@ -56,15 +141,54 @@ func Metrics(next http.Handler) http.Handler {
httpRequestsTotal.WithLabelValues(r.Method, route, status).Inc()
httpRequestDuration.WithLabelValues(r.Method, route).Observe(duration)
if r.ContentLength > 0 {
httpRequestSize.WithLabelValues(r.Method, route).Observe(float64(r.ContentLength))
}
httpResponseSize.WithLabelValues(r.Method, route).Observe(float64(wrapped.bytesWritten))
})
}
// MetricsHandler returns the Prometheus scrape endpoint
// MetricsHandler returns the Prometheus scrape endpoint.
func MetricsHandler() http.Handler {
return promhttp.Handler()
}
// SetBuildInfo records build metadata as a gauge of value 1.
func SetBuildInfo(version string) {
buildInfo.WithLabelValues(version).Set(1)
}
// RecordOrderCreated records a successfully created order.
func RecordOrderCreated(status string) {
ordersCreatedTotal.WithLabelValues(status).Inc()
}
// RecordCartConversion records the outcome of a checkout attempt.
func RecordCartConversion(outcome string) {
cartConversionTotal.WithLabelValues(outcome).Inc()
}
// ObserveOrderValueCents records the value of a completed order (cents → dollars).
func ObserveOrderValueCents(cents int) {
orderValueDollars.Observe(float64(cents) / 100.0)
}
// ObserveStripeRequest records latency of a Stripe API call.
func ObserveStripeRequest(op, outcome string, durSec float64) {
stripeRequestDuration.WithLabelValues(op, outcome).Observe(durSec)
}
// RecordAuthAttempt records an authentication attempt outcome.
func RecordAuthAttempt(result string) {
authAttemptsTotal.WithLabelValues(result).Inc()
}
// RecordRateLimitRejection records a request blocked by a rate limiter.
func RecordRateLimitRejection(scope string) {
rateLimitRejectionsTotal.WithLabelValues(scope).Inc()
}
// RecordLogLevel increments the per-level log counter.
func RecordLogLevel(level string) {
logMessagesTotal.WithLabelValues(level).Inc()
}

View File

@@ -16,6 +16,7 @@ func RateLimitByIP(limit int, window time.Duration) func(http.Handler) http.Hand
limit, window,
httprate.WithKeyFuncs(httprate.KeyByIP),
httprate.WithLimitHandler(func(w http.ResponseWriter, r *http.Request) {
RecordRateLimitRejection("ip")
utils.RespondError(w, http.StatusTooManyRequests, "RATE_LIMITED", "too many requests", nil)
}),
)
@@ -34,6 +35,7 @@ func RateLimitByUser(limit int, window time.Duration) func(http.Handler) http.Ha
return "user:" + strconv.FormatUint(uint64(userID), 10), nil
}),
httprate.WithLimitHandler(func(w http.ResponseWriter, r *http.Request) {
RecordRateLimitRejection("user")
utils.RespondError(w, http.StatusTooManyRequests, "RATE_LIMITED", "too many requests", nil)
}),
)

View File

@@ -0,0 +1,62 @@
package observability
import (
"context"
"log"
"log/slog"
"os"
"strings"
"terminalShop/api/middleware"
)
// countingHandler wraps a slog.Handler and increments the log_messages_total
// counter for every record before delegating to the inner handler. This is
// what gives the dashboard a per-level log rate without forcing call sites
// to thread metrics manually.
type countingHandler struct {
inner slog.Handler
}
func (h *countingHandler) Enabled(ctx context.Context, l slog.Level) bool {
return h.inner.Enabled(ctx, l)
}
func (h *countingHandler) Handle(ctx context.Context, r slog.Record) error {
middleware.RecordLogLevel(strings.ToLower(r.Level.String()))
return h.inner.Handle(ctx, r)
}
func (h *countingHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
return &countingHandler{inner: h.inner.WithAttrs(attrs)}
}
func (h *countingHandler) WithGroup(name string) slog.Handler {
return &countingHandler{inner: h.inner.WithGroup(name)}
}
// InitLogger installs a slog-based default logger with a level-counting wrapper
// and bridges the stdlib `log` package through slog so existing log.Printf
// calls are also counted (as INFO).
func InitLogger() {
level := slog.LevelInfo
if env := strings.ToLower(os.Getenv("LOG_LEVEL")); env != "" {
switch env {
case "debug":
level = slog.LevelDebug
case "warn", "warning":
level = slog.LevelWarn
case "error":
level = slog.LevelError
}
}
base := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: level})
handler := &countingHandler{inner: base}
slog.SetDefault(slog.New(handler))
// Route the stdlib log package through slog at INFO so legacy log.Printf
// calls show up in structured output and bump the counter.
slog.SetLogLoggerLevel(slog.LevelInfo)
log.SetFlags(0)
}