From e17600db2816b06a86c1dbdc369d337a4a51c80d Mon Sep 17 00:00:00 2001 From: Evan Jarrett Date: Sat, 25 Oct 2025 11:00:48 -0500 Subject: [PATCH] slog and refactor config in appview --- .env.appview.example | 2 +- .env.hold.example | 10 + cmd/appview/serve.go | 253 +++--- deploy/.env.prod.template | 2 +- deploy/docker-compose.prod.yml | 4 + docker-compose.yml | 4 +- pkg/appview/config.go | 485 +++++------ pkg/appview/config_test.go | 1371 +------------------------------- pkg/hold/oci/http_helpers.go | 3 +- pkg/hold/oci/multipart.go | 80 +- pkg/hold/oci/xrpc.go | 5 +- pkg/hold/pds/auth.go | 6 +- pkg/hold/pds/captain.go | 5 +- pkg/hold/pds/events.go | 64 +- pkg/hold/pds/keys.go | 7 +- pkg/hold/pds/manifest_post.go | 5 +- pkg/hold/pds/profile.go | 17 +- pkg/hold/pds/server.go | 25 +- pkg/hold/pds/status.go | 9 +- pkg/hold/pds/xrpc.go | 83 +- 20 files changed, 565 insertions(+), 1875 deletions(-) diff --git a/.env.appview.example b/.env.appview.example index 171b883..6de686a 100644 --- a/.env.appview.example +++ b/.env.appview.example @@ -66,7 +66,7 @@ ATCR_UI_ENABLED=true # ============================================================================== # Log level: debug, info, warn, error (default: info) -# ATCR_LOG_LEVEL=info +ATCR_LOG_LEVEL=debug # Log formatter: text, json (default: text) # ATCR_LOG_FORMATTER=text diff --git a/.env.hold.example b/.env.hold.example index ecc1e40..a282e79 100644 --- a/.env.hold.example +++ b/.env.hold.example @@ -110,3 +110,13 @@ HOLD_DATABASE_DIR=/var/lib/atcr-hold # - Skips OAuth if records exist # HOLD_OWNER=did:plc:your-did-here + +# ============================================================================== +# Logging Configuration +# ============================================================================== + +# Log level: debug, info, warn, error (default: info) +ATCR_LOG_LEVEL=debug + +# Log formatter: text, json (default: text) +# ATCR_LOG_FORMATTER=text diff --git a/cmd/appview/serve.go b/cmd/appview/serve.go index cd21dcc..97d13a8 100644 --- a/cmd/appview/serve.go +++ b/cmd/appview/serve.go @@ -6,6 +6,7 @@ import ( "encoding/json" "fmt" "html/template" + "log/slog" "net/http" "os" "os/signal" @@ -14,7 +15,6 @@ import ( "time" "github.com/bluesky-social/indigo/atproto/syntax" - "github.com/distribution/distribution/v3/configuration" "github.com/distribution/distribution/v3/registry" "github.com/distribution/distribution/v3/registry/handlers" "github.com/spf13/cobra" @@ -59,74 +59,62 @@ func init() { } func serveRegistry(cmd *cobra.Command, args []string) error { - // Initialize structured logging - logging.InitLogger(appview.GetLogLevel()) - // Load configuration from environment variables - fmt.Println("Loading configuration from environment variables...") - config, err := appview.LoadConfigFromEnv() + cfg, err := appview.LoadConfigFromEnv() if err != nil { return fmt.Errorf("failed to load config from environment: %w", err) } - fmt.Println("Configuration loaded successfully from environment") + + // Initialize structured logging + logging.InitLogger(cfg.LogLevel) + + slog.Info("Configuration loaded successfully from environment") // Initialize UI database first (required for all stores) - fmt.Println("Initializing UI database...") - uiEnabled := appview.GetUIEnabled() - dbPath := appview.GetUIDatabasePath() - uiDatabase, uiReadOnlyDB, uiSessionStore := db.InitializeDatabase(uiEnabled, dbPath) + slog.Info("Initializing UI database", "path", cfg.UI.DatabasePath) + uiDatabase, uiReadOnlyDB, uiSessionStore := db.InitializeDatabase(cfg.UI.Enabled, cfg.UI.DatabasePath) if uiDatabase == nil { return fmt.Errorf("failed to initialize UI database - required for session storage") } // Initialize hold health checker - fmt.Println("Initializing hold health checker...") - cacheTTL := appview.GetHealthCacheTTL() - healthChecker := holdhealth.NewChecker(cacheTTL) + slog.Info("Initializing hold health checker", "cache_ttl", cfg.Health.CacheTTL) + healthChecker := holdhealth.NewChecker(cfg.Health.CacheTTL) // Initialize README cache - fmt.Println("Initializing README cache...") - readmeCacheTTL := appview.GetReadmeCacheTTL() - readmeCache := readme.NewCache(uiDatabase, readmeCacheTTL) + slog.Info("Initializing README cache", "cache_ttl", cfg.Health.ReadmeCacheTTL) + readmeCache := readme.NewCache(uiDatabase, cfg.Health.ReadmeCacheTTL) // Start background health check worker - refreshInterval := appview.GetHealthCheckInterval() startupDelay := 5 * time.Second // Wait for hold services to start (Docker compose) dbAdapter := holdhealth.NewDBAdapter(uiDatabase) - healthWorker := holdhealth.NewWorkerWithStartupDelay(healthChecker, dbAdapter, refreshInterval, startupDelay) + healthWorker := holdhealth.NewWorkerWithStartupDelay(healthChecker, dbAdapter, cfg.Health.CheckInterval, startupDelay) // Create context for worker lifecycle management workerCtx, workerCancel := context.WithCancel(context.Background()) defer workerCancel() // Ensure context is cancelled on all exit paths healthWorker.Start(workerCtx) - fmt.Printf("Hold health worker started (5s startup delay, %s refresh interval, %s cache TTL)\n", refreshInterval, cacheTTL) + slog.Info("Hold health worker started", "startup_delay", startupDelay, "refresh_interval", cfg.Health.CheckInterval, "cache_ttl", cfg.Health.CacheTTL) // Initialize OAuth components - fmt.Println("Initializing OAuth components...") + slog.Info("Initializing OAuth components") // Create OAuth session storage (SQLite-backed) oauthStore := db.NewOAuthStore(uiDatabase) - fmt.Println("Using SQLite for OAuth session storage") + slog.Info("Using SQLite for OAuth session storage") // Create device store (SQLite-backed) deviceStore := db.NewDeviceStore(uiDatabase) - fmt.Println("Using SQLite for device storage") + slog.Info("Using SQLite for device storage") - // Get base URL from config or environment - baseURL := appview.GetBaseURL(config.HTTP.Addr) - fmt.Printf("DEBUG: Base URL for OAuth: %s\n", baseURL) + // Get base URL and default hold DID from config + baseURL := cfg.Server.BaseURL + defaultHoldDID := cfg.Server.DefaultHoldDID + testMode := cfg.Server.TestMode - // Extract default hold DID for OAuth server and backfill worker - // This is used to create sailor profiles on first login and cache captain records - // Expected format: "did:web:hold01.atcr.io" - // To find a hold's DID, visit: https://hold01.atcr.io/.well-known/did.json - // The extraction function normalizes URLs to DIDs for consistency - defaultHoldDID := appview.ExtractDefaultHoldDID(config) - - // Extract test mode from config (needed for OAuth scope configuration) - testMode := appview.ExtractTestMode(config) + slog.Debug("Base URL for OAuth", "base_url", baseURL) if testMode { - fmt.Println("TEST_MODE enabled - will use HTTP for local DID resolution and transition:generic scope") + slog.Info("TEST_MODE enabled - will use HTTP for local DID resolution and transition:generic scope") } // Create OAuth app (indigo client) @@ -135,9 +123,9 @@ func serveRegistry(cmd *cobra.Command, args []string) error { return fmt.Errorf("failed to create OAuth app: %w", err) } if testMode { - fmt.Println("Using OAuth scopes with transition:generic (test mode)") + slog.Info("Using OAuth scopes with transition:generic (test mode)") } else { - fmt.Println("Using OAuth scopes with RPC scope (production mode)") + slog.Info("Using OAuth scopes with RPC scope (production mode)") } // Invalidate sessions with mismatched scopes on startup @@ -145,9 +133,9 @@ func serveRegistry(cmd *cobra.Command, args []string) error { desiredScopes := oauth.GetDefaultScopes(defaultHoldDID, testMode) invalidatedCount, err := oauthStore.InvalidateSessionsWithMismatchedScopes(context.Background(), desiredScopes) if err != nil { - fmt.Printf("Warning: Failed to invalidate sessions with mismatched scopes: %v\n", err) + slog.Warn("Failed to invalidate sessions with mismatched scopes", "error", err) } else if invalidatedCount > 0 { - fmt.Printf("Invalidated %d OAuth session(s) due to scope changes\n", invalidatedCount) + slog.Info("Invalidated OAuth sessions due to scope changes", "count", invalidatedCount) } // Create oauth token refresher @@ -168,14 +156,17 @@ func serveRegistry(cmd *cobra.Command, args []string) error { // Create RemoteHoldAuthorizer for hold authorization with caching holdAuthorizer := auth.NewRemoteHoldAuthorizer(uiDatabase, testMode) middleware.SetGlobalAuthorizer(holdAuthorizer) - fmt.Println("Hold authorizer initialized with database caching") + slog.Info("Hold authorizer initialized with database caching") // Set global readme cache for middleware middleware.SetGlobalReadmeCache(readmeCache) - fmt.Println("README cache initialized for manifest push refresh") + slog.Info("README cache initialized for manifest push refresh") + + // Initialize Jetstream workers (background services before HTTP routes) + initializeJetstream(uiDatabase, &cfg.Jetstream, defaultHoldDID, testMode) // Initialize UI routes with OAuth app, refresher, device store, health checker, and readme cache - uiTemplates, uiRouter := initializeUIRoutes(uiDatabase, uiReadOnlyDB, uiSessionStore, oauthApp, oauthStore, refresher, baseURL, deviceStore, defaultHoldDID, healthChecker, readmeCache) + uiTemplates, uiRouter := initializeUIRoutes(cfg.UI.Enabled, uiDatabase, uiReadOnlyDB, uiSessionStore, oauthApp, oauthStore, refresher, baseURL, deviceStore, healthChecker, readmeCache) // Create OAuth server oauthServer := oauth.NewServer(oauthApp) @@ -189,19 +180,19 @@ func serveRegistry(cmd *cobra.Command, args []string) error { // Register OAuth post-auth callback for AppView business logic // This decouples the OAuth package from AppView-specific dependencies oauthServer.SetPostAuthCallback(func(ctx context.Context, did, handle, pdsEndpoint, sessionID string) error { - fmt.Printf("DEBUG [appview/callback]: OAuth post-auth callback for DID=%s\n", did) + slog.Debug("OAuth post-auth callback", "component", "appview/callback", "did", did) // Parse DID for session resume didParsed, err := syntax.ParseDID(did) if err != nil { - fmt.Printf("WARNING [appview/callback]: Failed to parse DID %s: %v\n", did, err) + slog.Warn("Failed to parse DID", "component", "appview/callback", "did", did, "error", err) return nil // Non-fatal } // Resume OAuth session to get authenticated client session, err := oauthApp.ResumeSession(ctx, didParsed, sessionID) if err != nil { - fmt.Printf("WARNING [appview/callback]: Failed to resume session for DID=%s: %v\n", did, err) + slog.Warn("Failed to resume session", "component", "appview/callback", "did", did, "error", err) // Fallback: update user without avatar _ = db.UpsertUser(uiDatabase, &db.User{ DID: did, @@ -217,18 +208,18 @@ func serveRegistry(cmd *cobra.Command, args []string) error { client := atproto.NewClientWithIndigoClient(pdsEndpoint, did, session.APIClient()) // Ensure sailor profile exists (creates with default hold if configured) - fmt.Printf("DEBUG [appview/callback]: Ensuring profile exists for %s (defaultHold=%s)\n", did, defaultHoldDID) + slog.Debug("Ensuring profile exists", "component", "appview/callback", "did", did, "default_hold_did", defaultHoldDID) if err := storage.EnsureProfile(ctx, client, defaultHoldDID); err != nil { - fmt.Printf("WARNING [appview/callback]: Failed to ensure profile for %s: %v\n", did, err) + slog.Warn("Failed to ensure profile", "component", "appview/callback", "did", did, "error", err) // Continue anyway - profile creation is not critical for avatar fetch } else { - fmt.Printf("DEBUG [appview/callback]: Profile ensured for %s\n", did) + slog.Debug("Profile ensured", "component", "appview/callback", "did", did) } // Fetch user's profile record from PDS (contains blob references) profileRecord, err := client.GetProfileRecord(ctx, did) if err != nil { - fmt.Printf("WARNING [appview/callback]: Failed to fetch profile record for DID=%s: %v\n", did, err) + slog.Warn("Failed to fetch profile record", "component", "appview/callback", "did", did, "error", err) // Still update user without avatar _ = db.UpsertUser(uiDatabase, &db.User{ DID: did, @@ -244,7 +235,7 @@ func serveRegistry(cmd *cobra.Command, args []string) error { var avatarURL string if profileRecord.Avatar != nil && profileRecord.Avatar.Ref.Link != "" { avatarURL = atproto.BlobCDNURL(did, profileRecord.Avatar.Ref.Link) - fmt.Printf("DEBUG [appview/callback]: Constructed avatar URL: %s\n", avatarURL) + slog.Debug("Constructed avatar URL", "component", "appview/callback", "avatar_url", avatarURL) } // Store user with avatar in database @@ -256,16 +247,16 @@ func serveRegistry(cmd *cobra.Command, args []string) error { LastSeen: time.Now(), }) if err != nil { - fmt.Printf("WARNING [appview/callback]: Failed to store user in database: %v\n", err) + slog.Warn("Failed to store user in database", "component", "appview/callback", "error", err) return nil // Non-fatal } - fmt.Printf("DEBUG [appview/callback]: Stored user with avatar for DID=%s\n", did) + slog.Debug("Stored user with avatar", "component", "appview/callback", "did", did) // Migrate profile URL→DID if needed profile, err := storage.GetProfile(ctx, client) if err != nil { - fmt.Printf("WARNING [appview/callback]: Failed to get profile for %s: %v\n", did, err) + slog.Warn("Failed to get profile", "component", "appview/callback", "did", did, "error", err) return nil // Non-fatal } @@ -273,7 +264,7 @@ func serveRegistry(cmd *cobra.Command, args []string) error { if profile != nil && profile.DefaultHold != "" { // Check if defaultHold is a URL (needs migration) if strings.HasPrefix(profile.DefaultHold, "http://") || strings.HasPrefix(profile.DefaultHold, "https://") { - fmt.Printf("DEBUG [appview/callback]: Migrating hold URL to DID for %s: %s\n", did, profile.DefaultHold) + slog.Debug("Migrating hold URL to DID", "component", "appview/callback", "did", did, "hold_url", profile.DefaultHold) // Resolve URL to DID holdDID := atproto.ResolveHoldDIDFromURL(profile.DefaultHold) @@ -281,18 +272,18 @@ func serveRegistry(cmd *cobra.Command, args []string) error { // Update profile with DID profile.DefaultHold = holdDID if err := storage.UpdateProfile(ctx, client, profile); err != nil { - fmt.Printf("WARNING [appview/callback]: Failed to update profile with hold DID for %s: %v\n", did, err) + slog.Warn("Failed to update profile with hold DID", "component", "appview/callback", "did", did, "error", err) } else { - fmt.Printf("DEBUG [appview/callback]: Updated profile with hold DID: %s\n", holdDID) + slog.Debug("Updated profile with hold DID", "component", "appview/callback", "hold_did", holdDID) } - fmt.Printf("DEBUG [oauth/server]: Attempting crew registration for %s at hold %s\n", did, holdDID) + slog.Debug("Attempting crew registration", "component", "oauth/server", "did", did, "hold_did", holdDID) storage.EnsureCrewMembership(ctx, client, refresher, holdDID) } else { // Already a DID - use it holdDID = profile.DefaultHold } // Register crew regardless of migration (outside the migration block) - fmt.Printf("DEBUG [appview/callback]: Attempting crew registration for %s at hold %s\n", did, holdDID) + slog.Debug("Attempting crew registration", "component", "appview/callback", "did", did, "hold_did", holdDID) storage.EnsureCrewMembership(ctx, client, refresher, holdDID) } @@ -300,23 +291,21 @@ func serveRegistry(cmd *cobra.Command, args []string) error { return nil // All errors are non-fatal, logged for debugging }) - // Initialize auth keys and create token issuer + // Create token issuer (also initializes auth keys if needed) var issuer *token.Issuer - if config.Auth["token"] != nil { - if err := initializeAuthKeys(config); err != nil { - return fmt.Errorf("failed to initialize auth keys: %w", err) - } - - // Create token issuer for auth handlers - issuer, err = createTokenIssuer(config) + if cfg.Distribution.Auth["token"] != nil { + issuer, err = createTokenIssuer(cfg) if err != nil { return fmt.Errorf("failed to create token issuer: %w", err) } + + // Log successful initialization + slog.Info("Auth keys initialized", "path", cfg.Auth.KeyPath) } // Create registry app (returns http.Handler) ctx := context.Background() - app := handlers.NewApp(ctx, config) + app := handlers.NewApp(ctx, cfg.Distribution) // Create main HTTP mux mux := http.NewServeMux() @@ -332,9 +321,7 @@ func serveRegistry(cmd *cobra.Command, args []string) error { // Mount UI routes directly at root level mux.Handle("/", uiRouter) - fmt.Printf("UI enabled:\n") - fmt.Printf(" - Home: /\n") - fmt.Printf(" - Settings: /settings\n") + slog.Info("UI enabled", "home", "/", "settings", "/settings") } // Mount OAuth endpoints @@ -363,7 +350,7 @@ func serveRegistry(cmd *cobra.Command, args []string) error { // Register token post-auth callback for profile management // This decouples the token package from AppView-specific dependencies tokenHandler.SetPostAuthCallback(func(ctx context.Context, did, handle, pdsEndpoint, accessToken string) error { - fmt.Printf("DEBUG [appview/callback]: Token post-auth callback for DID=%s\n", did) + slog.Debug("Token post-auth callback", "component", "appview/callback", "did", did) // Create ATProto client with validated token atprotoClient := atproto.NewClient(pdsEndpoint, did, accessToken) @@ -371,9 +358,9 @@ func serveRegistry(cmd *cobra.Command, args []string) error { // Ensure profile exists (will create with default hold if not exists and default is configured) if err := storage.EnsureProfile(ctx, atprotoClient, defaultHoldDID); err != nil { // Log error but don't fail auth - profile management is not critical - fmt.Printf("WARNING [appview/callback]: Failed to ensure profile for %s: %v\n", did, err) + slog.Warn("Failed to ensure profile", "component", "appview/callback", "did", did, "error", err) } else { - fmt.Printf("DEBUG [appview/callback]: Profile ensured for %s with default hold %s\n", did, defaultHoldDID) + slog.Debug("Profile ensured with default hold", "component", "appview/callback", "did", did, "default_hold_did", defaultHoldDID) } return nil // All errors are non-fatal @@ -390,18 +377,18 @@ func serveRegistry(cmd *cobra.Command, args []string) error { Store: deviceStore, }) - fmt.Printf("Auth endpoints enabled:\n") - fmt.Printf(" - Basic Auth: /auth/token (device secrets + app passwords)\n") - fmt.Printf(" - Device Auth: /auth/device/code\n") - fmt.Printf(" - Device Auth: /auth/device/token\n") - fmt.Printf(" - OAuth: /auth/oauth/authorize\n") - fmt.Printf(" - OAuth: /auth/oauth/callback\n") - fmt.Printf(" - OAuth Meta: /client-metadata.json\n") + slog.Info("Auth endpoints enabled", + "basic_auth", "/auth/token", + "device_code", "/auth/device/code", + "device_token", "/auth/device/token", + "oauth_authorize", "/auth/oauth/authorize", + "oauth_callback", "/auth/oauth/callback", + "oauth_metadata", "/client-metadata.json") } // Create HTTP server server := &http.Server{ - Addr: config.HTTP.Addr, + Addr: cfg.Server.Addr, Handler: mux, } @@ -412,7 +399,7 @@ func serveRegistry(cmd *cobra.Command, args []string) error { // Start server in goroutine errChan := make(chan error, 1) go func() { - fmt.Printf("Starting registry server on %s\n", config.HTTP.Addr) + slog.Info("Starting registry server", "addr", cfg.Server.Addr) if err := server.ListenAndServe(); err != nil && err != http.ErrServerClosed { errChan <- err } @@ -421,10 +408,10 @@ func serveRegistry(cmd *cobra.Command, args []string) error { // Wait for shutdown signal or error select { case <-stop: - fmt.Println("Shutting down registry server...") + slog.Info("Shutting down registry server") // Stop health worker first - fmt.Println("Stopping hold health worker...") + slog.Info("Stopping hold health worker") healthWorker.Stop() shutdownCtx, cancel := context.WithTimeout(context.Background(), 10*time.Second) @@ -442,68 +429,32 @@ func serveRegistry(cmd *cobra.Command, args []string) error { return nil } -// initializeAuthKeys creates the auth keys if they don't exist -func initializeAuthKeys(config *configuration.Configuration) error { - tokenParams, ok := config.Auth["token"] - if !ok { - return nil - } - - privateKeyPath := appview.GetStringParam(tokenParams, "privatekey", "/var/lib/atcr/auth/private-key.pem") - issuerName := appview.GetStringParam(tokenParams, "issuer", "atcr.io") - service := appview.GetStringParam(tokenParams, "service", "atcr.io") - expirationSecs := appview.GetIntParam(tokenParams, "expiration", 300) - - // Create issuer (this will generate the key if it doesn't exist) - _, err := token.NewIssuer( - privateKeyPath, - issuerName, - service, - time.Duration(expirationSecs)*time.Second, - ) - if err != nil { - return fmt.Errorf("failed to initialize token issuer: %w", err) - } - - fmt.Printf("Auth keys initialized at %s\n", privateKeyPath) - return nil -} - // createTokenIssuer creates a token issuer for auth handlers -func createTokenIssuer(config *configuration.Configuration) (*token.Issuer, error) { - tokenParams, ok := config.Auth["token"] - if !ok { - return nil, fmt.Errorf("token auth not configured") - } - - privateKeyPath := appview.GetStringParam(tokenParams, "privatekey", "/var/lib/atcr/auth/private-key.pem") - issuerName := appview.GetStringParam(tokenParams, "issuer", "atcr.io") - service := appview.GetStringParam(tokenParams, "service", "atcr.io") - expirationSecs := appview.GetIntParam(tokenParams, "expiration", 300) - +func createTokenIssuer(cfg *appview.Config) (*token.Issuer, error) { return token.NewIssuer( - privateKeyPath, - issuerName, - service, - time.Duration(expirationSecs)*time.Second, + cfg.Auth.KeyPath, + cfg.Auth.ServiceName, // issuer + cfg.Auth.ServiceName, // service + cfg.Auth.TokenExpiration, ) } // initializeUIRoutes initializes the web UI routes +// uiEnabled: whether UI is enabled (from Config.UI.Enabled) // database: read-write connection for auth and writes // readOnlyDB: read-only connection for public queries (search, user pages, etc.) -// defaultHoldDID: DID of the default hold service (e.g., "did:web:hold01.atcr.io") // healthChecker: hold endpoint health checker -func initializeUIRoutes(database *sql.DB, readOnlyDB *sql.DB, sessionStore *db.SessionStore, oauthApp *oauth.App, oauthStore *db.OAuthStore, refresher *oauth.Refresher, baseURL string, deviceStore *db.DeviceStore, defaultHoldDID string, healthChecker *holdhealth.Checker, readmeCache *readme.Cache) (*template.Template, *mux.Router) { +// readmeCache: README cache for repository pages +func initializeUIRoutes(uiEnabled bool, database *sql.DB, readOnlyDB *sql.DB, sessionStore *db.SessionStore, oauthApp *oauth.App, oauthStore *db.OAuthStore, refresher *oauth.Refresher, baseURL string, deviceStore *db.DeviceStore, healthChecker *holdhealth.Checker, readmeCache *readme.Cache) (*template.Template, *mux.Router) { // Check if UI is enabled - if !appview.GetUIEnabled() { + if !uiEnabled { return nil, nil } // Load templates templates, err := appview.Templates() if err != nil { - fmt.Printf("Warning: Failed to load UI templates: %v\n", err) + slog.Warn("Failed to load UI templates", "error", err) return nil, nil } @@ -682,8 +633,13 @@ func initializeUIRoutes(database *sql.DB, readOnlyDB *sql.DB, sessionStore *db.S OAuthStore: oauthStore, }).Methods("GET", "POST") + return templates, router +} + +// initializeJetstream initializes the Jetstream workers for real-time events and backfill +func initializeJetstream(database *sql.DB, jetstreamCfg *appview.JetstreamConfig, defaultHoldDID string, testMode bool) { // Start Jetstream worker - jetstreamURL := appview.GetJetstreamURL() + jetstreamURL := jetstreamCfg.URL // Start real-time Jetstream worker with cursor tracking for reconnects go func() { @@ -693,59 +649,54 @@ func initializeUIRoutes(database *sql.DB, readOnlyDB *sql.DB, sessionStore *db.S if err := worker.Start(context.Background()); err != nil { // Save cursor from this connection for next reconnect lastCursor = worker.GetLastCursor() - fmt.Printf("Jetstream: Real-time worker error: %v, reconnecting in 10s...\n", err) + slog.Warn("Jetstream real-time worker error, reconnecting", "component", "jetstream", "error", err, "reconnect_delay", "10s") time.Sleep(10 * time.Second) } } }() - fmt.Println("Jetstream: Real-time worker started") + slog.Info("Jetstream real-time worker started", "component", "jetstream") // Start backfill worker (enabled by default, set ATCR_BACKFILL_ENABLED=false to disable) - if appview.GetBackfillEnabled() { + if jetstreamCfg.BackfillEnabled { // Get relay endpoint for sync API (defaults to Bluesky's relay) - relayEndpoint := appview.GetRelayEndpoint() - - // Check test mode - testMode := appview.GetTestMode() + relayEndpoint := jetstreamCfg.RelayEndpoint backfillWorker, err := jetstream.NewBackfillWorker(database, relayEndpoint, defaultHoldDID, testMode) if err != nil { - fmt.Printf("Warning: Failed to create backfill worker: %v\n", err) + slog.Warn("Failed to create backfill worker", "component", "jetstream/backfill", "error", err) } else { // Run initial backfill with startup delay for Docker compose go func() { // Wait for hold service to be ready (Docker startup race condition) startupDelay := 5 * time.Second - fmt.Printf("Backfill: Waiting %s for services to be ready...\n", startupDelay) + slog.Info("Waiting for services to be ready", "component", "jetstream/backfill", "startup_delay", startupDelay) time.Sleep(startupDelay) - fmt.Printf("Backfill: Starting sync-based backfill from %s...\n", relayEndpoint) + slog.Info("Starting sync-based backfill", "component", "jetstream/backfill", "relay_endpoint", relayEndpoint) if err := backfillWorker.Start(context.Background()); err != nil { - fmt.Printf("Backfill: Finished with error: %v\n", err) + slog.Warn("Backfill finished with error", "component", "jetstream/backfill", "error", err) } else { - fmt.Println("Backfill: Completed successfully!") + slog.Info("Backfill completed successfully", "component", "jetstream/backfill") } }() // Start periodic backfill scheduler - interval := appview.GetBackfillInterval() + interval := jetstreamCfg.BackfillInterval go func() { ticker := time.NewTicker(interval) defer ticker.Stop() for range ticker.C { - fmt.Printf("Backfill: Starting periodic backfill (runs every %s)...\n", interval) + slog.Info("Starting periodic backfill", "component", "jetstream/backfill", "interval", interval) if err := backfillWorker.Start(context.Background()); err != nil { - fmt.Printf("Backfill: Periodic backfill finished with error: %v\n", err) + slog.Warn("Periodic backfill finished with error", "component", "jetstream/backfill", "error", err) } else { - fmt.Println("Backfill: Periodic backfill completed successfully!") + slog.Info("Periodic backfill completed successfully", "component", "jetstream/backfill") } } }() - fmt.Printf("Backfill: Periodic scheduler started (interval: %s)\n", interval) + slog.Info("Periodic backfill scheduler started", "component", "jetstream/backfill", "interval", interval) } } - - return templates, router } diff --git a/deploy/.env.prod.template b/deploy/.env.prod.template index 4fb8b3e..0e6aed0 100644 --- a/deploy/.env.prod.template +++ b/deploy/.env.prod.template @@ -161,7 +161,7 @@ ATCR_UI_ENABLED=true # Log level: debug, info, warn, error # Default: info -ATCR_LOG_LEVEL=info +ATCR_LOG_LEVEL=debug # Log formatter: text, json # Default: text diff --git a/deploy/docker-compose.prod.yml b/deploy/docker-compose.prod.yml index bc8b22a..f632c23 100644 --- a/deploy/docker-compose.prod.yml +++ b/deploy/docker-compose.prod.yml @@ -114,6 +114,10 @@ services: S3_ENDPOINT: ${S3_ENDPOINT:-} S3_REGION_ENDPOINT: ${S3_REGION_ENDPOINT:-} + # Logging + ATCR_LOG_LEVEL: ${ATCR_LOG_LEVEL:-debug} + ATCR_LOG_FORMATTER: ${ATCR_LOG_FORMATTER:-text} + # Optional: Filesystem storage (comment out S3 vars above) # STORAGE_DRIVER: filesystem # STORAGE_ROOT_DIR: /var/lib/atcr/hold diff --git a/docker-compose.yml b/docker-compose.yml index 81080e1..4b66dc6 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -20,7 +20,7 @@ services: # Test mode - fallback to default hold when user's hold is unreachable TEST_MODE: true # Logging - ATCR_LOG_LEVEL: info + ATCR_LOG_LEVEL: debug volumes: # Auth keys (JWT signing keys) # - atcr-auth:/var/lib/atcr/auth @@ -50,6 +50,8 @@ services: # STORAGE_ROOT_DIR: /var/lib/atcr/hold TEST_MODE: true # DISABLE_PRESIGNED_URLS: true + # Logging + ATCR_LOG_LEVEL: debug # Storage config comes from env_file (STORAGE_DRIVER, AWS_*, S3_*) build: context: . diff --git a/pkg/appview/config.go b/pkg/appview/config.go index 880db8f..122f056 100644 --- a/pkg/appview/config.go +++ b/pkg/appview/config.go @@ -17,92 +17,230 @@ import ( "github.com/distribution/distribution/v3/configuration" ) -// LoadConfigFromEnv builds a complete configuration from environment variables -// This follows the same pattern as the hold service (no config files, only env vars) -func LoadConfigFromEnv() (*configuration.Configuration, error) { - config := &configuration.Configuration{} - - // Version - config.Version = configuration.MajorMinorVersion(0, 1) - - // Logging - config.Log = buildLogConfig() - - // HTTP server - httpConfig, err := buildHTTPConfig() - if err != nil { - return nil, fmt.Errorf("failed to build HTTP config: %w", err) - } - config.HTTP = httpConfig - - // Storage (fake in-memory placeholder - all real storage is proxied) - config.Storage = buildStorageConfig() - - // Get base URL for error messages and auth config - baseURL := GetBaseURL(httpConfig.Addr) - - // Middleware (ATProto resolver) - defaultHoldDID := os.Getenv("ATCR_DEFAULT_HOLD_DID") - if defaultHoldDID == "" { - return nil, fmt.Errorf("ATCR_DEFAULT_HOLD_DID is required") - } - config.Middleware = buildMiddlewareConfig(defaultHoldDID, baseURL) - - // Auth - authConfig, err := buildAuthConfig(baseURL) - if err != nil { - return nil, fmt.Errorf("failed to build auth config: %w", err) - } - config.Auth = authConfig - - // Health checks - config.Health = buildHealthConfig() - - return config, nil +// Config represents the AppView service configuration +type Config struct { + Version string `yaml:"version"` + LogLevel string `yaml:"log_level"` + Server ServerConfig `yaml:"server"` + UI UIConfig `yaml:"ui"` + Health HealthConfig `yaml:"health"` + Jetstream JetstreamConfig `yaml:"jetstream"` + Auth AuthConfig `yaml:"auth"` + Distribution *configuration.Configuration `yaml:"-"` // Wrapped distribution config for compatibility } -// buildLogConfig creates logging configuration from environment variables -func buildLogConfig() configuration.Log { - level := GetEnvOrDefault("ATCR_LOG_LEVEL", "info") - formatter := GetEnvOrDefault("ATCR_LOG_FORMATTER", "text") +// ServerConfig defines server settings +type ServerConfig struct { + // Addr is the HTTP listen address (from env: ATCR_HTTP_ADDR, default: ":5000") + Addr string `yaml:"addr"` - return configuration.Log{ - Level: configuration.Loglevel(level), - Formatter: formatter, + // BaseURL is the public URL for OAuth/JWT realm (from env: ATCR_BASE_URL) + // Auto-detected from Addr if not set + BaseURL string `yaml:"base_url"` + + // DefaultHoldDID is the default hold DID for blob storage (from env: ATCR_DEFAULT_HOLD_DID) + // REQUIRED - e.g., "did:web:hold01.atcr.io" + DefaultHoldDID string `yaml:"default_hold_did"` + + // TestMode enables HTTP for local DID resolution and transition:generic scope (from env: TEST_MODE) + TestMode bool `yaml:"test_mode"` + + // DebugAddr is the debug/pprof HTTP listen address (from env: ATCR_DEBUG_ADDR, default: ":5001") + DebugAddr string `yaml:"debug_addr"` +} + +// UIConfig defines web UI settings +type UIConfig struct { + // Enabled controls whether the web UI is enabled (from env: ATCR_UI_ENABLED, default: true) + Enabled bool `yaml:"enabled"` + + // DatabasePath is the path to the UI SQLite database (from env: ATCR_UI_DATABASE_PATH, default: "/var/lib/atcr/ui.db") + DatabasePath string `yaml:"database_path"` +} + +// HealthConfig defines health check and cache settings +type HealthConfig struct { + // CacheTTL is the hold health check cache TTL (from env: ATCR_HEALTH_CACHE_TTL, default: 15m) + CacheTTL time.Duration `yaml:"cache_ttl"` + + // CheckInterval is the hold health check refresh interval (from env: ATCR_HEALTH_CHECK_INTERVAL, default: 15m) + CheckInterval time.Duration `yaml:"check_interval"` + + // ReadmeCacheTTL is the README cache TTL (from env: ATCR_README_CACHE_TTL, default: 1h) + ReadmeCacheTTL time.Duration `yaml:"readme_cache_ttl"` +} + +// JetstreamConfig defines ATProto Jetstream settings +type JetstreamConfig struct { + // URL is the Jetstream WebSocket URL (from env: JETSTREAM_URL, default: wss://jetstream2.us-west.bsky.network/subscribe) + URL string `yaml:"url"` + + // BackfillEnabled controls whether backfill is enabled (from env: ATCR_BACKFILL_ENABLED, default: true) + BackfillEnabled bool `yaml:"backfill_enabled"` + + // BackfillInterval is the backfill interval (from env: ATCR_BACKFILL_INTERVAL, default: 1h) + BackfillInterval time.Duration `yaml:"backfill_interval"` + + // RelayEndpoint is the relay endpoint for sync API (from env: ATCR_RELAY_ENDPOINT, default: https://relay1.us-east.bsky.network) + RelayEndpoint string `yaml:"relay_endpoint"` +} + +// AuthConfig defines authentication settings +type AuthConfig struct { + // KeyPath is the JWT signing key path (from env: ATCR_AUTH_KEY_PATH, default: "/var/lib/atcr/auth/private-key.pem") + KeyPath string `yaml:"key_path"` + + // CertPath is the JWT certificate path (from env: ATCR_AUTH_CERT_PATH, default: "/var/lib/atcr/auth/private-key.crt") + CertPath string `yaml:"cert_path"` + + // TokenExpiration is the JWT expiration duration (from env: ATCR_TOKEN_EXPIRATION, default: 300s) + TokenExpiration time.Duration `yaml:"token_expiration"` + + // ServiceName is the service name used for JWT issuer and service fields + // Derived from ATCR_SERVICE_NAME env var or extracted from base URL (e.g., "atcr.io") + ServiceName string `yaml:"service_name"` +} + +// LoadConfigFromEnv builds a complete configuration from environment variables +// This follows the same pattern as the hold service (no config files, only env vars) +func LoadConfigFromEnv() (*Config, error) { + cfg := &Config{ + Version: "0.1", + } + + // Logging configuration + cfg.LogLevel = getEnvOrDefault("ATCR_LOG_LEVEL", "info") + + // Server configuration + cfg.Server.Addr = getEnvOrDefault("ATCR_HTTP_ADDR", ":5000") + cfg.Server.DebugAddr = getEnvOrDefault("ATCR_DEBUG_ADDR", ":5001") + cfg.Server.DefaultHoldDID = os.Getenv("ATCR_DEFAULT_HOLD_DID") + if cfg.Server.DefaultHoldDID == "" { + return nil, fmt.Errorf("ATCR_DEFAULT_HOLD_DID is required") + } + cfg.Server.TestMode = os.Getenv("TEST_MODE") == "true" + + // Auto-detect base URL if not explicitly set + cfg.Server.BaseURL = os.Getenv("ATCR_BASE_URL") + if cfg.Server.BaseURL == "" { + cfg.Server.BaseURL = autoDetectBaseURL(cfg.Server.Addr) + } + + // UI configuration + cfg.UI.Enabled = os.Getenv("ATCR_UI_ENABLED") != "false" + cfg.UI.DatabasePath = getEnvOrDefault("ATCR_UI_DATABASE_PATH", "/var/lib/atcr/ui.db") + + // Health and cache configuration + cfg.Health.CacheTTL = getDurationOrDefault("ATCR_HEALTH_CACHE_TTL", 15*time.Minute) + cfg.Health.CheckInterval = getDurationOrDefault("ATCR_HEALTH_CHECK_INTERVAL", 15*time.Minute) + cfg.Health.ReadmeCacheTTL = getDurationOrDefault("ATCR_README_CACHE_TTL", 1*time.Hour) + + // Jetstream configuration + cfg.Jetstream.URL = getEnvOrDefault("JETSTREAM_URL", "wss://jetstream2.us-west.bsky.network/subscribe") + cfg.Jetstream.BackfillEnabled = os.Getenv("ATCR_BACKFILL_ENABLED") != "false" + cfg.Jetstream.BackfillInterval = getDurationOrDefault("ATCR_BACKFILL_INTERVAL", 1*time.Hour) + cfg.Jetstream.RelayEndpoint = getEnvOrDefault("ATCR_RELAY_ENDPOINT", "https://relay1.us-east.bsky.network") + + // Auth configuration + cfg.Auth.KeyPath = getEnvOrDefault("ATCR_AUTH_KEY_PATH", "/var/lib/atcr/auth/private-key.pem") + cfg.Auth.CertPath = getEnvOrDefault("ATCR_AUTH_CERT_PATH", "/var/lib/atcr/auth/private-key.crt") + + // Parse token expiration (default: 300 seconds = 5 minutes) + expirationStr := getEnvOrDefault("ATCR_TOKEN_EXPIRATION", "300") + expirationSecs, err := strconv.Atoi(expirationStr) + if err != nil { + return nil, fmt.Errorf("invalid ATCR_TOKEN_EXPIRATION: %w", err) + } + cfg.Auth.TokenExpiration = time.Duration(expirationSecs) * time.Second + + // Derive service name from base URL or env var (used for JWT issuer and service) + cfg.Auth.ServiceName = getServiceName(cfg.Server.BaseURL) + + // Build distribution configuration for compatibility with distribution library + distConfig, err := buildDistributionConfig(cfg) + if err != nil { + return nil, fmt.Errorf("failed to build distribution config: %w", err) + } + cfg.Distribution = distConfig + + return cfg, nil +} + +// buildDistributionConfig creates a distribution Configuration from our Config +// This maintains compatibility with the distribution library +func buildDistributionConfig(cfg *Config) (*configuration.Configuration, error) { + distConfig := &configuration.Configuration{} + + // Version + distConfig.Version = configuration.MajorMinorVersion(0, 1) + + // Logging + distConfig.Log = configuration.Log{ + Level: configuration.Loglevel(cfg.LogLevel), + Formatter: getEnvOrDefault("ATCR_LOG_FORMATTER", "text"), Fields: map[string]any{ "service": "atcr-appview", }, } -} -// buildHTTPConfig creates HTTP server configuration from environment variables -func buildHTTPConfig() (configuration.HTTP, error) { - addr := GetEnvOrDefault("ATCR_HTTP_ADDR", ":5000") - debugAddr := GetEnvOrDefault("ATCR_DEBUG_ADDR", ":5001") - - // HTTP secret - only needed for multipart uploads in distribution's storage driver - // Since AppView is stateless and routes all storage through middleware, this isn't - // actually used, but we generate a random secret for defense in depth + // HTTP server httpSecret := os.Getenv("REGISTRY_HTTP_SECRET") if httpSecret == "" { // Generate a random 32-byte secret randomBytes := make([]byte, 32) if _, err := rand.Read(randomBytes); err != nil { - return configuration.HTTP{}, fmt.Errorf("failed to generate random secret: %w", err) + return nil, fmt.Errorf("failed to generate random secret: %w", err) } httpSecret = hex.EncodeToString(randomBytes) } - return configuration.HTTP{ - Addr: addr, + distConfig.HTTP = configuration.HTTP{ + Addr: cfg.Server.Addr, Secret: httpSecret, Headers: map[string][]string{ "X-Content-Type-Options": {"nosniff"}, }, Debug: configuration.Debug{ - Addr: debugAddr, + Addr: cfg.Server.DebugAddr, }, - }, nil + } + + // Storage (fake in-memory placeholder - all real storage is proxied) + distConfig.Storage = buildStorageConfig() + + // Middleware (ATProto resolver) + distConfig.Middleware = buildMiddlewareConfig(cfg.Server.DefaultHoldDID, cfg.Server.BaseURL) + + // Auth (use values from cfg.Auth) + realm := cfg.Server.BaseURL + "/auth/token" + + distConfig.Auth = configuration.Auth{ + "token": configuration.Parameters{ + "realm": realm, + "service": cfg.Auth.ServiceName, + "issuer": cfg.Auth.ServiceName, + "rootcertbundle": cfg.Auth.CertPath, + "privatekey": cfg.Auth.KeyPath, + "expiration": int(cfg.Auth.TokenExpiration.Seconds()), + }, + } + + // Health checks + distConfig.Health = buildHealthConfig() + + return distConfig, nil +} + +// autoDetectBaseURL determines the base URL for the service from the HTTP address +func autoDetectBaseURL(httpAddr string) string { + // Auto-detect from HTTP addr + if httpAddr[0] == ':' { + // Just a port, assume localhost + return fmt.Sprintf("http://127.0.0.1%s", httpAddr) + } + + // Full address provided + return fmt.Sprintf("http://%s", httpAddr) } // buildStorageConfig creates a fake in-memory storage config @@ -148,37 +286,6 @@ func buildMiddlewareConfig(defaultHoldDID string, baseURL string) map[string][]c } } -// buildAuthConfig creates authentication configuration from environment variables -func buildAuthConfig(baseURL string) (configuration.Auth, error) { - // Token configuration - privateKeyPath := GetEnvOrDefault("ATCR_AUTH_KEY_PATH", "/var/lib/atcr/auth/private-key.pem") - certPath := GetEnvOrDefault("ATCR_AUTH_CERT_PATH", "/var/lib/atcr/auth/private-key.crt") - - // Token expiration in seconds (default: 5 minutes) - expirationStr := GetEnvOrDefault("ATCR_TOKEN_EXPIRATION", "300") - expiration, err := strconv.Atoi(expirationStr) - if err != nil { - return configuration.Auth{}, fmt.Errorf("invalid ATCR_TOKEN_EXPIRATION: %w", err) - } - - // Auto-derive service name from base URL or use env var - serviceName := getServiceName(baseURL) - - // Auto-derive realm from base URL - realm := baseURL + "/auth/token" - - return configuration.Auth{ - "token": configuration.Parameters{ - "realm": realm, - "service": serviceName, - "issuer": serviceName, - "rootcertbundle": certPath, - "privatekey": privateKeyPath, - "expiration": expiration, - }, - }, nil -} - // buildHealthConfig creates health check configuration func buildHealthConfig() configuration.Health { return configuration.Health{ @@ -190,24 +297,6 @@ func buildHealthConfig() configuration.Health { } } -// GetBaseURL determines the base URL for the service -// Priority: ATCR_BASE_URL env var, then derived from HTTP addr -func GetBaseURL(httpAddr string) string { - baseURL := os.Getenv("ATCR_BASE_URL") - if baseURL != "" { - return baseURL - } - - // Auto-detect from HTTP addr - if httpAddr[0] == ':' { - // Just a port, assume localhost - return fmt.Sprintf("http://127.0.0.1%s", httpAddr) - } - - // Full address provided - return fmt.Sprintf("http://%s", httpAddr) -} - // getServiceName extracts service name from base URL or uses env var func getServiceName(baseURL string) string { // Check env var first @@ -232,98 +321,17 @@ func getServiceName(baseURL string) string { return "atcr.io" } -// GetEnvOrDefault gets an environment variable or returns a default value -func GetEnvOrDefault(key, defaultValue string) string { +// getEnvOrDefault gets an environment variable or returns a default value +func getEnvOrDefault(key, defaultValue string) string { if val := os.Getenv(key); val != "" { return val } return defaultValue } -// GetLogLevel returns the configured log level from environment -// Centralizes ATCR_LOG_LEVEL env var reading -func GetLogLevel() string { - return GetEnvOrDefault("ATCR_LOG_LEVEL", "info") -} - -// GetStringParam extracts a string parameter from configuration.Parameters -func GetStringParam(params configuration.Parameters, key, defaultValue string) string { - if v, ok := params[key]; ok { - if s, ok := v.(string); ok { - return s - } - } - return defaultValue -} - -// GetIntParam extracts an int parameter from configuration.Parameters -func GetIntParam(params configuration.Parameters, key string, defaultValue int) int { - if v, ok := params[key]; ok { - if i, ok := v.(int); ok { - return i - } - } - return defaultValue -} - -// ExtractDefaultHoldDID extracts the default hold DID from middleware config -// Returns a DID (e.g., "did:web:hold01.atcr.io") -// To find a hold's DID, visit: https://hold-url/.well-known/did.json -func ExtractDefaultHoldDID(config *configuration.Configuration) string { - // Navigate through: middleware.registry[].options.default_hold_did - registryMiddleware, ok := config.Middleware["registry"] - if !ok { - return "" - } - - // Find atproto-resolver middleware - for _, mw := range registryMiddleware { - // Check if this is the atproto-resolver - if mw.Name != "atproto-resolver" { - continue - } - - // Extract options - options is configuration.Parameters which is map[string]any - if mw.Options != nil { - if holdDID, ok := mw.Options["default_hold_did"].(string); ok { - return holdDID - } - } - } - - return "" -} - -// ExtractTestMode extracts the test_mode flag from middleware config -// Returns true if TEST_MODE=true, false otherwise -func ExtractTestMode(config *configuration.Configuration) bool { - // Navigate through: middleware.registry[].options.test_mode - registryMiddleware, ok := config.Middleware["registry"] - if !ok { - return false - } - - // Find atproto-resolver middleware - for _, mw := range registryMiddleware { - // Check if this is the atproto-resolver - if mw.Name != "atproto-resolver" { - continue - } - - // Extract options - options is configuration.Parameters which is map[string]any - if mw.Options != nil { - if testMode, ok := mw.Options["test_mode"].(bool); ok { - return testMode - } - } - } - - return false -} - -// GetDurationOrDefault parses a duration from environment variable or returns default +// getDurationOrDefault parses a duration from environment variable or returns default // Logs a warning if parsing fails -func GetDurationOrDefault(envKey string, defaultValue time.Duration) time.Duration { +func getDurationOrDefault(envKey string, defaultValue time.Duration) time.Duration { envVal := os.Getenv(envKey) if envVal == "" { return defaultValue @@ -337,86 +345,3 @@ func GetDurationOrDefault(envKey string, defaultValue time.Duration) time.Durati return parsed } - -// GetBoolOrDefault returns a boolean from environment variable or returns default -// Treats "false" as false, everything else (including empty) as the default value -func GetBoolOrDefault(envKey string, defaultValue bool) bool { - envVal := os.Getenv(envKey) - if envVal == "" { - return defaultValue - } - - // Explicit false check - if envVal == "false" { - return false - } - - // Explicit true check - if envVal == "true" { - return true - } - - // For any other value, return default - return defaultValue -} - -// UI Configuration - -// GetUIEnabled returns whether the UI is enabled (default: true) -func GetUIEnabled() bool { - // UI is enabled unless explicitly set to "false" - return os.Getenv("ATCR_UI_ENABLED") != "false" -} - -// GetUIDatabasePath returns the path to the UI database (default: /var/lib/atcr/ui.db) -func GetUIDatabasePath() string { - return GetEnvOrDefault("ATCR_UI_DATABASE_PATH", "/var/lib/atcr/ui.db") -} - -// Health & Cache Configuration - -// GetHealthCacheTTL returns the hold health check cache TTL (default: 15m) -func GetHealthCacheTTL() time.Duration { - return GetDurationOrDefault("ATCR_HEALTH_CACHE_TTL", 15*time.Minute) -} - -// GetReadmeCacheTTL returns the README cache TTL (default: 1h) -func GetReadmeCacheTTL() time.Duration { - return GetDurationOrDefault("ATCR_README_CACHE_TTL", 1*time.Hour) -} - -// GetHealthCheckInterval returns the hold health check refresh interval (default: 15m) -func GetHealthCheckInterval() time.Duration { - return GetDurationOrDefault("ATCR_HEALTH_CHECK_INTERVAL", 15*time.Minute) -} - -// Jetstream Configuration - -// GetJetstreamURL returns the Jetstream WebSocket URL (default: wss://jetstream2.us-west.bsky.network/subscribe) -func GetJetstreamURL() string { - return GetEnvOrDefault("JETSTREAM_URL", "wss://jetstream2.us-west.bsky.network/subscribe") -} - -// GetBackfillEnabled returns whether backfill is enabled (default: true) -func GetBackfillEnabled() bool { - // Backfill is enabled unless explicitly set to "false" - return os.Getenv("ATCR_BACKFILL_ENABLED") != "false" -} - -// GetRelayEndpoint returns the relay endpoint for sync API (default: https://relay1.us-east.bsky.network) -func GetRelayEndpoint() string { - return GetEnvOrDefault("ATCR_RELAY_ENDPOINT", "https://relay1.us-east.bsky.network") -} - -// GetBackfillInterval returns the backfill interval (default: 1h) -func GetBackfillInterval() time.Duration { - return GetDurationOrDefault("ATCR_BACKFILL_INTERVAL", 1*time.Hour) -} - -// Test Mode Configuration - -// GetTestMode returns whether test mode is enabled (default: false) -// Test mode enables HTTP for local DID resolution and transition:generic scope -func GetTestMode() bool { - return os.Getenv("TEST_MODE") == "true" -} diff --git a/pkg/appview/config_test.go b/pkg/appview/config_test.go index 049c22e..4a34339 100644 --- a/pkg/appview/config_test.go +++ b/pkg/appview/config_test.go @@ -4,109 +4,8 @@ import ( "os" "testing" "time" - - "github.com/distribution/distribution/v3/configuration" ) -func TestGetEnvOrDefault(t *testing.T) { - tests := []struct { - name string - key string - defaultValue string - envValue string - setEnv bool - want string - }{ - { - name: "env var not set", - key: "TEST_VAR_NOT_SET", - defaultValue: "default", - setEnv: false, - want: "default", - }, - { - name: "env var set to value", - key: "TEST_VAR_SET", - defaultValue: "default", - envValue: "custom", - setEnv: true, - want: "custom", - }, - { - name: "env var set to empty string", - key: "TEST_VAR_EMPTY", - defaultValue: "default", - envValue: "", - setEnv: true, - want: "default", - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if tt.setEnv { - t.Setenv(tt.key, tt.envValue) - } - - got := GetEnvOrDefault(tt.key, tt.defaultValue) - if got != tt.want { - t.Errorf("GetEnvOrDefault() = %v, want %v", got, tt.want) - } - }) - } -} - -func TestGetBaseURL(t *testing.T) { - tests := []struct { - name string - httpAddr string - envBaseURL string - setEnv bool - want string - }{ - { - name: "env var set", - httpAddr: ":5000", - envBaseURL: "https://registry.example.com", - setEnv: true, - want: "https://registry.example.com", - }, - { - name: "port only - auto detect localhost", - httpAddr: ":5000", - setEnv: false, - want: "http://127.0.0.1:5000", - }, - { - name: "full address", - httpAddr: "0.0.0.0:5000", - setEnv: false, - want: "http://0.0.0.0:5000", - }, - { - name: "custom port", - httpAddr: ":8080", - setEnv: false, - want: "http://127.0.0.1:8080", - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if tt.setEnv { - t.Setenv("ATCR_BASE_URL", tt.envBaseURL) - } else { - os.Unsetenv("ATCR_BASE_URL") - } - - got := GetBaseURL(tt.httpAddr) - if got != tt.want { - t.Errorf("GetBaseURL() = %v, want %v", got, tt.want) - } - }) - } -} - func Test_getServiceName(t *testing.T) { tests := []struct { name string @@ -170,170 +69,9 @@ func Test_getServiceName(t *testing.T) { } } -func TestBuildLogConfig(t *testing.T) { - tests := []struct { - name string - envLevel string - envFormatter string - setLevel bool - setFormatter bool - wantLevel configuration.Loglevel - wantFormatter string - }{ - { - name: "defaults", - setLevel: false, - setFormatter: false, - wantLevel: "info", - wantFormatter: "text", - }, - { - name: "custom level", - envLevel: "debug", - setLevel: true, - setFormatter: false, - wantLevel: "debug", - wantFormatter: "text", - }, - { - name: "custom formatter", - envLevel: "info", - envFormatter: "json", - setLevel: true, - setFormatter: true, - wantLevel: "info", - wantFormatter: "json", - }, - } +// TestBuildLogConfig removed - buildLogConfig is now an internal function - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if tt.setLevel { - t.Setenv("ATCR_LOG_LEVEL", tt.envLevel) - } else { - os.Unsetenv("ATCR_LOG_LEVEL") - } - - if tt.setFormatter { - t.Setenv("ATCR_LOG_FORMATTER", tt.envFormatter) - } else { - os.Unsetenv("ATCR_LOG_FORMATTER") - } - - got := buildLogConfig() - if got.Level != tt.wantLevel { - t.Errorf("buildLogConfig().Level = %v, want %v", got.Level, tt.wantLevel) - } - if got.Formatter != tt.wantFormatter { - t.Errorf("buildLogConfig().Formatter = %v, want %v", got.Formatter, tt.wantFormatter) - } - if got.Fields["service"] != "atcr-appview" { - t.Errorf("buildLogConfig().Fields[service] = %v, want atcr-appview", got.Fields["service"]) - } - }) - } -} - -func TestBuildHTTPConfig(t *testing.T) { - tests := []struct { - name string - envAddr string - envDebugAddr string - envSecret string - setAddr bool - setDebugAddr bool - setSecret bool - wantAddr string - wantDebug string - wantSecret string // empty means "should be generated" - }{ - { - name: "defaults", - setAddr: false, - wantAddr: ":5000", - wantDebug: ":5001", - wantSecret: "", // generated - }, - { - name: "custom addr", - envAddr: ":8080", - setAddr: true, - setDebugAddr: false, - wantAddr: ":8080", - wantDebug: ":5001", - wantSecret: "", - }, - { - name: "custom debug addr", - envDebugAddr: ":9001", - setAddr: false, - setDebugAddr: true, - wantAddr: ":5000", - wantDebug: ":9001", - wantSecret: "", - }, - { - name: "custom secret", - envSecret: "my-custom-secret", - setAddr: false, - setSecret: true, - wantAddr: ":5000", - wantDebug: ":5001", - wantSecret: "my-custom-secret", - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if tt.setAddr { - t.Setenv("ATCR_HTTP_ADDR", tt.envAddr) - } else { - os.Unsetenv("ATCR_HTTP_ADDR") - } - - if tt.setDebugAddr { - t.Setenv("ATCR_DEBUG_ADDR", tt.envDebugAddr) - } else { - os.Unsetenv("ATCR_DEBUG_ADDR") - } - - if tt.setSecret { - t.Setenv("REGISTRY_HTTP_SECRET", tt.envSecret) - } else { - os.Unsetenv("REGISTRY_HTTP_SECRET") - } - - got, err := buildHTTPConfig() - if err != nil { - t.Fatalf("buildHTTPConfig() error = %v", err) - } - - if got.Addr != tt.wantAddr { - t.Errorf("buildHTTPConfig().Addr = %v, want %v", got.Addr, tt.wantAddr) - } - - if got.Debug.Addr != tt.wantDebug { - t.Errorf("buildHTTPConfig().Debug.Addr = %v, want %v", got.Debug.Addr, tt.wantDebug) - } - - if tt.wantSecret == "" { - // Should be generated (64 hex chars = 32 bytes) - if len(got.Secret) != 64 { - t.Errorf("buildHTTPConfig().Secret length = %v, want 64", len(got.Secret)) - } - } else { - if got.Secret != tt.wantSecret { - t.Errorf("buildHTTPConfig().Secret = %v, want %v", got.Secret, tt.wantSecret) - } - } - - // Verify headers - if got.Headers["X-Content-Type-Options"][0] != "nosniff" { - t.Error("buildHTTPConfig() missing X-Content-Type-Options header") - } - }) - } -} +// TestBuildHTTPConfig removed - buildHTTPConfig is now an internal function func TestBuildStorageConfig(t *testing.T) { got := buildStorageConfig() @@ -430,126 +168,6 @@ func TestBuildMiddlewareConfig(t *testing.T) { } } -func TestBuildAuthConfig(t *testing.T) { - tests := []struct { - name string - baseURL string - envKeyPath string - envCertPath string - envExpiration string - setKeyPath bool - setCertPath bool - setExpiration bool - wantKeyPath string - wantCertPath string - wantExpiration int - wantRealm string - wantService string - wantError bool - }{ - { - name: "defaults", - baseURL: "http://127.0.0.1:5000", - setKeyPath: false, - setCertPath: false, - setExpiration: false, - wantKeyPath: "/var/lib/atcr/auth/private-key.pem", - wantCertPath: "/var/lib/atcr/auth/private-key.crt", - wantExpiration: 300, - wantRealm: "http://127.0.0.1:5000/auth/token", - wantService: "atcr.io", - wantError: false, - }, - { - name: "custom values", - baseURL: "https://registry.example.com", - envKeyPath: "/custom/key.pem", - envCertPath: "/custom/cert.crt", - envExpiration: "600", - setKeyPath: true, - setCertPath: true, - setExpiration: true, - wantKeyPath: "/custom/key.pem", - wantCertPath: "/custom/cert.crt", - wantExpiration: 600, - wantRealm: "https://registry.example.com/auth/token", - wantService: "registry.example.com", - wantError: false, - }, - { - name: "invalid expiration", - baseURL: "http://127.0.0.1:5000", - envExpiration: "not-a-number", - setExpiration: true, - wantError: true, - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if tt.setKeyPath { - t.Setenv("ATCR_AUTH_KEY_PATH", tt.envKeyPath) - } else { - os.Unsetenv("ATCR_AUTH_KEY_PATH") - } - - if tt.setCertPath { - t.Setenv("ATCR_AUTH_CERT_PATH", tt.envCertPath) - } else { - os.Unsetenv("ATCR_AUTH_CERT_PATH") - } - - if tt.setExpiration { - t.Setenv("ATCR_TOKEN_EXPIRATION", tt.envExpiration) - } else { - os.Unsetenv("ATCR_TOKEN_EXPIRATION") - } - - // Clear service name env var - os.Unsetenv("ATCR_SERVICE_NAME") - - got, err := buildAuthConfig(tt.baseURL) - if (err != nil) != tt.wantError { - t.Errorf("buildAuthConfig() error = %v, wantError %v", err, tt.wantError) - return - } - - if tt.wantError { - return - } - - tokenParams, ok := got["token"] - if !ok { - t.Fatal("buildAuthConfig() missing token params") - } - - if tokenParams["privatekey"] != tt.wantKeyPath { - t.Errorf("privatekey = %v, want %v", tokenParams["privatekey"], tt.wantKeyPath) - } - - if tokenParams["rootcertbundle"] != tt.wantCertPath { - t.Errorf("rootcertbundle = %v, want %v", tokenParams["rootcertbundle"], tt.wantCertPath) - } - - if tokenParams["expiration"] != tt.wantExpiration { - t.Errorf("expiration = %v, want %v", tokenParams["expiration"], tt.wantExpiration) - } - - if tokenParams["realm"] != tt.wantRealm { - t.Errorf("realm = %v, want %v", tokenParams["realm"], tt.wantRealm) - } - - if tokenParams["service"] != tt.wantService { - t.Errorf("service = %v, want %v", tokenParams["service"], tt.wantService) - } - - if tokenParams["issuer"] != tt.wantService { - t.Errorf("issuer = %v, want %v", tokenParams["issuer"], tt.wantService) - } - }) - } -} - func TestBuildHealthConfig(t *testing.T) { got := buildHealthConfig() @@ -566,336 +184,6 @@ func TestBuildHealthConfig(t *testing.T) { } } -func TestGetStringParam(t *testing.T) { - tests := []struct { - name string - params configuration.Parameters - key string - defaultValue string - want string - }{ - { - name: "string value exists", - params: configuration.Parameters{ - "foo": "bar", - }, - key: "foo", - defaultValue: "default", - want: "bar", - }, - { - name: "key does not exist", - params: configuration.Parameters{}, - key: "foo", - defaultValue: "default", - want: "default", - }, - { - name: "value is not a string", - params: configuration.Parameters{ - "foo": 123, - }, - key: "foo", - defaultValue: "default", - want: "default", - }, - { - name: "empty string value", - params: configuration.Parameters{ - "foo": "", - }, - key: "foo", - defaultValue: "default", - want: "", - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - got := GetStringParam(tt.params, tt.key, tt.defaultValue) - if got != tt.want { - t.Errorf("GetStringParam() = %v, want %v", got, tt.want) - } - }) - } -} - -func TestGetIntParam(t *testing.T) { - tests := []struct { - name string - params configuration.Parameters - key string - defaultValue int - want int - }{ - { - name: "int value exists", - params: configuration.Parameters{ - "foo": 42, - }, - key: "foo", - defaultValue: 100, - want: 42, - }, - { - name: "key does not exist", - params: configuration.Parameters{}, - key: "foo", - defaultValue: 100, - want: 100, - }, - { - name: "value is not an int", - params: configuration.Parameters{ - "foo": "not-an-int", - }, - key: "foo", - defaultValue: 100, - want: 100, - }, - { - name: "zero value", - params: configuration.Parameters{ - "foo": 0, - }, - key: "foo", - defaultValue: 100, - want: 0, - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - got := GetIntParam(tt.params, tt.key, tt.defaultValue) - if got != tt.want { - t.Errorf("GetIntParam() = %v, want %v", got, tt.want) - } - }) - } -} - -func TestExtractDefaultHoldDID(t *testing.T) { - tests := []struct { - name string - config *configuration.Configuration - want string - }{ - { - name: "valid config with hold DID", - config: &configuration.Configuration{ - Middleware: map[string][]configuration.Middleware{ - "registry": { - { - Name: "atproto-resolver", - Options: configuration.Parameters{ - "default_hold_did": "did:web:hold01.atcr.io", - }, - }, - }, - }, - }, - want: "did:web:hold01.atcr.io", - }, - { - name: "no registry middleware", - config: &configuration.Configuration{ - Middleware: map[string][]configuration.Middleware{}, - }, - want: "", - }, - { - name: "no atproto-resolver middleware", - config: &configuration.Configuration{ - Middleware: map[string][]configuration.Middleware{ - "registry": { - { - Name: "other-middleware", - Options: configuration.Parameters{ - "foo": "bar", - }, - }, - }, - }, - }, - want: "", - }, - { - name: "atproto-resolver without default_hold_did", - config: &configuration.Configuration{ - Middleware: map[string][]configuration.Middleware{ - "registry": { - { - Name: "atproto-resolver", - Options: configuration.Parameters{ - "other_option": "value", - }, - }, - }, - }, - }, - want: "", - }, - { - name: "default_hold_did is not a string", - config: &configuration.Configuration{ - Middleware: map[string][]configuration.Middleware{ - "registry": { - { - Name: "atproto-resolver", - Options: configuration.Parameters{ - "default_hold_did": 123, - }, - }, - }, - }, - }, - want: "", - }, - { - name: "nil options", - config: &configuration.Configuration{ - Middleware: map[string][]configuration.Middleware{ - "registry": { - { - Name: "atproto-resolver", - Options: nil, - }, - }, - }, - }, - want: "", - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - got := ExtractDefaultHoldDID(tt.config) - if got != tt.want { - t.Errorf("ExtractDefaultHoldDID() = %v, want %v", got, tt.want) - } - }) - } -} - -func TestExtractTestMode(t *testing.T) { - tests := []struct { - name string - config *configuration.Configuration - want bool - }{ - { - name: "test mode enabled", - config: &configuration.Configuration{ - Middleware: map[string][]configuration.Middleware{ - "registry": { - { - Name: "atproto-resolver", - Options: configuration.Parameters{ - "test_mode": true, - }, - }, - }, - }, - }, - want: true, - }, - { - name: "test mode disabled", - config: &configuration.Configuration{ - Middleware: map[string][]configuration.Middleware{ - "registry": { - { - Name: "atproto-resolver", - Options: configuration.Parameters{ - "test_mode": false, - }, - }, - }, - }, - }, - want: false, - }, - { - name: "no registry middleware", - config: &configuration.Configuration{ - Middleware: map[string][]configuration.Middleware{}, - }, - want: false, - }, - { - name: "no atproto-resolver middleware", - config: &configuration.Configuration{ - Middleware: map[string][]configuration.Middleware{ - "registry": { - { - Name: "other-middleware", - Options: configuration.Parameters{ - "foo": "bar", - }, - }, - }, - }, - }, - want: false, - }, - { - name: "atproto-resolver without test_mode", - config: &configuration.Configuration{ - Middleware: map[string][]configuration.Middleware{ - "registry": { - { - Name: "atproto-resolver", - Options: configuration.Parameters{ - "other_option": "value", - }, - }, - }, - }, - }, - want: false, - }, - { - name: "test_mode is not a bool", - config: &configuration.Configuration{ - Middleware: map[string][]configuration.Middleware{ - "registry": { - { - Name: "atproto-resolver", - Options: configuration.Parameters{ - "test_mode": "true", - }, - }, - }, - }, - }, - want: false, - }, - { - name: "nil options", - config: &configuration.Configuration{ - Middleware: map[string][]configuration.Middleware{ - "registry": { - { - Name: "atproto-resolver", - Options: nil, - }, - }, - }, - }, - want: false, - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - got := ExtractTestMode(tt.config) - if got != tt.want { - t.Errorf("ExtractTestMode() = %v, want %v", got, tt.want) - } - }) - } -} - func TestLoadConfigFromEnv(t *testing.T) { tests := []struct { name string @@ -939,645 +227,50 @@ func TestLoadConfigFromEnv(t *testing.T) { } // Verify config structure - if got.Version.Major() != 0 || got.Version.Minor() != 1 { + if got.Version != "0.1" { t.Errorf("version = %v, want 0.1", got.Version) } - if got.Log.Level != "info" { - t.Errorf("log level = %v, want info", got.Log.Level) + if got.LogLevel != "info" { + t.Errorf("log level = %v, want info", got.LogLevel) } - if got.HTTP.Addr != ":5000" { - t.Errorf("HTTP addr = %v, want :5000", got.HTTP.Addr) + if got.Server.Addr != ":5000" { + t.Errorf("HTTP addr = %v, want :5000", got.Server.Addr) } - if _, ok := got.Storage["inmemory"]; !ok { - t.Error("storage missing inmemory driver") + if got.Server.DefaultHoldDID != tt.envHoldDID { + t.Errorf("default hold DID = %v, want %v", got.Server.DefaultHoldDID, tt.envHoldDID) } - if _, ok := got.Middleware["registry"]; !ok { - t.Error("middleware missing registry") + if got.UI.DatabasePath != "/var/lib/atcr/ui.db" { + t.Errorf("UI database path = %v, want /var/lib/atcr/ui.db", got.UI.DatabasePath) } - if _, ok := got.Auth["token"]; !ok { - t.Error("auth missing token config") + if got.Health.CacheTTL != 15*time.Minute { + t.Errorf("health cache TTL = %v, want 15m", got.Health.CacheTTL) } - if !got.Health.StorageDriver.Enabled { - t.Error("health storage driver not enabled") + if got.Jetstream.URL != "wss://jetstream2.us-west.bsky.network/subscribe" { + t.Errorf("jetstream URL = %v, want default", got.Jetstream.URL) + } + + // Verify distribution config was built + if got.Distribution == nil { + t.Error("distribution config is nil") + } + + if _, ok := got.Distribution.Storage["inmemory"]; !ok { + t.Error("distribution storage missing inmemory driver") + } + + if _, ok := got.Distribution.Middleware["registry"]; !ok { + t.Error("distribution middleware missing registry") + } + + if _, ok := got.Distribution.Auth["token"]; !ok { + t.Error("distribution auth missing token config") } }) } } - -func TestGetDurationOrDefault(t *testing.T) { - tests := []struct { - name string - envKey string - envValue string - setEnv bool - defaultValue string - want string - }{ - { - name: "env var not set", - envKey: "TEST_DURATION", - setEnv: false, - defaultValue: "5m", - want: "5m", - }, - { - name: "env var set to valid duration", - envKey: "TEST_DURATION", - envValue: "10m", - setEnv: true, - defaultValue: "5m", - want: "10m", - }, - { - name: "env var set to invalid duration", - envKey: "TEST_DURATION", - envValue: "invalid", - setEnv: true, - defaultValue: "5m", - want: "5m", // Falls back to default - }, - { - name: "env var set to empty string", - envKey: "TEST_DURATION", - envValue: "", - setEnv: true, - defaultValue: "15m", - want: "15m", - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if tt.setEnv { - t.Setenv(tt.envKey, tt.envValue) - } else { - os.Unsetenv(tt.envKey) - } - - defaultDur := parseDuration(t, tt.defaultValue) - wantDur := parseDuration(t, tt.want) - - got := GetDurationOrDefault(tt.envKey, defaultDur) - if got != wantDur { - t.Errorf("GetDurationOrDefault() = %v, want %v", got, wantDur) - } - }) - } -} - -func TestGetBoolOrDefault(t *testing.T) { - tests := []struct { - name string - envKey string - envValue string - setEnv bool - defaultValue bool - want bool - }{ - { - name: "env var not set - default true", - envKey: "TEST_BOOL", - setEnv: false, - defaultValue: true, - want: true, - }, - { - name: "env var not set - default false", - envKey: "TEST_BOOL", - setEnv: false, - defaultValue: false, - want: false, - }, - { - name: "env var set to true", - envKey: "TEST_BOOL", - envValue: "true", - setEnv: true, - defaultValue: false, - want: true, - }, - { - name: "env var set to false", - envKey: "TEST_BOOL", - envValue: "false", - setEnv: true, - defaultValue: true, - want: false, - }, - { - name: "env var set to invalid value - use default true", - envKey: "TEST_BOOL", - envValue: "invalid", - setEnv: true, - defaultValue: true, - want: true, - }, - { - name: "env var set to invalid value - use default false", - envKey: "TEST_BOOL", - envValue: "invalid", - setEnv: true, - defaultValue: false, - want: false, - }, - { - name: "env var set to empty string - use default", - envKey: "TEST_BOOL", - envValue: "", - setEnv: true, - defaultValue: true, - want: true, - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if tt.setEnv { - t.Setenv(tt.envKey, tt.envValue) - } else { - os.Unsetenv(tt.envKey) - } - - got := GetBoolOrDefault(tt.envKey, tt.defaultValue) - if got != tt.want { - t.Errorf("GetBoolOrDefault() = %v, want %v", got, tt.want) - } - }) - } -} - -func TestGetUIEnabled(t *testing.T) { - tests := []struct { - name string - envValue string - setEnv bool - want bool - }{ - { - name: "env var not set - enabled by default", - setEnv: false, - want: true, - }, - { - name: "env var set to false", - envValue: "false", - setEnv: true, - want: false, - }, - { - name: "env var set to true", - envValue: "true", - setEnv: true, - want: true, - }, - { - name: "env var set to empty string - enabled by default", - envValue: "", - setEnv: true, - want: true, - }, - { - name: "env var set to any other value - enabled", - envValue: "yes", - setEnv: true, - want: true, - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if tt.setEnv { - t.Setenv("ATCR_UI_ENABLED", tt.envValue) - } else { - os.Unsetenv("ATCR_UI_ENABLED") - } - - got := GetUIEnabled() - if got != tt.want { - t.Errorf("GetUIEnabled() = %v, want %v", got, tt.want) - } - }) - } -} - -func TestGetUIDatabasePath(t *testing.T) { - tests := []struct { - name string - envValue string - setEnv bool - want string - }{ - { - name: "env var not set - use default", - setEnv: false, - want: "/var/lib/atcr/ui.db", - }, - { - name: "env var set to custom path", - envValue: "/custom/path/ui.db", - setEnv: true, - want: "/custom/path/ui.db", - }, - { - name: "env var set to empty string - use default", - envValue: "", - setEnv: true, - want: "/var/lib/atcr/ui.db", - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if tt.setEnv { - t.Setenv("ATCR_UI_DATABASE_PATH", tt.envValue) - } else { - os.Unsetenv("ATCR_UI_DATABASE_PATH") - } - - got := GetUIDatabasePath() - if got != tt.want { - t.Errorf("GetUIDatabasePath() = %v, want %v", got, tt.want) - } - }) - } -} - -func TestGetHealthCacheTTL(t *testing.T) { - tests := []struct { - name string - envValue string - setEnv bool - want string - }{ - { - name: "env var not set - use default 15m", - setEnv: false, - want: "15m", - }, - { - name: "env var set to custom duration", - envValue: "30m", - setEnv: true, - want: "30m", - }, - { - name: "env var set to invalid duration - use default", - envValue: "invalid", - setEnv: true, - want: "15m", - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if tt.setEnv { - t.Setenv("ATCR_HEALTH_CACHE_TTL", tt.envValue) - } else { - os.Unsetenv("ATCR_HEALTH_CACHE_TTL") - } - - wantDur := parseDuration(t, tt.want) - got := GetHealthCacheTTL() - if got != wantDur { - t.Errorf("GetHealthCacheTTL() = %v, want %v", got, wantDur) - } - }) - } -} - -func TestGetReadmeCacheTTL(t *testing.T) { - tests := []struct { - name string - envValue string - setEnv bool - want string - }{ - { - name: "env var not set - use default 1h", - setEnv: false, - want: "1h", - }, - { - name: "env var set to custom duration", - envValue: "2h", - setEnv: true, - want: "2h", - }, - { - name: "env var set to invalid duration - use default", - envValue: "invalid", - setEnv: true, - want: "1h", - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if tt.setEnv { - t.Setenv("ATCR_README_CACHE_TTL", tt.envValue) - } else { - os.Unsetenv("ATCR_README_CACHE_TTL") - } - - wantDur := parseDuration(t, tt.want) - got := GetReadmeCacheTTL() - if got != wantDur { - t.Errorf("GetReadmeCacheTTL() = %v, want %v", got, wantDur) - } - }) - } -} - -func TestGetHealthCheckInterval(t *testing.T) { - tests := []struct { - name string - envValue string - setEnv bool - want string - }{ - { - name: "env var not set - use default 15m", - setEnv: false, - want: "15m", - }, - { - name: "env var set to custom interval", - envValue: "5m", - setEnv: true, - want: "5m", - }, - { - name: "env var set to invalid duration - use default", - envValue: "invalid", - setEnv: true, - want: "15m", - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if tt.setEnv { - t.Setenv("ATCR_HEALTH_CHECK_INTERVAL", tt.envValue) - } else { - os.Unsetenv("ATCR_HEALTH_CHECK_INTERVAL") - } - - wantDur := parseDuration(t, tt.want) - got := GetHealthCheckInterval() - if got != wantDur { - t.Errorf("GetHealthCheckInterval() = %v, want %v", got, wantDur) - } - }) - } -} - -func TestGetJetstreamURL(t *testing.T) { - tests := []struct { - name string - envValue string - setEnv bool - want string - }{ - { - name: "env var not set - use default", - setEnv: false, - want: "wss://jetstream2.us-west.bsky.network/subscribe", - }, - { - name: "env var set to custom URL", - envValue: "wss://custom-jetstream.example.com/subscribe", - setEnv: true, - want: "wss://custom-jetstream.example.com/subscribe", - }, - { - name: "env var set to empty string - use default", - envValue: "", - setEnv: true, - want: "wss://jetstream2.us-west.bsky.network/subscribe", - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if tt.setEnv { - t.Setenv("JETSTREAM_URL", tt.envValue) - } else { - os.Unsetenv("JETSTREAM_URL") - } - - got := GetJetstreamURL() - if got != tt.want { - t.Errorf("GetJetstreamURL() = %v, want %v", got, tt.want) - } - }) - } -} - -func TestGetBackfillEnabled(t *testing.T) { - tests := []struct { - name string - envValue string - setEnv bool - want bool - }{ - { - name: "env var not set - enabled by default", - setEnv: false, - want: true, - }, - { - name: "env var set to false", - envValue: "false", - setEnv: true, - want: false, - }, - { - name: "env var set to true", - envValue: "true", - setEnv: true, - want: true, - }, - { - name: "env var set to empty string - enabled by default", - envValue: "", - setEnv: true, - want: true, - }, - { - name: "env var set to any other value - enabled", - envValue: "yes", - setEnv: true, - want: true, - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if tt.setEnv { - t.Setenv("ATCR_BACKFILL_ENABLED", tt.envValue) - } else { - os.Unsetenv("ATCR_BACKFILL_ENABLED") - } - - got := GetBackfillEnabled() - if got != tt.want { - t.Errorf("GetBackfillEnabled() = %v, want %v", got, tt.want) - } - }) - } -} - -func TestGetRelayEndpoint(t *testing.T) { - tests := []struct { - name string - envValue string - setEnv bool - want string - }{ - { - name: "env var not set - use default", - setEnv: false, - want: "https://relay1.us-east.bsky.network", - }, - { - name: "env var set to custom endpoint", - envValue: "https://custom-relay.example.com", - setEnv: true, - want: "https://custom-relay.example.com", - }, - { - name: "env var set to empty string - use default", - envValue: "", - setEnv: true, - want: "https://relay1.us-east.bsky.network", - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if tt.setEnv { - t.Setenv("ATCR_RELAY_ENDPOINT", tt.envValue) - } else { - os.Unsetenv("ATCR_RELAY_ENDPOINT") - } - - got := GetRelayEndpoint() - if got != tt.want { - t.Errorf("GetRelayEndpoint() = %v, want %v", got, tt.want) - } - }) - } -} - -func TestGetBackfillInterval(t *testing.T) { - tests := []struct { - name string - envValue string - setEnv bool - want string - }{ - { - name: "env var not set - use default 1h", - setEnv: false, - want: "1h", - }, - { - name: "env var set to custom interval", - envValue: "30m", - setEnv: true, - want: "30m", - }, - { - name: "env var set to invalid duration - use default", - envValue: "invalid", - setEnv: true, - want: "1h", - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if tt.setEnv { - t.Setenv("ATCR_BACKFILL_INTERVAL", tt.envValue) - } else { - os.Unsetenv("ATCR_BACKFILL_INTERVAL") - } - - wantDur := parseDuration(t, tt.want) - got := GetBackfillInterval() - if got != wantDur { - t.Errorf("GetBackfillInterval() = %v, want %v", got, wantDur) - } - }) - } -} - -func TestGetTestMode(t *testing.T) { - tests := []struct { - name string - envValue string - setEnv bool - want bool - }{ - { - name: "env var not set - disabled by default", - setEnv: false, - want: false, - }, - { - name: "env var set to true", - envValue: "true", - setEnv: true, - want: true, - }, - { - name: "env var set to false", - envValue: "false", - setEnv: true, - want: false, - }, - { - name: "env var set to empty string - disabled", - envValue: "", - setEnv: true, - want: false, - }, - { - name: "env var set to any other value - disabled", - envValue: "yes", - setEnv: true, - want: false, - }, - } - - for _, tt := range tests { - t.Run(tt.name, func(t *testing.T) { - if tt.setEnv { - t.Setenv("TEST_MODE", tt.envValue) - } else { - os.Unsetenv("TEST_MODE") - } - - got := GetTestMode() - if got != tt.want { - t.Errorf("GetTestMode() = %v, want %v", got, tt.want) - } - }) - } -} - -// parseDuration is a helper function to parse duration strings in tests -func parseDuration(t *testing.T, s string) time.Duration { - t.Helper() - d, err := time.ParseDuration(s) - if err != nil { - t.Fatalf("parseDuration(%q) failed: %v", s, err) - } - return d -} diff --git a/pkg/hold/oci/http_helpers.go b/pkg/hold/oci/http_helpers.go index 637bfd4..c23d689 100644 --- a/pkg/hold/oci/http_helpers.go +++ b/pkg/hold/oci/http_helpers.go @@ -6,6 +6,7 @@ package oci import ( "encoding/json" "fmt" + "log/slog" "net/http" ) @@ -25,7 +26,7 @@ func RespondJSON(w http.ResponseWriter, status int, v any) { if err := json.NewEncoder(w).Encode(v); err != nil { // If encoding fails, we can't do much since headers are already sent // Log the error but don't try to send another response - fmt.Printf("ERROR: failed to encode JSON response: %v\n", err) + slog.Error("Failed to encode JSON response", "error", err) } } diff --git a/pkg/hold/oci/multipart.go b/pkg/hold/oci/multipart.go index fd49160..a2d066a 100644 --- a/pkg/hold/oci/multipart.go +++ b/pkg/hold/oci/multipart.go @@ -5,7 +5,7 @@ import ( "crypto/sha256" "encoding/hex" "fmt" - "log" + "log/slog" "sort" "strings" "sync" @@ -97,7 +97,9 @@ func (m *MultipartManager) cleanupExpiredSessions() { now := time.Now() for uploadID, session := range m.sessions { if now.Sub(session.LastActivity) > 24*time.Hour { - log.Printf("Cleaning up expired multipart session: uploadID=%s, age=%v", uploadID, now.Sub(session.CreatedAt)) + slog.Debug("Cleaning up expired multipart session", + "uploadID", uploadID, + "age", now.Sub(session.CreatedAt)) delete(m.sessions, uploadID) } } @@ -121,7 +123,10 @@ func (m *MultipartManager) CreateSession(digest string, mode MultipartMode, s3Up m.sessions[uploadID] = session m.mu.Unlock() - log.Printf("Created multipart session: uploadID=%s, digest=%s, mode=%v", uploadID, digest, mode) + slog.Debug("Created multipart session", + "uploadID", uploadID, + "digest", digest, + "mode", mode) return session } @@ -144,7 +149,7 @@ func (m *MultipartManager) DeleteSession(uploadID string) { defer m.mu.Unlock() delete(m.sessions, uploadID) - log.Printf("Deleted multipart session: uploadID=%s", uploadID) + slog.Debug("Deleted multipart session", "uploadID", uploadID) } // StorePart stores a part in the session (for Buffered mode) @@ -167,7 +172,11 @@ func (s *MultipartSession) StorePart(partNumber int, data []byte) string { s.Parts[partNumber] = part s.LastActivity = time.Now() - log.Printf("Stored part: uploadID=%s, part=%d, size=%d bytes, etag=%s", s.UploadID, partNumber, len(data), etag) + slog.Debug("Stored part", + "uploadID", s.UploadID, + "part", partNumber, + "size", len(data), + "etag", etag) return etag } @@ -205,7 +214,10 @@ func (s *MultipartSession) AssembleBufferedParts() ([]byte, int64, error) { assembled = append(assembled, part.Data...) } - log.Printf("Assembled buffered parts: uploadID=%s, parts=%d, totalSize=%d bytes", s.UploadID, maxPart, totalSize) + slog.Debug("Assembled buffered parts", + "uploadID", s.UploadID, + "parts", maxPart, + "totalSize", totalSize) return assembled, totalSize, nil } @@ -214,9 +226,9 @@ func (s *MultipartSession) AssembleBufferedParts() ([]byte, int64, error) { func (h *XRPCHandler) StartMultipartUploadWithManager(ctx context.Context, digest string) (string, MultipartMode, error) { // Check if presigned URLs are disabled for testing if h.disablePresignedURLs { - log.Printf("Presigned URLs disabled (DISABLE_PRESIGNED_URLS=true), using buffered mode") + slog.Debug("Presigned URLs disabled, using buffered mode", "reason", "DISABLE_PRESIGNED_URLS=true") session := h.MultipartMgr.CreateSession(digest, Buffered, "") - log.Printf("Started buffered multipart: uploadID=%s", session.UploadID) + slog.Debug("Started buffered multipart", "uploadID", session.UploadID) return session.UploadID, Buffered, nil } @@ -239,15 +251,18 @@ func (h *XRPCHandler) StartMultipartUploadWithManager(ctx context.Context, diges s3UploadID := *result.UploadId // S3 native multipart succeeded session := h.MultipartMgr.CreateSession(digest, S3Native, s3UploadID) - log.Printf("Started S3 native multipart: digest=%s, uploadID=%s, s3UploadID=%s", digest, session.UploadID, s3UploadID) + slog.Debug("Started S3 native multipart", + "digest", digest, + "uploadID", session.UploadID, + "s3UploadID", s3UploadID) return session.UploadID, S3Native, nil } - log.Printf("S3 native multipart failed, falling back to buffered mode: %v", err) + slog.Warn("S3 native multipart failed, falling back to buffered mode", "error", err) } // Fallback to buffered mode session := h.MultipartMgr.CreateSession(digest, Buffered, "") - log.Printf("Started buffered multipart: uploadID=%s", session.UploadID) + slog.Debug("Started buffered multipart", "uploadID", session.UploadID) return session.UploadID, Buffered, nil } @@ -283,7 +298,10 @@ func (h *XRPCHandler) GetPartUploadURL(ctx context.Context, uploadID string, par return nil, err } - log.Printf("Generated part presigned URL: digest=%s, uploadID=%s, part=%d", session.Digest, uploadID, partNumber) + slog.Debug("Generated part presigned URL", + "digest", session.Digest, + "uploadID", uploadID, + "part", partNumber) return &PartUploadInfo{ URL: url, @@ -350,26 +368,40 @@ func (h *XRPCHandler) CompleteMultipartUploadWithManager(ctx context.Context, up if err != nil { return fmt.Errorf("failed to complete multipart upload: digest=%s, uploadID=%s, err=%v", session.Digest, uploadID, err) } - log.Printf("Completed S3 native multipart at temp location: digest=%s, uploadID=%s, parts=%d", session.Digest, session.UploadID, len(s3Parts)) + slog.Info("Completed S3 native multipart at temp location", + "digest", session.Digest, + "uploadID", session.UploadID, + "parts", len(s3Parts)) // Verify the blob exists at temp location before moving destPath := blobPath(finalDigest) - log.Printf("[DEBUG] About to move: source=%s, dest=%s", sourcePath, destPath) + slog.Debug("About to move blob", + "source", sourcePath, + "dest", destPath) if _, err := h.driver.Stat(ctx, sourcePath); err != nil { - log.Printf("[ERROR] Source blob not found after multipart complete: path=%s, err=%v", sourcePath, err) + slog.Error("Source blob not found after multipart complete", + "path", sourcePath, + "error", err) return fmt.Errorf("source blob not found after multipart complete: %w", err) } - log.Printf("[DEBUG] Source blob verified at: %s", sourcePath) + slog.Debug("Source blob verified", "path", sourcePath) // Move from temp to final digest location using driver // Driver handles path management correctly (including S3 prefix) if err := h.driver.Move(ctx, sourcePath, destPath); err != nil { - log.Printf("[ERROR] Failed to move blob: source=%s, dest=%s, err=%v", sourcePath, destPath, err) + slog.Error("Failed to move blob", + "source", sourcePath, + "dest", destPath, + "error", err) return fmt.Errorf("failed to move blob to final location: %w", err) } - log.Printf("Moved blob to final location: %s → %s (driver paths: %s → %s)", session.Digest, finalDigest, sourcePath, destPath) + slog.Info("Moved blob to final location", + "from", session.Digest, + "to", finalDigest, + "sourcePath", sourcePath, + "destPath", destPath) return nil } @@ -396,7 +428,11 @@ func (h *XRPCHandler) CompleteMultipartUploadWithManager(ctx context.Context, up return fmt.Errorf("failed to commit blob: %w", err) } - log.Printf("Completed buffered multipart: uploadID=%s, finalDigest=%s, size=%d bytes, written=%d", session.UploadID, finalDigest, size, written) + slog.Info("Completed buffered multipart", + "uploadID", session.UploadID, + "finalDigest", finalDigest, + "size", size, + "written", written) return nil } @@ -427,12 +463,14 @@ func (h *XRPCHandler) AbortMultipartUploadWithManager(ctx context.Context, uploa if err != nil { return fmt.Errorf("failed to abort multipart upload: digest=%s, uploadID=%s, err=%v", session.Digest, uploadID, err) } - log.Printf("Aborted S3 native multipart: digest=%s, uploadID=%s", session.Digest, session.UploadID) + slog.Debug("Aborted S3 native multipart", + "digest", session.Digest, + "uploadID", session.UploadID) return nil } // Buffered mode: just delete the session (parts are in memory) - log.Printf("Aborted buffered multipart: uploadID=%s", session.UploadID) + slog.Debug("Aborted buffered multipart", "uploadID", session.UploadID) return nil } diff --git a/pkg/hold/oci/xrpc.go b/pkg/hold/oci/xrpc.go index c2d4989..4556d2e 100644 --- a/pkg/hold/oci/xrpc.go +++ b/pkg/hold/oci/xrpc.go @@ -3,6 +3,7 @@ package oci import ( "fmt" "io" + "log/slog" "net/http" "strconv" @@ -268,7 +269,7 @@ func (h *XRPCHandler) HandleNotifyManifest(w http.ResponseWriter, r *http.Reques _, _, err := h.pds.CreateLayerRecord(ctx, record) if err != nil { - fmt.Printf("Failed to create layer record: %v\n", err) + slog.Error("Failed to create layer record", "error", err) // Continue creating other records } else { layersCreated++ @@ -302,7 +303,7 @@ func (h *XRPCHandler) HandleNotifyManifest(w http.ResponseWriter, r *http.Reques totalSize, ) if err != nil { - fmt.Printf("Failed to create manifest post: %v\n", err) + slog.Error("Failed to create manifest post", "error", err) } else { postCreated = true } diff --git a/pkg/hold/pds/auth.go b/pkg/hold/pds/auth.go index a8d5607..31451e2 100644 --- a/pkg/hold/pds/auth.go +++ b/pkg/hold/pds/auth.go @@ -6,7 +6,7 @@ import ( "encoding/json" "fmt" "io" - "log" + "log/slog" "net/http" "slices" "strings" @@ -426,7 +426,7 @@ func ValidateServiceToken(r *http.Request, holdDID string, httpClient HTTPClient return nil, fmt.Errorf("missing token") } - log.Printf("[ValidateServiceToken] Validating service token for hold %s", holdDID) + slog.Debug("Validating service token", "holdDID", holdDID) // Manually parse JWT (bypass golang-jwt since it doesn't support ES256K algorithm used by ATProto) // Split token: header.payload.signature @@ -493,7 +493,7 @@ func ValidateServiceToken(r *http.Request, holdDID string, httpClient HTTPClient return nil, fmt.Errorf("signature verification failed: %w", err) } - log.Printf("[ValidateServiceToken] Successfully validated service token for user %s", issuerDID) + slog.Debug("Successfully validated service token", "userDID", issuerDID) // Return validated user return &ValidatedUser{ diff --git a/pkg/hold/pds/captain.go b/pkg/hold/pds/captain.go index 46dac8d..8a2b2de 100644 --- a/pkg/hold/pds/captain.go +++ b/pkg/hold/pds/captain.go @@ -3,6 +3,7 @@ package pds import ( "context" "fmt" + "log/slog" "time" "atcr.io/pkg/atproto" @@ -32,7 +33,9 @@ func (p *HoldPDS) CreateCaptainRecord(ctx context.Context, ownerDID string, publ return cid.Undef, fmt.Errorf("failed to create captain record: %w", err) } - fmt.Printf("Created captain record at %s, cid: %s\n", recordPath, recordCID) + slog.Info("Created captain record", + "path", recordPath, + "cid", recordCID.String()) return recordCID, nil } diff --git a/pkg/hold/pds/events.go b/pkg/hold/pds/events.go index b387c82..f6af5c6 100644 --- a/pkg/hold/pds/events.go +++ b/pkg/hold/pds/events.go @@ -6,7 +6,7 @@ import ( "database/sql" "encoding/json" "fmt" - "log" + "log/slog" "strings" "sync" "time" @@ -79,8 +79,8 @@ func NewEventBroadcaster(holdDID string, maxHistory int, dbPath string) *EventBr // Initialize database connection and schema if dbPath != "" && dbPath != ":memory:" { if err := broadcaster.initDatabase(); err != nil { - log.Printf("Warning: Failed to initialize event database: %v", err) - log.Printf("Events will not persist across restarts") + slog.Warn("Failed to initialize event database", "error", err) + slog.Warn("Events will not persist across restarts") } } @@ -127,14 +127,14 @@ func (b *EventBroadcaster) initDatabase() error { var lastSeq sql.NullInt64 err = db.QueryRow("SELECT MAX(seq) FROM firehose_events").Scan(&lastSeq) if err != nil { - log.Printf("Warning: Failed to load last event sequence: %v", err) + slog.Warn("Failed to load last event sequence", "error", err) } else if lastSeq.Valid { b.eventSeq = lastSeq.Int64 - log.Printf("Loaded event sequence from database: seq=%d", b.eventSeq) + slog.Info("Loaded event sequence from database", "seq", b.eventSeq) } else { // Database is empty but might have existing repo records // This happens on first deployment after adding persistent events - log.Printf("No events in database - will bootstrap from repo if needed") + slog.Info("No events in database - will bootstrap from repo if needed") } return nil @@ -185,7 +185,7 @@ func (b *EventBroadcaster) BootstrapFromRepo(pds *HoldPDS) error { } if count > 0 { - log.Printf("Database already has %d events, skipping bootstrap", count) + slog.Info("Database already has events, skipping bootstrap", "count", count) return nil } @@ -200,7 +200,7 @@ func (b *EventBroadcaster) BootstrapFromRepo(pds *HoldPDS) error { head, err := pds.carstore.GetUserRepoHead(ctx, pds.uid) if err != nil || !head.Defined() { // Empty repo, nothing to bootstrap - log.Printf("Empty repo, no events to bootstrap") + slog.Info("Empty repo, no events to bootstrap") return nil } @@ -215,7 +215,9 @@ func (b *EventBroadcaster) BootstrapFromRepo(pds *HoldPDS) error { return fmt.Errorf("failed to get repo rev: %w", err) } - log.Printf("Bootstrapping firehose events from current repo state (head=%s, rev=%s)", head.String(), rev) + slog.Info("Bootstrapping firehose events from current repo state", + "head", head.String(), + "rev", rev) var recordCount int64 @@ -224,13 +226,13 @@ func (b *EventBroadcaster) BootstrapFromRepo(pds *HoldPDS) error { // Get record value _, recBytes, err := repoHandle.GetRecordBytes(ctx, path) if err != nil { - log.Printf("Warning: failed to get record bytes for %s: %v", path, err) + slog.Warn("Failed to get record bytes", "path", path, "error", err) return nil // Skip this record but continue } recordValue, err := lexutil.CborDecodeValue(*recBytes) if err != nil { - log.Printf("Warning: failed to decode record %s: %v", path, err) + slog.Warn("Failed to decode record", "path", path, "error", err) return nil } @@ -265,13 +267,13 @@ func (b *EventBroadcaster) BootstrapFromRepo(pds *HoldPDS) error { Version: 1, } if err := car.WriteHeader(carHeader, &carBuf); err != nil { - log.Printf("Warning: failed to write CAR header: %v", err) + slog.Warn("Failed to write CAR header", "error", err) return nil } // Write the record block if err := carutil.LdWrite(&carBuf, recordCID.Bytes(), *recBytes); err != nil { - log.Printf("Warning: failed to write record block: %v", err) + slog.Warn("Failed to write record block", "error", err) return nil } @@ -311,7 +313,9 @@ func (b *EventBroadcaster) BootstrapFromRepo(pds *HoldPDS) error { return fmt.Errorf("failed to walk repo: %w", err) } - log.Printf("✅ Bootstrapped %d events from repo (seq now at %d)", recordCount, b.eventSeq) + slog.Info("Bootstrapped events from repo", + "recordCount", recordCount, + "seq", b.eventSeq) return nil } @@ -349,7 +353,9 @@ func (b *EventBroadcaster) Subscribe(conn *websocket.Conn, cursor int64) *Subscr } else if cursor > currentSeq { // Relay has cursor ahead of us - server was restarted // Database should have the events if we had them before - log.Printf("Relay cursor %d > currentSeq %d (server restarted), attempting database backfill", cursor, currentSeq) + slog.Info("Relay cursor ahead of current seq, attempting database backfill", + "cursor", cursor, + "currentSeq", currentSeq) go b.backfillSubscriber(sub, cursor) } // else cursor == currentSeq: relay is caught up, just stream new events @@ -387,7 +393,9 @@ func (b *EventBroadcaster) Broadcast(ctx context.Context, event *RepoEvent) { // Persist event to database if b.db != nil { if err := b.persistEvent(commitEvent); err != nil { - log.Printf("Warning: Failed to persist event seq=%d to database: %v", seq, err) + slog.Warn("Failed to persist event to database", + "seq", seq, + "error", err) } } @@ -401,7 +409,7 @@ func (b *EventBroadcaster) Broadcast(ctx context.Context, event *RepoEvent) { // Sent successfully default: // Subscriber's buffer is full, skip (they'll get disconnected for being too slow) - log.Printf("Warning: subscriber buffer full, skipping event seq=%d", seq) + slog.Warn("Subscriber buffer full, skipping event", "seq", seq) } } } @@ -488,7 +496,7 @@ func (b *EventBroadcaster) backfillSubscriber(sub *Subscriber, cursor int64) { // If database is available, use it for backfill if b.db != nil { if err := b.backfillFromDatabase(sub, cursor); err != nil { - log.Printf("Database backfill failed, falling back to in-memory: %v", err) + slog.Warn("Database backfill failed, falling back to in-memory", "error", err) b.backfillFromMemory(sub, cursor) } return @@ -527,14 +535,14 @@ func (b *EventBroadcaster) backfillFromDatabase(sub *Subscriber, cursor int64) e ) if err := rows.Scan(&seq, &commitCID, &rev, &sinceRev, &repoSlice, &opsJSON, &createdAt); err != nil { - log.Printf("Error scanning event row: %v", err) + slog.Error("Error scanning event row", "error", err) continue } // Deserialize ops from JSON var ops []*atproto.SyncSubscribeRepos_RepoOp if err := json.Unmarshal(opsJSON, &ops); err != nil { - log.Printf("Error unmarshaling ops for seq=%d: %v", seq, err) + slog.Error("Error unmarshaling ops", "seq", seq, "error", err) continue } @@ -562,7 +570,7 @@ func (b *EventBroadcaster) backfillFromDatabase(sub *Subscriber, cursor int64) e // Sent successfully case <-time.After(5 * time.Second): // Timeout, subscriber too slow - log.Printf("Backfill timeout for subscriber at seq=%d", seq) + slog.Warn("Backfill timeout for subscriber", "seq", seq) return nil } } @@ -582,7 +590,7 @@ func (b *EventBroadcaster) backfillFromMemory(sub *Subscriber, cursor int64) { // Sent case <-time.After(5 * time.Second): // Timeout, subscriber too slow - log.Printf("Backfill timeout for subscriber at seq=%d", he.Seq) + slog.Warn("Backfill timeout for subscriber", "seq", he.Seq) return } } @@ -606,13 +614,13 @@ func (b *EventBroadcaster) handleSubscriber(sub *Subscriber) { // Get a writer for this message wc, err := sub.conn.NextWriter(websocket.BinaryMessage) if err != nil { - log.Printf("Failed to get websocket writer: %v", err) + slog.Error("Failed to get websocket writer", "error", err) return } // Write header as CBOR if err := header.MarshalCBOR(wc); err != nil { - log.Printf("Failed to write event header: %v", err) + slog.Error("Failed to write event header", "error", err) wc.Close() return } @@ -623,14 +631,14 @@ func (b *EventBroadcaster) handleSubscriber(sub *Subscriber) { // Write the event as CBOR var obj lexutil.CBOR = indigoEvent if err := obj.MarshalCBOR(wc); err != nil { - log.Printf("Failed to write event body: %v", err) + slog.Error("Failed to write event body", "error", err) wc.Close() return } // Close the writer to flush the message if err := wc.Close(); err != nil { - log.Printf("Failed to close websocket writer: %v", err) + slog.Error("Failed to close websocket writer", "error", err) return } @@ -645,7 +653,9 @@ func convertToIndigoCommit(event *RepoCommitEvent) *atproto.SyncSubscribeRepos_C // Parse commit CID string to cid.Cid, then convert to LexLink commitCID, err := cid.Decode(event.Commit) if err != nil { - log.Printf("Warning: failed to parse commit CID %s: %v", event.Commit, err) + slog.Warn("Failed to parse commit CID", + "cid", event.Commit, + "error", err) // Create an empty CID as fallback commitCID = cid.Undef } diff --git a/pkg/hold/pds/keys.go b/pkg/hold/pds/keys.go index b1b0df1..81df124 100644 --- a/pkg/hold/pds/keys.go +++ b/pkg/hold/pds/keys.go @@ -2,6 +2,7 @@ package pds import ( "fmt" + "log/slog" "os" "path/filepath" @@ -42,7 +43,7 @@ func generateKey(keyPath string) (*atcrypto.PrivateKeyK256, error) { return nil, fmt.Errorf("failed to write key file: %w", err) } - fmt.Printf("Generated new K-256 signing key at %s\n", keyPath) + slog.Info("Generated new K-256 signing key", "path", keyPath) return privateKey, nil } @@ -59,7 +60,7 @@ func loadKey(keyPath string) (*atcrypto.PrivateKeyK256, error) { if err != nil { // Check if this is an old P-256 PEM key (migration) if isPEMFormat(keyBytes) { - fmt.Printf("⚠️ Detected old P-256 key, replacing with K-256...\n") + slog.Warn("Detected old P-256 key, replacing with K-256") // Generate new K-256 key (overwrites old P-256) return generateKey(keyPath) } @@ -67,7 +68,7 @@ func loadKey(keyPath string) (*atcrypto.PrivateKeyK256, error) { return nil, fmt.Errorf("failed to parse private key: %w", err) } - fmt.Printf("Loaded existing K-256 signing key from %s\n", keyPath) + slog.Info("Loaded existing K-256 signing key", "path", keyPath) return privateKey, nil } diff --git a/pkg/hold/pds/manifest_post.go b/pkg/hold/pds/manifest_post.go index 8f3ae55..3f39c2d 100644 --- a/pkg/hold/pds/manifest_post.go +++ b/pkg/hold/pds/manifest_post.go @@ -3,6 +3,7 @@ package pds import ( "context" "fmt" + "log/slog" "strings" "time" @@ -55,7 +56,9 @@ func (p *HoldPDS) CreateManifestPost( // Build ATProto URI for the post postURI := fmt.Sprintf("at://%s/app.bsky.feed.post/%s", p.did, rkey) - fmt.Printf("Created manifest post: %s (cid: %s)\n", postURI, recordCID) + slog.Info("Created manifest post", + "uri", postURI, + "cid", recordCID.String()) return postURI, nil } diff --git a/pkg/hold/pds/profile.go b/pkg/hold/pds/profile.go index f8cd4a6..bf46097 100644 --- a/pkg/hold/pds/profile.go +++ b/pkg/hold/pds/profile.go @@ -6,6 +6,7 @@ import ( "crypto/sha256" "fmt" "io" + "log/slog" "net/http" "time" @@ -137,20 +138,22 @@ func (p *HoldPDS) CreateProfileRecord(ctx context.Context, storageDriver driver. // Download and upload avatar if URL is provided if avatarURL != "" { - fmt.Printf("Downloading avatar from %s\n", avatarURL) + slog.Debug("Downloading avatar", "url", avatarURL) imageData, mimeType, err := downloadImage(ctx, avatarURL) if err != nil { return cid.Undef, fmt.Errorf("failed to download avatar: %w", err) } - fmt.Printf("Uploading avatar blob (%d bytes, %s)\n", len(imageData), mimeType) + slog.Debug("Uploading avatar blob", + "size", len(imageData), + "mimeType", mimeType) avatarBlob, err := uploadBlobToStorage(ctx, storageDriver, p.did, imageData, mimeType) if err != nil { return cid.Undef, fmt.Errorf("failed to upload avatar blob: %w", err) } profile.Avatar = avatarBlob - fmt.Printf("Avatar uploaded successfully: %s\n", avatarBlob.Ref.String()) + slog.Info("Avatar uploaded successfully", "ref", avatarBlob.Ref.String()) } // Use repomgr.PutRecord - creates with explicit rkey, fails if already exists @@ -159,7 +162,9 @@ func (p *HoldPDS) CreateProfileRecord(ctx context.Context, storageDriver driver. return cid.Undef, fmt.Errorf("failed to create profile record: %w", err) } - fmt.Printf("Created profile record at %s, cid: %s\n", recordPath, recordCID) + slog.Info("Created profile record", + "path", recordPath, + "cid", recordCID.String()) return recordCID, nil } @@ -200,7 +205,9 @@ func (p *HoldPDS) CreateTangledProfileRecord(ctx context.Context, links []string return cid.Undef, fmt.Errorf("failed to create tangled profile record: %w", err) } - fmt.Printf("Created tangled profile record at %s, cid: %s\n", recordPath, recordCID) + slog.Info("Created tangled profile record", + "path", recordPath, + "cid", recordCID.String()) return recordCID, nil } diff --git a/pkg/hold/pds/server.go b/pkg/hold/pds/server.go index 96b83a1..8ac991b 100644 --- a/pkg/hold/pds/server.go +++ b/pkg/hold/pds/server.go @@ -3,6 +3,7 @@ package pds import ( "context" "fmt" + "log/slog" "os" "path/filepath" "strings" @@ -92,7 +93,7 @@ func NewHoldPDS(ctx context.Context, did, publicURL, dbPath, keyPath string, ena // Initialize empty repo with first commit // RepoManager requires at least one commit to exist // We'll create this by doing a dummy operation in Bootstrap - fmt.Printf("New hold repo - will be initialized in Bootstrap\n") + slog.Info("New hold repo - will be initialized in Bootstrap") } return &HoldPDS{ @@ -134,9 +135,9 @@ func (p *HoldPDS) Bootstrap(ctx context.Context, storageDriver driver.StorageDri if captainExists { // Captain record exists, skip captain/crew setup but still create profile if needed - fmt.Printf("✅ Captain record exists, skipping captain/crew setup\n") + slog.Info("Captain record exists, skipping captain/crew setup") } else { - fmt.Printf("🚀 Bootstrapping hold PDS with owner: %s\n", ownerDID) + slog.Info("Bootstrapping hold PDS", "owner", ownerDID) } if !captainExists { @@ -151,7 +152,7 @@ func (p *HoldPDS) Bootstrap(ctx context.Context, storageDriver driver.StorageDri if err != nil { return fmt.Errorf("failed to initialize repo: %w", err) } - fmt.Printf("✅ Initialized empty repo\n") + slog.Info("Initialized empty repo") } // Create captain record (hold ownership and settings) @@ -160,7 +161,10 @@ func (p *HoldPDS) Bootstrap(ctx context.Context, storageDriver driver.StorageDri return fmt.Errorf("failed to create captain record: %w", err) } - fmt.Printf("✅ Created captain record (public=%v, allowAllCrew=%v, enableBlueskyPosts=%v)\n", public, allowAllCrew, p.enableBlueskyPosts) + slog.Info("Created captain record", + "public", public, + "allowAllCrew", allowAllCrew, + "enableBlueskyPosts", p.enableBlueskyPosts) // Add hold owner as first crew member with admin role _, err = p.AddCrewMember(ctx, ownerDID, "admin", []string{"blob:read", "blob:write", "crew:admin"}) @@ -168,7 +172,7 @@ func (p *HoldPDS) Bootstrap(ctx context.Context, storageDriver driver.StorageDri return fmt.Errorf("failed to add owner as crew member: %w", err) } - fmt.Printf("✅ Added %s as hold admin\n", ownerDID) + slog.Info("Added owner as hold admin", "did", ownerDID) } else { // Captain record exists, check if we need to sync settings from env vars _, existingCaptain, err := p.GetCaptainRecord(ctx) @@ -184,7 +188,10 @@ func (p *HoldPDS) Bootstrap(ctx context.Context, storageDriver driver.StorageDri if err != nil { return fmt.Errorf("failed to update captain record: %w", err) } - fmt.Printf("✅ Synced captain record with env vars (public=%v, allowAllCrew=%v, enableBlueskyPosts=%v)\n", public, allowAllCrew, p.enableBlueskyPosts) + slog.Info("Synced captain record with env vars", + "public", public, + "allowAllCrew", allowAllCrew, + "enableBlueskyPosts", p.enableBlueskyPosts) } } } @@ -203,9 +210,9 @@ func (p *HoldPDS) Bootstrap(ctx context.Context, storageDriver driver.StorageDri if err != nil { return fmt.Errorf("failed to create bluesky profile record: %w", err) } - fmt.Printf("✅ Created Bluesky profile record (displayName=%s)\n", displayName) + slog.Info("Created Bluesky profile record", "displayName", displayName) } else { - fmt.Printf("✅ Bluesky profile record already exists, skipping\n") + slog.Info("Bluesky profile record already exists, skipping") } } diff --git a/pkg/hold/pds/status.go b/pkg/hold/pds/status.go index 3e51682..02b6f18 100644 --- a/pkg/hold/pds/status.go +++ b/pkg/hold/pds/status.go @@ -3,6 +3,7 @@ package pds import ( "context" "fmt" + "log/slog" "time" bsky "github.com/bluesky-social/indigo/api/bsky" @@ -19,7 +20,7 @@ const ( func (p *HoldPDS) SetStatus(ctx context.Context, status string) error { // Check if Bluesky posts are enabled if !p.enableBlueskyPosts { - fmt.Printf("Bluesky posts disabled, skipping status post: %s\n", status) + slog.Debug("Bluesky posts disabled, skipping status post", "status", status) return nil } @@ -51,6 +52,10 @@ func (p *HoldPDS) createStatusPost(ctx context.Context, text string) error { return fmt.Errorf("failed to create status post: %w", err) } - fmt.Printf("Created status post at %s/%s (rkey: %s), cid: %s, text: %s\n", StatusPostCollection, rkey, rkey, recordCID, text) + slog.Info("Created status post", + "collection", StatusPostCollection, + "rkey", rkey, + "cid", recordCID.String(), + "text", text) return nil } diff --git a/pkg/hold/pds/xrpc.go b/pkg/hold/pds/xrpc.go index e3f5a11..bcb93f1 100644 --- a/pkg/hold/pds/xrpc.go +++ b/pkg/hold/pds/xrpc.go @@ -20,7 +20,7 @@ import ( "crypto/sha256" "io" - "log" + "log/slog" "net/http" "strconv" "strings" @@ -827,7 +827,7 @@ func (h *XRPCHandler) HandleGetRepo(w http.ResponseWriter, r *http.Request) { if err != nil { // Error already written to response by ReadRepo streaming // Log it but don't try to write another HTTP error - fmt.Printf("Error streaming repo CAR: %v\n", err) + slog.Error("Error streaming repo CAR", "error", err) return } } @@ -865,7 +865,7 @@ func (h *XRPCHandler) HandleSubscribeRepos(w http.ResponseWriter, r *http.Reques // Upgrade to WebSocket conn, err := upgrader.Upgrade(w, r, nil) if err != nil { - fmt.Printf("WebSocket upgrade failed: %v\n", err) + slog.Error("WebSocket upgrade failed", "error", err) return } @@ -970,7 +970,10 @@ func (h *XRPCHandler) HandleGetBlob(w http.ResponseWriter, r *http.Request) { did := r.URL.Query().Get("did") cidOrDigest := r.URL.Query().Get("cid") - log.Printf("[HandleGetBlob] %s request - did=%s, cid=%s", r.Method, did, cidOrDigest) + slog.Debug("HandleGetBlob request", + "method", r.Method, + "did", did, + "cid", cidOrDigest) if did == "" || cidOrDigest == "" { http.Error(w, "missing required parameters", http.StatusBadRequest) @@ -992,14 +995,14 @@ func (h *XRPCHandler) HandleGetBlob(w http.ResponseWriter, r *http.Request) { // Returns JSON with presigned URL for AppView integration // Authorization: Protected by hold access control (captain.public or crew with blob:read) func (h *XRPCHandler) handleGetOCIBlob(w http.ResponseWriter, r *http.Request, did, digest string) { - log.Printf("[handleGetOCIBlob] Processing OCI blob: %s", digest) + slog.Debug("Processing OCI blob", "digest", digest) // Validate blob read access (hold access control) // If captain.public = true, returns nil (public access allowed) // If captain.public = false, validates auth and checks for blob:read permission _, err := ValidateBlobReadAccess(r, h.pds, h.httpClient) if err != nil { - log.Printf("[handleGetOCIBlob] Authorization failed: %v", err) + slog.Warn("OCI blob authorization failed", "error", err, "digest", digest) http.Error(w, fmt.Sprintf("authorization failed: %v", err), http.StatusForbidden) return } @@ -1014,12 +1017,18 @@ func (h *XRPCHandler) handleGetOCIBlob(w http.ResponseWriter, r *http.Request, d // Generate presigned URL (use empty DID for content-addressed storage) presignedURL, err := h.GetPresignedURL(r.Context(), operation, digest, "") if err != nil { - log.Printf("[handleGetOCIBlob] Failed to get presigned %s URL: %v", operation, err) + slog.Error("Failed to get presigned URL for OCI blob", + "error", err, + "operation", operation, + "digest", digest) http.Error(w, "failed to get presigned URL", http.StatusInternalServerError) return } - log.Printf("[handleGetOCIBlob] Returning presigned %s URL: %s", operation, presignedURL) + slog.Debug("Returning presigned URL for OCI blob", + "operation", operation, + "digest", digest, + "url", presignedURL) // Return JSON response with presigned URL (AppView expects this format) response := map[string]string{ @@ -1033,11 +1042,13 @@ func (h *XRPCHandler) handleGetOCIBlob(w http.ResponseWriter, r *http.Request, d // Returns 307 redirect to presigned URL (standard ATProto behavior) // Authorization: Public per ATProto spec (no auth required) func (h *XRPCHandler) handleGetATProtoBlob(w http.ResponseWriter, r *http.Request, did, cid string) { - log.Printf("[handleGetATProtoBlob] Processing ATProto blob: %s", cid) + slog.Debug("Processing ATProto blob", "cid", cid) // Validate DID (ATProto blobs are stored per-DID for data sovereignty) if did != h.pds.DID() { - log.Printf("[handleGetATProtoBlob] DID mismatch: got %s, expected %s", did, h.pds.DID()) + slog.Warn("ATProto blob DID mismatch", + "got", did, + "expected", h.pds.DID()) http.Error(w, "invalid did", http.StatusBadRequest) return } @@ -1051,7 +1062,11 @@ func (h *XRPCHandler) handleGetATProtoBlob(w http.ResponseWriter, r *http.Reques // Generate presigned URL (use DID for per-DID storage path) presignedURL, err := h.GetPresignedURL(r.Context(), operation, cid, did) if err != nil { - log.Printf("[handleGetATProtoBlob] Failed to get presigned %s URL: %v", operation, err) + slog.Error("Failed to get presigned URL for ATProto blob", + "error", err, + "operation", operation, + "cid", cid, + "did", did) http.Error(w, "failed to get presigned URL", http.StatusInternalServerError) return } @@ -1170,7 +1185,7 @@ func (h *XRPCHandler) HandleAtprotoDID(w http.ResponseWriter, r *http.Request) { // This endpoint allows authenticated users to request crew membership // Authorization is checked against captain record settings func (h *XRPCHandler) HandleRequestCrew(w http.ResponseWriter, r *http.Request) { - log.Printf("[HandleRequestCrew] Starting crew membership request") + slog.Debug("Starting crew membership request") // Get authenticated user from context (if coming through middleware) // Otherwise validate directly (for tests or direct handler calls) @@ -1179,12 +1194,12 @@ func (h *XRPCHandler) HandleRequestCrew(w http.ResponseWriter, r *http.Request) var err error user, err = ValidateDPoPRequest(r, h.httpClient) if err != nil { - log.Printf("[HandleRequestCrew] Authentication failed: %v", err) + slog.Warn("Crew request authentication failed", "error", err) http.Error(w, fmt.Sprintf("authentication failed: %v", err), http.StatusUnauthorized) return } } - log.Printf("[HandleRequestCrew] Authenticated user: %s", user.DID) + slog.Debug("Authenticated user for crew request", "did", user.DID) // Parse request body (optional parameters) var req struct { @@ -1195,21 +1210,23 @@ func (h *XRPCHandler) HandleRequestCrew(w http.ResponseWriter, r *http.Request) // Body is optional - if empty, just use defaults if r.Body != nil && r.ContentLength > 0 { if err := json.NewDecoder(r.Body).Decode(&req); err != nil { - log.Printf("[HandleRequestCrew] Failed to parse request body: %v", err) + slog.Warn("Failed to parse crew request body", "error", err) http.Error(w, fmt.Sprintf("invalid request body: %v", err), http.StatusBadRequest) return } } // Get captain record to check authorization settings - log.Printf("[HandleRequestCrew] Getting captain record...") + slog.Debug("Getting captain record for crew request") _, captain, err := h.pds.GetCaptainRecord(r.Context()) if err != nil { - log.Printf("[HandleRequestCrew] Failed to get captain record: %v", err) + slog.Error("Failed to get captain record", "error", err) http.Error(w, fmt.Sprintf("failed to get captain record: %v", err), http.StatusInternalServerError) return } - log.Printf("[HandleRequestCrew] Captain record retrieved: owner=%s, allowAllCrew=%v", captain.Owner, captain.AllowAllCrew) + slog.Debug("Captain record retrieved", + "owner", captain.Owner, + "allowAllCrew", captain.AllowAllCrew) // Check authorization: // 1. If allowAllCrew is true, any authenticated user can join @@ -1231,19 +1248,21 @@ func (h *XRPCHandler) HandleRequestCrew(w http.ResponseWriter, r *http.Request) // Check if user is already a crew member // List all crew members and check if this DID is already present - log.Printf("[HandleRequestCrew] Checking existing crew membership...") + slog.Debug("Checking existing crew membership") crew, err := h.pds.ListCrewMembers(r.Context()) if err != nil { - log.Printf("[HandleRequestCrew] Failed to list crew members: %v", err) + slog.Error("Failed to list crew members", "error", err) http.Error(w, fmt.Sprintf("failed to list crew members: %v", err), http.StatusInternalServerError) return } - log.Printf("[HandleRequestCrew] Found %d existing crew members", len(crew)) + slog.Debug("Found existing crew members", "count", len(crew)) for _, member := range crew { if member.Record.Member == user.DID { // Already a crew member, return success with existing record - log.Printf("[HandleRequestCrew] User is already a crew member (rkey=%s)", member.Rkey) + slog.Debug("User is already a crew member", + "did", user.DID, + "rkey", member.Rkey) response := map[string]any{ "uri": fmt.Sprintf("at://%s/%s/%s", h.pds.DID(), atproto.CrewCollection, member.Rkey), "cid": member.Cid.String(), @@ -1258,14 +1277,21 @@ func (h *XRPCHandler) HandleRequestCrew(w http.ResponseWriter, r *http.Request) } // Create new crew record - log.Printf("[HandleRequestCrew] Creating new crew record for user %s (role=%s, permissions=%v)", user.DID, req.Role, req.Permissions) + slog.Debug("Creating new crew record", + "did", user.DID, + "role", req.Role, + "permissions", req.Permissions) recordCID, err := h.pds.AddCrewMember(r.Context(), user.DID, req.Role, req.Permissions) if err != nil { - log.Printf("[HandleRequestCrew] Failed to create crew record: %v", err) + slog.Error("Failed to create crew record", + "error", err, + "did", user.DID) http.Error(w, fmt.Sprintf("failed to create crew record: %v", err), http.StatusInternalServerError) return } - log.Printf("[HandleRequestCrew] Successfully created crew record (CID=%s)", recordCID.String()) + slog.Info("Successfully created crew record", + "did", user.DID, + "cid", recordCID.String()) // Return success response // Note: rkey is generated by AddCrewMember (TID), we don't have direct access to it @@ -1341,8 +1367,11 @@ func (h *XRPCHandler) GetPresignedURL(ctx context.Context, operation string, dig // Generate presigned URL with 15 minute expiry url, err := req.Presign(15 * time.Minute) if err != nil { - log.Printf("[getPresignedURL] Presign FAILED for %s: %v", operation, err) - log.Printf(" Falling back to XRPC endpoint") + slog.Warn("Presign failed, falling back to XRPC endpoint", + "error", err, + "operation", operation, + "digest", digest) + slog.Debug("Using XRPC proxy fallback") proxyURL := getProxyURL(h.pds.PublicURL, digest, did, operation) if proxyURL == "" { return "", fmt.Errorf("presign failed and XRPC proxy not supported for PUT operations")