fix(storage): surface all silent errors with structured logging

- Inject *slog.Logger into HybridStore, PocketBaseStore, and pbClient
- Fix credential defaults in main.go (changeme123 / admin) to match docker-compose
- listOne/listAll/upsert/deleteWhere now return errors on non-2xx HTTP status
- WriteChapter: log warn instead of discarding UpsertChapterIdx error
- MetadataMtime, GetAudioCache, GetProgress: log warn on PocketBase failures
- EnsureCollections: log info/debug/warn per outcome instead of _ = err
- CountChapterIdx: log warn on failure instead of silently returning 0
- server: log warn when SetAudioCache fails after audio generation
- NewHybridStore: add explicit Ping() before EnsureCollections for fast-fail on bad credentials
This commit is contained in:
Admin
2026-03-03 22:31:14 +05:00
parent c2bcb2b0a6
commit 7acf04fb9f
4 changed files with 97 additions and 29 deletions

View File

@@ -99,8 +99,8 @@ func run(log *slog.Logger) error {
// ── Storage backends ──────────────────────────────────────────────────── // ── Storage backends ────────────────────────────────────────────────────
minioCfg := storage.MinioConfig{ minioCfg := storage.MinioConfig{
Endpoint: envOr("MINIO_ENDPOINT", "localhost:9000"), Endpoint: envOr("MINIO_ENDPOINT", "localhost:9000"),
AccessKey: envOr("MINIO_ACCESS_KEY", "minioadmin"), AccessKey: envOr("MINIO_ACCESS_KEY", "admin"),
SecretKey: envOr("MINIO_SECRET_KEY", "minioadmin"), SecretKey: envOr("MINIO_SECRET_KEY", "changeme123"),
UseSSL: strings.ToLower(os.Getenv("MINIO_USE_SSL")) == "true", UseSSL: strings.ToLower(os.Getenv("MINIO_USE_SSL")) == "true",
BucketChapters: envOr("MINIO_BUCKET_CHAPTERS", "libnovel-chapters"), BucketChapters: envOr("MINIO_BUCKET_CHAPTERS", "libnovel-chapters"),
BucketAudio: envOr("MINIO_BUCKET_AUDIO", "libnovel-audio"), BucketAudio: envOr("MINIO_BUCKET_AUDIO", "libnovel-audio"),
@@ -108,13 +108,13 @@ func run(log *slog.Logger) error {
pbCfg := storage.PocketBaseConfig{ pbCfg := storage.PocketBaseConfig{
BaseURL: envOr("POCKETBASE_URL", "http://localhost:8090"), BaseURL: envOr("POCKETBASE_URL", "http://localhost:8090"),
AdminEmail: envOr("POCKETBASE_EMAIL", "admin@libnovel.local"), AdminEmail: envOr("POCKETBASE_EMAIL", "admin@libnovel.local"),
AdminPassword: envOr("POCKETBASE_PASSWORD", "adminpassword"), AdminPassword: envOr("POCKETBASE_PASSWORD", "changeme123"),
} }
ctx, stop := signal.NotifyContext(context.Background(), syscall.SIGINT, syscall.SIGTERM) ctx, stop := signal.NotifyContext(context.Background(), syscall.SIGINT, syscall.SIGTERM)
defer stop() defer stop()
store, err := storage.NewHybridStore(ctx, pbCfg, minioCfg) store, err := storage.NewHybridStore(ctx, pbCfg, minioCfg, log)
if err != nil { if err != nil {
return fmt.Errorf("storage init failed: %w", err) return fmt.Errorf("storage init failed: %w", err)
} }

View File

@@ -428,7 +428,9 @@ func (s *Server) handleAudioGenerate(w http.ResponseWriter, r *http.Request) {
return return
} }
_ = s.store.SetAudioCache(r.Context(), cacheKey, filename) if err := s.store.SetAudioCache(r.Context(), cacheKey, filename); err != nil {
s.log.Warn("audio cache write failed", "slug", slug, "chapter", n, "cache_key", cacheKey, "err", err)
}
// Download generated audio from Kokoro and persist to MinIO so that // Download generated audio from Kokoro and persist to MinIO so that
// presigned URLs for the audio object are accessible. // presigned URLs for the audio object are accessible.

View File

@@ -6,6 +6,7 @@ import (
"context" "context"
"encoding/json" "encoding/json"
"fmt" "fmt"
"log/slog"
"sort" "sort"
"strconv" "strconv"
"strings" "strings"
@@ -19,21 +20,26 @@ import (
type HybridStore struct { type HybridStore struct {
pb *PocketBaseStore pb *PocketBaseStore
minio *MinioClient minio *MinioClient
log *slog.Logger
} }
// NewHybridStore constructs a HybridStore. It connects to both backends and // NewHybridStore constructs a HybridStore. It connects to both backends and
// calls EnsureCollections to bootstrap any missing PocketBase collections. // calls EnsureCollections to bootstrap any missing PocketBase collections.
func NewHybridStore(ctx context.Context, pbCfg PocketBaseConfig, minioCfg MinioConfig) (*HybridStore, error) { func NewHybridStore(ctx context.Context, pbCfg PocketBaseConfig, minioCfg MinioConfig, log *slog.Logger) (*HybridStore, error) {
mc, err := NewMinioClient(ctx, minioCfg) mc, err := NewMinioClient(ctx, minioCfg)
if err != nil { if err != nil {
return nil, fmt.Errorf("storage: minio: %w", err) return nil, fmt.Errorf("storage: minio: %w", err)
} }
pb := NewPocketBaseStore(pbCfg) pb := NewPocketBaseStore(pbCfg, log)
if err := pb.EnsureCollections(ctx); err != nil { // Verify PocketBase credentials before proceeding.
// Log but don't fail — collection creation errors are often "already exists" if err := pb.Ping(ctx); err != nil {
_ = err return nil, fmt.Errorf("storage: pocketbase auth: %w", err)
} }
return &HybridStore{pb: pb, minio: mc}, nil if err := pb.EnsureCollections(ctx); err != nil {
// Non-fatal: 400/422 means collections already exist.
log.Warn("EnsureCollections returned an error (may be safe to ignore)", "err", err)
}
return &HybridStore{pb: pb, minio: mc, log: log}, nil
} }
// ─── Book metadata ──────────────────────────────────────────────────────────── // ─── Book metadata ────────────────────────────────────────────────────────────
@@ -80,7 +86,11 @@ func (h *HybridStore) LocalSlugs(ctx context.Context) (map[string]bool, error) {
func (h *HybridStore) MetadataMtime(ctx context.Context, slug string) int64 { func (h *HybridStore) MetadataMtime(ctx context.Context, slug string) int64 {
t, err := h.pb.BookMetaUpdated(ctx, slug) t, err := h.pb.BookMetaUpdated(ctx, slug)
if err != nil || t.IsZero() { if err != nil {
h.log.Warn("MetadataMtime: BookMetaUpdated failed", "slug", slug, "err", err)
return 0
}
if t.IsZero() {
return 0 return 0
} }
return t.Unix() return t.Unix()
@@ -99,7 +109,10 @@ func (h *HybridStore) WriteChapter(ctx context.Context, slug string, chapter scr
} }
// Update chapter index in PocketBase. // Update chapter index in PocketBase.
title, dateLabel := splitChapterTitle(chapter.Ref.Title) title, dateLabel := splitChapterTitle(chapter.Ref.Title)
_ = h.pb.UpsertChapterIdx(ctx, slug, chapter.Ref.Number, title, dateLabel) if err := h.pb.UpsertChapterIdx(ctx, slug, chapter.Ref.Number, title, dateLabel); err != nil {
h.log.Warn("WriteChapter: failed to upsert chapter index in PocketBase",
"slug", slug, "chapter", chapter.Ref.Number, "err", err)
}
return nil return nil
} }
@@ -151,7 +164,10 @@ func (h *HybridStore) RankingFreshEnough(ctx context.Context, maxAge time.Durati
// ─── Audio cache ────────────────────────────────────────────────────────────── // ─── Audio cache ──────────────────────────────────────────────────────────────
func (h *HybridStore) GetAudioCache(ctx context.Context, cacheKey string) (string, bool) { func (h *HybridStore) GetAudioCache(ctx context.Context, cacheKey string) (string, bool) {
filename, ok, _ := h.pb.GetAudioCache(ctx, cacheKey) filename, ok, err := h.pb.GetAudioCache(ctx, cacheKey)
if err != nil {
h.log.Warn("GetAudioCache: PocketBase lookup failed", "cache_key", cacheKey, "err", err)
}
return filename, ok return filename, ok
} }
@@ -163,7 +179,11 @@ func (h *HybridStore) SetAudioCache(ctx context.Context, cacheKey, filename stri
func (h *HybridStore) GetProgress(ctx context.Context, sessionID, slug string) (ReadingProgress, bool) { func (h *HybridStore) GetProgress(ctx context.Context, sessionID, slug string) (ReadingProgress, bool) {
ch, updated, ok, err := h.pb.GetProgress(ctx, sessionID, slug) ch, updated, ok, err := h.pb.GetProgress(ctx, sessionID, slug)
if err != nil || !ok { if err != nil {
h.log.Warn("GetProgress: PocketBase lookup failed", "slug", slug, "err", err)
return ReadingProgress{}, false
}
if !ok {
return ReadingProgress{}, false return ReadingProgress{}, false
} }
return ReadingProgress{Slug: slug, Chapter: ch, UpdatedAt: updated}, true return ReadingProgress{Slug: slug, Chapter: ch, UpdatedAt: updated}, true

View File

@@ -18,6 +18,7 @@ import (
"encoding/json" "encoding/json"
"fmt" "fmt"
"io" "io"
"log/slog"
"net/http" "net/http"
"net/url" "net/url"
"strings" "strings"
@@ -36,6 +37,7 @@ type PocketBaseConfig struct {
type pbClient struct { type pbClient struct {
cfg PocketBaseConfig cfg PocketBaseConfig
httpClient *http.Client httpClient *http.Client
log *slog.Logger
tokenMu sync.RWMutex tokenMu sync.RWMutex
token string token string
@@ -44,10 +46,11 @@ type pbClient struct {
// newPBClient creates a new PocketBase client. It does not authenticate yet; // newPBClient creates a new PocketBase client. It does not authenticate yet;
// authentication happens lazily on the first API call. // authentication happens lazily on the first API call.
func newPBClient(cfg PocketBaseConfig) *pbClient { func newPBClient(cfg PocketBaseConfig, log *slog.Logger) *pbClient {
return &pbClient{ return &pbClient{
cfg: cfg, cfg: cfg,
httpClient: &http.Client{Timeout: 15 * time.Second}, httpClient: &http.Client{Timeout: 15 * time.Second},
log: log,
} }
} }
@@ -140,11 +143,15 @@ func (p *pbClient) listOne(ctx context.Context, collection, filter string) (map[
if resp.StatusCode == http.StatusNotFound { if resp.StatusCode == http.StatusNotFound {
return nil, nil return nil, nil
} }
if resp.StatusCode != http.StatusOK {
b, _ := io.ReadAll(resp.Body)
return nil, fmt.Errorf("pocketbase: listOne %s: status %d: %s", collection, resp.StatusCode, b)
}
var result struct { var result struct {
Items []map[string]interface{} `json:"items"` Items []map[string]interface{} `json:"items"`
} }
if err := json.NewDecoder(resp.Body).Decode(&result); err != nil { if err := json.NewDecoder(resp.Body).Decode(&result); err != nil {
return nil, err return nil, fmt.Errorf("pocketbase: listOne %s: decode: %w", collection, err)
} }
if len(result.Items) == 0 { if len(result.Items) == 0 {
return nil, nil return nil, nil
@@ -168,11 +175,15 @@ func (p *pbClient) listAll(ctx context.Context, collection, filter, sort string)
return nil, err return nil, err
} }
defer resp.Body.Close() defer resp.Body.Close()
if resp.StatusCode != http.StatusOK {
b, _ := io.ReadAll(resp.Body)
return nil, fmt.Errorf("pocketbase: listAll %s: status %d: %s", collection, resp.StatusCode, b)
}
var result struct { var result struct {
Items []map[string]interface{} `json:"items"` Items []map[string]interface{} `json:"items"`
} }
if err := json.NewDecoder(resp.Body).Decode(&result); err != nil { if err := json.NewDecoder(resp.Body).Decode(&result); err != nil {
return nil, err return nil, fmt.Errorf("pocketbase: listAll %s: decode: %w", collection, err)
} }
return result.Items, nil return result.Items, nil
} }
@@ -190,7 +201,11 @@ func (p *pbClient) upsert(ctx context.Context, collection, filter string, data m
if err != nil { if err != nil {
return err return err
} }
resp.Body.Close() defer resp.Body.Close()
if resp.StatusCode != http.StatusOK {
b, _ := io.ReadAll(resp.Body)
return fmt.Errorf("pocketbase: upsert (patch) %s id=%s: status %d: %s", collection, id, resp.StatusCode, b)
}
return nil return nil
} }
resp, err := p.do(ctx, http.MethodPost, resp, err := p.do(ctx, http.MethodPost,
@@ -198,7 +213,11 @@ func (p *pbClient) upsert(ctx context.Context, collection, filter string, data m
if err != nil { if err != nil {
return err return err
} }
resp.Body.Close() defer resp.Body.Close()
if resp.StatusCode != http.StatusOK && resp.StatusCode != http.StatusCreated {
b, _ := io.ReadAll(resp.Body)
return fmt.Errorf("pocketbase: upsert (create) %s: status %d: %s", collection, resp.StatusCode, b)
}
return nil return nil
} }
@@ -215,7 +234,11 @@ func (p *pbClient) deleteWhere(ctx context.Context, collection, filter string) e
if err != nil { if err != nil {
return err return err
} }
resp.Body.Close() defer resp.Body.Close()
if resp.StatusCode != http.StatusNoContent && resp.StatusCode != http.StatusOK {
b, _ := io.ReadAll(resp.Body)
return fmt.Errorf("pocketbase: deleteWhere %s id=%s: status %d: %s", collection, id, resp.StatusCode, b)
}
} }
return nil return nil
} }
@@ -225,12 +248,13 @@ func (p *pbClient) deleteWhere(ctx context.Context, collection, filter string) e
// PocketBaseStore implements the structured-data portion of the Store interface // PocketBaseStore implements the structured-data portion of the Store interface
// backed by PocketBase REST API. // backed by PocketBase REST API.
type PocketBaseStore struct { type PocketBaseStore struct {
pb *pbClient pb *pbClient
log *slog.Logger
} }
// NewPocketBaseStore returns a connected PocketBaseStore. // NewPocketBaseStore returns a connected PocketBaseStore.
func NewPocketBaseStore(cfg PocketBaseConfig) *PocketBaseStore { func NewPocketBaseStore(cfg PocketBaseConfig, log *slog.Logger) *PocketBaseStore {
return &PocketBaseStore{pb: newPBClient(cfg)} return &PocketBaseStore{pb: newPBClient(cfg, log), log: log}
} }
// Ping verifies connectivity by authenticating. // Ping verifies connectivity by authenticating.
@@ -323,12 +347,23 @@ func (s *PocketBaseStore) EnsureCollections(ctx context.Context) error {
}, },
} }
for _, col := range collections { for _, col := range collections {
name, _ := col["name"].(string)
resp, err := s.pb.do(ctx, http.MethodPost, "/api/collections", col) resp, err := s.pb.do(ctx, http.MethodPost, "/api/collections", col)
if err != nil { if err != nil {
return fmt.Errorf("pocketbase: ensure collection %v: %w", col["name"], err) return fmt.Errorf("pocketbase: ensure collection %q: %w", name, err)
} }
b, _ := io.ReadAll(resp.Body)
resp.Body.Close() resp.Body.Close()
// 400/422 = already exists or schema mismatch — ignore switch resp.StatusCode {
case http.StatusOK, http.StatusCreated:
s.log.Info("pocketbase: collection created", "collection", name)
case http.StatusBadRequest, http.StatusUnprocessableEntity:
// Already exists or schema mismatch — expected on subsequent startups.
s.log.Debug("pocketbase: collection already exists (skipped)", "collection", name)
default:
s.log.Warn("pocketbase: unexpected status ensuring collection",
"collection", name, "status", resp.StatusCode, "body", string(b))
}
} }
return nil return nil
} }
@@ -400,7 +435,11 @@ func (s *PocketBaseStore) ListChapterIdx(ctx context.Context, slug string) ([]ma
} }
func (s *PocketBaseStore) CountChapterIdx(ctx context.Context, slug string) int { func (s *PocketBaseStore) CountChapterIdx(ctx context.Context, slug string) int {
rows, _ := s.ListChapterIdx(ctx, slug) rows, err := s.ListChapterIdx(ctx, slug)
if err != nil {
s.log.Warn("pocketbase: CountChapterIdx failed", "slug", slug, "err", err)
return 0
}
return len(rows) return len(rows)
} }
@@ -468,11 +507,15 @@ func (s *PocketBaseStore) RankingLastUpdated(ctx context.Context) (time.Time, er
return time.Time{}, err return time.Time{}, err
} }
defer resp.Body.Close() defer resp.Body.Close()
if resp.StatusCode != http.StatusOK {
b, _ := io.ReadAll(resp.Body)
return time.Time{}, fmt.Errorf("pocketbase: RankingLastUpdated: status %d: %s", resp.StatusCode, b)
}
var result struct { var result struct {
Items []map[string]interface{} `json:"items"` Items []map[string]interface{} `json:"items"`
} }
if err := json.NewDecoder(resp.Body).Decode(&result); err != nil { if err := json.NewDecoder(resp.Body).Decode(&result); err != nil {
return time.Time{}, err return time.Time{}, fmt.Errorf("pocketbase: RankingLastUpdated: decode: %w", err)
} }
if len(result.Items) == 0 { if len(result.Items) == 0 {
return time.Time{}, nil return time.Time{}, nil
@@ -537,9 +580,12 @@ func (s *PocketBaseStore) SetAudioCache(ctx context.Context, cacheKey, filename
func (s *PocketBaseStore) GetAudioCache(ctx context.Context, cacheKey string) (string, bool, error) { func (s *PocketBaseStore) GetAudioCache(ctx context.Context, cacheKey string) (string, bool, error) {
rec, err := s.pb.listOne(ctx, "audio_cache", rec, err := s.pb.listOne(ctx, "audio_cache",
fmt.Sprintf(`cache_key="%s"`, pbEsc(cacheKey))) fmt.Sprintf(`cache_key="%s"`, pbEsc(cacheKey)))
if err != nil || rec == nil { if err != nil {
return "", false, err return "", false, err
} }
if rec == nil {
return "", false, nil
}
filename, _ := rec["filename"].(string) filename, _ := rec["filename"].(string)
return filename, filename != "", nil return filename, filename != "", nil
} }