From 58d9c0a9c0022ca8e817cf782ca8aecc4c74ac71 Mon Sep 17 00:00:00 2001 From: LovroG05 Date: Wed, 1 Jul 2026 16:16:49 +0200 Subject: [PATCH] perf: lazy-load log content, populate user_id, keyset-paginate admin logs MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Admin logs list no longer joins prompt/completion content for every row — content is fetched per-row only when a log is expanded in the dashboard, since a table of chat-length blobs was slow to serialize even at low row counts. request_logs.user_id (previously unpopulated despite an index existing on it) is now set from the owning key on every insert, including synthetic dashboard keys, and log queries filter on it directly instead of a virtual_keys subquery. Pagination switches from OFFSET to a (created_at, id) keyset cursor so paging deep into the log stays cheap. Adds indexes on provider_name/key_prefix used by the admin filters. --- backend/dashboard/src/lib/api.ts | 6 +- backend/dashboard/src/pages/Logs.tsx | 64 ++++++++++++++++-- backend/internal/api/admin.go | 28 ++++++++ backend/internal/api/api.go | 1 + backend/internal/api/chat.go | 1 + backend/internal/api/middleware.go | 3 + backend/internal/store/request_logs.go | 67 +++++++++++++++---- ...000004_request_logs_optimizations.down.sql | 2 + .../000004_request_logs_optimizations.up.sql | 13 ++++ 9 files changed, 166 insertions(+), 19 deletions(-) create mode 100644 backend/migrations/000004_request_logs_optimizations.down.sql create mode 100644 backend/migrations/000004_request_logs_optimizations.up.sql diff --git a/backend/dashboard/src/lib/api.ts b/backend/dashboard/src/lib/api.ts index a1312fa..9ae5ccc 100644 --- a/backend/dashboard/src/lib/api.ts +++ b/backend/dashboard/src/lib/api.ts @@ -56,15 +56,19 @@ export const api = { req<{ status: string; models: number }>('/catalog/refresh', { method: 'POST' }), }, logs: { - list: (params: { provider?: string; key?: string; status?: string; since?: string } = {}) => { + list: (params: { provider?: string; key?: string; status?: string; since?: string; before?: string; beforeId?: string } = {}) => { const qs = new URLSearchParams() if (params.provider) qs.set('provider', params.provider) if (params.key) qs.set('key', params.key) if (params.status) qs.set('status', params.status) if (params.since) qs.set('since', params.since) + if (params.before) qs.set('before', params.before) + if (params.beforeId) qs.set('before_id', params.beforeId) const s = qs.toString() return req('/logs' + (s ? '?' + s : '')) }, + content: (id: string) => + req<{ Messages: RequestLog['Messages']; Completion: RequestLog['Completion'] }>(`/logs/${id}/content`), }, stats: { keys: (since?: string) => { diff --git a/backend/dashboard/src/pages/Logs.tsx b/backend/dashboard/src/pages/Logs.tsx index 76fc043..3f4a6e0 100644 --- a/backend/dashboard/src/pages/Logs.tsx +++ b/backend/dashboard/src/pages/Logs.tsx @@ -15,7 +15,10 @@ function fmtTime(iso: string) { return new Date(iso).toLocaleTimeString([], { hour: '2-digit', minute: '2-digit', second: '2-digit' }) } -function ContentDrawer({ log }: { log: RequestLog }) { +function ContentDrawer({ log, loading }: { log: RequestLog; loading: boolean }) { + if (loading) { + return
Loading…
+ } if (!log.Messages && !log.Completion) { return
No content logged
} @@ -53,21 +56,46 @@ function ContentDrawer({ log }: { log: RequestLog }) { ) } +const PAGE_SIZE = 100 + export default function Logs() { const [searchParams, setSearchParams] = useSearchParams() const [logs, setLogs] = useState([]) const [loading, setLoading] = useState(true) + const [loadingMore, setLoadingMore] = useState(false) + const [hasMore, setHasMore] = useState(false) const [rangeIdx, setRangeIdx] = useState(1) const [search, setSearch] = useState(() => searchParams.get('key') ?? '') const [expanded, setExpanded] = useState(null) + const [content, setContent] = useState>>({}) + const [contentLoading, setContentLoading] = useState(null) useEffect(() => { setLoading(true) api.logs.list({ since: new Date(Date.now() - RANGES[rangeIdx].ms).toISOString() }) - .then(r => setLogs(r ?? [])) + .then(r => { + setLogs(r ?? []) + setHasMore((r ?? []).length === PAGE_SIZE) + }) .finally(() => setLoading(false)) }, [rangeIdx]) + function loadMore() { + const last = logs[logs.length - 1] + if (!last) return + setLoadingMore(true) + api.logs.list({ + since: new Date(Date.now() - RANGES[rangeIdx].ms).toISOString(), + before: last.CreatedAt, + beforeId: last.ID, + }) + .then(r => { + setLogs(prev => [...prev, ...(r ?? [])]) + setHasMore((r ?? []).length === PAGE_SIZE) + }) + .finally(() => setLoadingMore(false)) + } + // Sync search → URL param so links from ApiKeys page work. useEffect(() => { if (search) setSearchParams({ key: search }, { replace: true }) @@ -82,6 +110,20 @@ export default function Logs() { l.RequestID.includes(search) ) + function toggleExpand(id: string) { + if (expanded === id) { + setExpanded(null) + return + } + setExpanded(id) + if (!content[id]) { + setContentLoading(id) + api.logs.content(id) + .then(c => setContent(prev => ({ ...prev, [id]: c }))) + .finally(() => setContentLoading(null)) + } + } + const cols = '80px 1fr 110px 80px 90px 72px 58px 22px' return ( @@ -122,7 +164,7 @@ export default function Logs() { return (
setExpanded(isOpen ? null : l.ID)} + onClick={() => toggleExpand(l.ID)} style={{ display: 'grid', gridTemplateColumns: cols, padding: '9px 16px', alignItems: 'center', cursor: 'pointer' }} > {fmtTime(l.CreatedAt)} @@ -142,10 +184,24 @@ export default function Logs() {
- {isOpen && } + {isOpen && ( + + )}
) })} + + {!loading && hasMore && ( +
+ +
+ )} ) diff --git a/backend/internal/api/admin.go b/backend/internal/api/admin.go index dbee4b0..c0ec0a8 100644 --- a/backend/internal/api/admin.go +++ b/backend/internal/api/admin.go @@ -304,6 +304,15 @@ func (a *API) adminListLogs(w http.ResponseWriter, r *http.Request) { p.Since = t } } + // Cursor for "load more": the CreatedAt/ID of the last row already shown. + if before := q.Get("before"); before != "" { + if t, err := time.Parse(time.RFC3339Nano, before); err == nil { + if id, err := uuid.Parse(q.Get("before_id")); err == nil { + p.Before = t + p.BeforeID = id + } + } + } rows, err := a.Store.ListRequestLogs(r.Context(), p) if err != nil { writeError(w, http.StatusInternalServerError, err.Error()) @@ -315,6 +324,25 @@ func (a *API) adminListLogs(w http.ResponseWriter, r *http.Request) { writeJSON(w, http.StatusOK, rows) } +func (a *API) adminGetLogContent(w http.ResponseWriter, r *http.Request) { + id, err := uuid.Parse(chi.URLParam(r, "id")) + if err != nil { + writeError(w, http.StatusBadRequest, "invalid log id") + return + } + au := userFrom(r.Context()) + var userID *uuid.UUID + if au != nil && !au.IsAdmin { + userID = &au.User.ID + } + messages, completion, err := a.Store.GetLogContent(r.Context(), id, userID) + if err != nil { + writeError(w, http.StatusInternalServerError, err.Error()) + return + } + writeJSON(w, http.StatusOK, map[string]any{"Messages": messages, "Completion": completion}) +} + func (a *API) adminKeyStats(w http.ResponseWriter, r *http.Request) { since := time.Now().Add(-24 * time.Hour) if s := r.URL.Query().Get("since"); s != "" { diff --git a/backend/internal/api/api.go b/backend/internal/api/api.go index 2979ff7..04b1acc 100644 --- a/backend/internal/api/api.go +++ b/backend/internal/api/api.go @@ -99,6 +99,7 @@ func (a *API) Mount(r chi.Router) { r.Post("/keys", a.adminCreateKey) r.Delete("/keys/{id}", a.adminRevokeKey) r.Get("/logs", a.adminListLogs) + r.Get("/logs/{id}/content", a.adminGetLogContent) r.Get("/stats/keys", a.adminKeyStats) // The following routes require admin group membership. diff --git a/backend/internal/api/chat.go b/backend/internal/api/chat.go index 415a3a5..6b2e983 100644 --- a/backend/internal/api/chat.go +++ b/backend/internal/api/chat.go @@ -178,6 +178,7 @@ func (a *API) logRequest(r *http.Request, key *store.VirtualKey, entry *catalog. } if key != nil { rec.KeyPrefix = key.KeyPrefix + rec.UserID = key.UserID // Only set VirtualKeyID for real keys — synthetic dashboard keys have a nil UUID. if key.ID != uuid.Nil { rec.VirtualKeyID = &key.ID diff --git a/backend/internal/api/middleware.go b/backend/internal/api/middleware.go index c924f2a..9380f24 100644 --- a/backend/internal/api/middleware.go +++ b/backend/internal/api/middleware.go @@ -78,6 +78,9 @@ func (a *API) requireAuth(next http.Handler) http.Handler { func (a *API) dashboardKeyAuth(next http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { synthetic := &store.VirtualKey{AllowAllModels: true, KeyPrefix: "dashboard"} + if au := userFrom(r.Context()); au != nil { + synthetic.UserID = &au.User.ID + } next.ServeHTTP(w, r.WithContext(context.WithValue(r.Context(), keyCtxKey, synthetic))) }) } diff --git a/backend/internal/store/request_logs.go b/backend/internal/store/request_logs.go index 5d9eabd..2cd25e1 100644 --- a/backend/internal/store/request_logs.go +++ b/backend/internal/store/request_logs.go @@ -3,15 +3,18 @@ package store import ( "context" "encoding/json" + "errors" "net/netip" "time" "github.com/google/uuid" + "github.com/jackc/pgx/v5" ) // RequestLog is one row to append to request_logs (billing source of truth). type RequestLog struct { VirtualKeyID *uuid.UUID + UserID *uuid.UUID // owner of the key used (set even for synthetic dashboard keys) ProviderModelID *uuid.UUID ProviderID *uuid.UUID KeyPrefix string @@ -36,14 +39,14 @@ func (s *Store) InsertRequestLog(ctx context.Context, e RequestLog) (uuid.UUID, var id uuid.UUID err := s.pool.QueryRow(ctx, ` INSERT INTO request_logs ( - virtual_key_id, provider_model_id, provider_id, + virtual_key_id, user_id, provider_model_id, provider_id, key_prefix, model_name, provider_name, status_code, streamed, finish_reason, error, prompt_tokens, completion_tokens, cached_tokens, total_tokens, cost, latency_ms, ttft_ms, request_id, client_ip - ) VALUES ($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12,$13,$14,$15,$16,$17,$18,$19) + ) VALUES ($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12,$13,$14,$15,$16,$17,$18,$19,$20) RETURNING id`, - e.VirtualKeyID, e.ProviderModelID, e.ProviderID, + e.VirtualKeyID, e.UserID, e.ProviderModelID, e.ProviderID, nullString(e.KeyPrefix), nullString(e.ModelName), nullString(e.ProviderName), e.StatusCode, e.Streamed, nullString(e.FinishReason), nullString(e.Error), e.PromptTokens, e.CompletionTokens, e.CachedTokens, e.TotalTokens, @@ -97,10 +100,18 @@ type ListLogsParams struct { StatusLt int // 0 = no upper bound Since time.Time Limit int - Offset int + // Before/BeforeID page backwards from a cursor: only rows strictly older + // than (Before, BeforeID) in the (created_at DESC, id DESC) ordering are + // returned. Pass the last row of the previous page. Zero value = first page. + // Keyset pagination instead of OFFSET so paging deep into the log stays + // O(limit) rather than re-scanning and discarding every skipped row. + Before time.Time + BeforeID uuid.UUID } -// ListRequestLogs returns recent request logs for the admin view, with content joined in. +// ListRequestLogs returns recent request logs for the admin view. Content +// (prompt/completion) is fetched separately per row on demand — joining it +// here would pull every logged conversation's full text on every page load. func (s *Store) ListRequestLogs(ctx context.Context, p ListLogsParams) ([]RequestLogListRow, error) { if p.Limit <= 0 { p.Limit = 50 @@ -109,24 +120,29 @@ func (s *Store) ListRequestLogs(ctx context.Context, p ListLogsParams) ([]Reques if !p.Since.IsZero() { since = &p.Since } + var before *time.Time + var beforeID *uuid.UUID + if !p.Before.IsZero() { + before = &p.Before + beforeID = &p.BeforeID + } rows, err := s.pool.Query(ctx, ` SELECT rl.id::text, rl.created_at, COALESCE(rl.request_id,''), COALESCE(rl.key_prefix,''), COALESCE(rl.model_name,''), COALESCE(rl.provider_name,''), rl.status_code, rl.streamed, COALESCE(rl.error,''), rl.prompt_tokens, rl.completion_tokens, rl.total_tokens, - rl.cost, rl.latency_ms, rl.ttft_ms, - rlc.messages, rlc.completion + rl.cost, rl.latency_ms, rl.ttft_ms FROM request_logs rl - LEFT JOIN request_log_content rlc ON rlc.request_log_id = rl.id WHERE ($1 = '' OR rl.provider_name = $1) AND ($2 = '' OR rl.key_prefix = $2) - AND ($3::uuid IS NULL OR rl.virtual_key_id IN (SELECT id FROM virtual_keys WHERE user_id = $3)) + AND ($3::uuid IS NULL OR rl.user_id = $3) AND ($4 = 0 OR rl.status_code >= $4) AND ($5 = 0 OR rl.status_code < $5) AND ($6::timestamptz IS NULL OR rl.created_at >= $6) - ORDER BY rl.created_at DESC - LIMIT $7 OFFSET $8`, - p.Provider, p.KeyPrefix, p.UserID, p.StatusGte, p.StatusLt, since, p.Limit, p.Offset, + AND ($7::timestamptz IS NULL OR (rl.created_at, rl.id) < ($7, $8)) + ORDER BY rl.created_at DESC, rl.id DESC + LIMIT $9`, + p.Provider, p.KeyPrefix, p.UserID, p.StatusGte, p.StatusLt, since, before, beforeID, p.Limit, ) if err != nil { return nil, err @@ -141,7 +157,6 @@ func (s *Store) ListRequestLogs(ctx context.Context, p ListLogsParams) ([]Reques &r.StatusCode, &r.Streamed, &r.Error, &r.PromptTokens, &r.CompletionTokens, &r.TotalTokens, &r.Cost, &r.LatencyMS, &r.TTFTMs, - &r.Messages, &r.Completion, ); err != nil { return nil, err } @@ -150,6 +165,30 @@ func (s *Store) ListRequestLogs(ctx context.Context, p ListLogsParams) ([]Reques return out, rows.Err() } +// GetLogContent returns the prompt messages and completion text for a single +// request log row, or (nil, nil, nil) if none was recorded or the log is not +// visible to userID (non-nil userID restricts to that user's own logs, same +// scoping as ListRequestLogs). +func (s *Store) GetLogContent(ctx context.Context, logID uuid.UUID, userID *uuid.UUID) (*json.RawMessage, *string, error) { + var messages *json.RawMessage + var completion *string + err := s.pool.QueryRow(ctx, ` + SELECT rlc.messages, rlc.completion + FROM request_log_content rlc + JOIN request_logs rl ON rl.id = rlc.request_log_id + WHERE rlc.request_log_id = $1 + AND ($2::uuid IS NULL OR rl.user_id = $2)`, + logID, userID, + ).Scan(&messages, &completion) + if errors.Is(err, pgx.ErrNoRows) { + return nil, nil, nil + } + if err != nil { + return nil, nil, err + } + return messages, completion, nil +} + // KeyStat is per-virtual-key aggregate stats for a time window. type KeyStat struct { KeyPrefix string `json:"key_prefix"` @@ -174,7 +213,7 @@ func (s *Store) KeyStats(ctx context.Context, since time.Time, userID *uuid.UUID SUM(CASE WHEN status_code >= 400 THEN 1 ELSE 0 END)::int FROM request_logs WHERE created_at >= $1 - AND ($2::uuid IS NULL OR virtual_key_id IN (SELECT id FROM virtual_keys WHERE user_id = $2)) + AND ($2::uuid IS NULL OR user_id = $2) GROUP BY key_prefix ORDER BY SUM(total_tokens) DESC`, since, userID, diff --git a/backend/migrations/000004_request_logs_optimizations.down.sql b/backend/migrations/000004_request_logs_optimizations.down.sql new file mode 100644 index 0000000..5720334 --- /dev/null +++ b/backend/migrations/000004_request_logs_optimizations.down.sql @@ -0,0 +1,2 @@ +DROP INDEX IF EXISTS idx_request_logs_key_prefix; +DROP INDEX IF EXISTS idx_request_logs_provider_name; diff --git a/backend/migrations/000004_request_logs_optimizations.up.sql b/backend/migrations/000004_request_logs_optimizations.up.sql new file mode 100644 index 0000000..f666ca7 --- /dev/null +++ b/backend/migrations/000004_request_logs_optimizations.up.sql @@ -0,0 +1,13 @@ +-- Backfill user_id on existing rows so the direct column (already indexed +-- via idx_request_logs_user) matches historical logs written before the app +-- started populating it from the owning key. +UPDATE request_logs rl +SET user_id = vk.user_id +FROM virtual_keys vk +WHERE rl.virtual_key_id = vk.id + AND rl.user_id IS NULL; + +-- Support the admin logs list's provider/key filters without a full scan +-- once the table grows past a handful of rows. +CREATE INDEX idx_request_logs_provider_name ON request_logs (provider_name, created_at DESC); +CREATE INDEX idx_request_logs_key_prefix ON request_logs (key_prefix, created_at DESC);