From 6141cf85eff452e26e85f2fb715efa5bc6cf9622 Mon Sep 17 00:00:00 2001 From: tbphp Date: Wed, 5 Aug 2026 23:01:42 +0800 Subject: [PATCH] =?UTF-8?q?feat(monitor):=20=E5=AE=8C=E6=88=90=E7=9B=91?= =?UTF-8?q?=E6=8E=A7=E9=A1=B5=E9=9D=A2=E8=AF=B7=E6=B1=82=E6=97=A5=E5=BF=97?= =?UTF-8?q?=E5=AE=9E=E7=8E=B0?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- .../access_key_collection_http_test.go | 4 +- internal/control/http_routes.go | 1 + internal/control/request_logs.go | 547 +++++++++-- internal/control/request_logs_test.go | 265 ++++- internal/gateway/forward.go | 4 + internal/gateway/handler.go | 4 + internal/gateway/request_log.go | 57 +- internal/gateway/request_log_test.go | 50 +- internal/pricing/nanousd.go | 4 +- internal/pricing/quote.go | 75 +- internal/pricing/quote_test.go | 68 ++ internal/pricing/receipt.go | 70 ++ internal/pricing/types.go | 40 +- internal/requestlog/mapper.go | 63 +- internal/requestlog/mapper_test.go | 31 +- internal/requestlog/query.go | 206 +++- internal/requestlog/query_test.go | 212 +++- internal/requestlog/service_test.go | 8 +- internal/requestlog/test_helpers_test.go | 1 - internal/requestlog/types.go | 56 +- internal/requestlog/worker.go | 9 + internal/storage/db.go | 12 +- internal/storage/db_test.go | 4 +- internal/storage/models/request.go | 72 +- .../storage/{schema_v4.go => schema_v5.go} | 68 +- .../{schema_v4_test.go => schema_v5_test.go} | 114 ++- ..._validation.go => schema_v5_validation.go} | 30 +- internal/telemetry/requestlog.go | 31 +- internal/telemetry/requestlog_test.go | 3 + web/src/app/query-keys.ts | 29 +- web/src/app/resources/request-logs.ts | 354 +++++-- web/src/components/ui/AppDateTime.vue | 8 +- .../components/ui/AppDateTimeRangePicker.vue | 232 +++++ web/src/components/ui/AppSearchInput.vue | 5 + web/src/components/ui/AppSelect.vue | 27 +- web/src/components/ui/PaginationBar.vue | 53 +- web/src/features/monitor/LogDetailDrawer.vue | 623 ++++++------ .../monitor/LogsAdvancedFilterDrawer.vue | 444 +++++++++ web/src/features/monitor/LogsFilterForm.vue | 435 ++++---- web/src/features/monitor/LogsTab.vue | 926 +++++++++++------- web/src/features/monitor/MonitorView.vue | 2 +- web/src/features/monitor/log-filters.ts | 492 +++++++--- web/src/features/monitor/log-format.ts | 47 + web/src/features/monitor/monitor-route.ts | 37 +- web/src/i18n/locales/en-US/monitor.ts | 126 ++- web/src/i18n/locales/ja-JP/monitor.ts | 126 ++- web/src/i18n/locales/zh-CN/monitor.ts | 129 ++- web/src/lib/format.ts | 5 + 48 files changed, 4664 insertions(+), 1545 deletions(-) create mode 100644 internal/pricing/receipt.go rename internal/storage/{schema_v4.go => schema_v5.go} (79%) rename internal/storage/{schema_v4_test.go => schema_v5_test.go} (86%) rename internal/storage/{schema_v4_validation.go => schema_v5_validation.go} (61%) create mode 100644 web/src/components/ui/AppDateTimeRangePicker.vue create mode 100644 web/src/features/monitor/LogsAdvancedFilterDrawer.vue create mode 100644 web/src/features/monitor/log-format.ts diff --git a/internal/control/access_key_collection_http_test.go b/internal/control/access_key_collection_http_test.go index 26205213..86132f48 100644 --- a/internal/control/access_key_collection_http_test.go +++ b/internal/control/access_key_collection_http_test.go @@ -170,12 +170,12 @@ func TestAccessKeyCollectionHTTPReturnsLatestRequestTimeAndOmitsCollectionScope( { ID: "00000000-0000-4000-8000-000000000001", CompletedAtMS: 1_700_000_000_100, AccessKeyID: used.ID, Protocol: "openai-completions", ClientModel: "gpt-4.1", - UpstreamModel: "gpt-4.1", Status: "success", Attempts: models.JSON(`[]`), + UpstreamModel: "gpt-4.1", Status: "success", }, { ID: "00000000-0000-4000-8000-000000000002", CompletedAtMS: 1_700_000_000_900, AccessKeyID: used.ID, Protocol: "anthropic", ClientModel: "claude-sonnet", - UpstreamModel: "claude-sonnet", Status: "error", Attempts: models.JSON(`[]`), + UpstreamModel: "claude-sonnet", Status: "error", }, }).Error; err != nil { t.Fatalf("create request logs: %v", err) diff --git a/internal/control/http_routes.go b/internal/control/http_routes.go index 32ada478..b5561bfa 100644 --- a/internal/control/http_routes.go +++ b/internal/control/http_routes.go @@ -114,6 +114,7 @@ func (s *Server) HTTPModule() httproute.Module { ), controlRoute("control.health", http.MethodGet, "/health", s.handleRuntimeHealth), controlRoute("control.logs.list", http.MethodGet, "/logs", s.handleListRequestLogs), + controlRoute("control.logs.get", http.MethodGet, "/logs/:request_id", s.handleGetRequestLog), controlRoute("control.usage", http.MethodGet, "/usage", s.handleUsage), controlRoute("control.route.inspect", http.MethodPost, "/route/inspect", s.handleRouteInspect), controlRoute("control.settings.get", http.MethodGet, "/settings", s.handleGetSettings), diff --git a/internal/control/request_logs.go b/internal/control/request_logs.go index 5f08022d..ffa89c32 100644 --- a/internal/control/request_logs.go +++ b/internal/control/request_logs.go @@ -17,6 +17,7 @@ import ( app_errors "gpt-load/internal/platform/errors" "gpt-load/internal/platform/response" "gpt-load/internal/pricing" + "gpt-load/internal/protocol" "gpt-load/internal/requestlog" "gpt-load/internal/telemetry" "gpt-load/internal/usage" @@ -34,6 +35,7 @@ var canonicalLowercaseUUIDv4 = regexp.MustCompile( type RequestLogReader interface { List(context.Context, requestlog.ListQuery) (requestlog.Page, error) + Get(context.Context, string) (requestlog.Record, error) } type requestLogCursorPayload struct { @@ -49,19 +51,49 @@ type requestLogAccessKeyResponse struct { } type requestLogAttemptResponse struct { - Sequence int `json:"sequence"` - GroupID uint `json:"group_id"` - GroupName string `json:"group_name"` - KeyID uint `json:"key_id"` - UpstreamModel *string `json:"upstream_model"` - StatusCode int `json:"status_code"` - DurationMs int64 `json:"duration_ms"` - FailureCategory telemetry.FailureCategory `json:"failure_category"` - Action telemetry.Action `json:"action"` - WillRetry bool `json:"will_retry"` - ErrorCode string `json:"error_code"` - ErrorSummary string `json:"error_summary"` - Committed bool `json:"committed"` + Sequence int `json:"sequence"` + GroupID uint `json:"group_id"` + GroupName string `json:"group_name"` + KeyID uint `json:"key_id"` + UpstreamModel *string `json:"upstream_model"` + StatusCode int `json:"status_code"` + DurationMs int64 `json:"duration_ms"` + FailureCategory telemetry.FailureCategory `json:"failure_category"` + Action telemetry.Action `json:"action"` + WillRetry bool `json:"will_retry"` + ErrorCode string `json:"error_code"` + ErrorSummary string `json:"error_summary"` + PricingReceipt *requestLogPricingReceiptResponse `json:"pricing_receipt"` +} + +type requestLogPricingIdentityResponse struct { + ScopeKey string `json:"scope_key"` + ModelID string `json:"model_id"` +} + +type requestLogPricingMultiplierResponse struct { + Numerator string `json:"numerator"` + Denominator string `json:"denominator"` +} + +type requestLogPricingLineResponse struct { + Code string `json:"code"` + Quantity string `json:"quantity"` + RateNanoUSDPerMillion *string `json:"rate_nano_usd_per_million"` + Multiplier requestLogPricingMultiplierResponse `json:"multiplier"` + State pricing.ReceiptLineState `json:"state"` + AmountNanoUSD *string `json:"amount_nano_usd"` +} + +type requestLogPricingReceiptResponse struct { + SchemaVersion int `json:"schema_version"` + Method string `json:"method"` + MethodVersion int `json:"method_version"` + Currency string `json:"currency"` + Rule requestLogPricingIdentityResponse `json:"rule"` + ContextThresholdTokens *string `json:"context_threshold_tokens"` + LineItems []requestLogPricingLineResponse `json:"line_items"` + TotalNanoUSD string `json:"total_nano_usd"` } type requestLogItemResponse struct { @@ -73,24 +105,31 @@ type requestLogItemResponse struct { UpstreamModel *string `json:"upstream_model"` Status telemetry.RequestStatus `json:"status"` StatusCode int `json:"status_code"` + Stream bool `json:"stream"` + FirstResponseMs *int64 `json:"first_response_ms"` DurationMs int64 `json:"duration_ms"` + AttemptCount int `json:"attempt_count"` ErrorCode string `json:"error_code"` ErrorSummary string `json:"error_summary"` AffinityHit bool `json:"affinity_hit"` - Attempts []requestLogAttemptResponse `json:"attempts"` GroupID *uint `json:"group_id"` UsageState usage.State `json:"usage_state"` CostState pricing.CostState `json:"cost_state"` PricingCompleteness pricing.Completeness `json:"pricing_completeness"` - UncachedInputTokens int64 `json:"uncached_input_tokens"` - CacheReadTokens int64 `json:"cache_read_tokens"` - CacheWrite5MTokens int64 `json:"cache_write_5m_tokens"` - CacheWrite1HTokens int64 `json:"cache_write_1h_tokens"` - CacheWriteUnknownTokens int64 `json:"cache_write_unknown_tokens"` - OutputTokens int64 `json:"output_tokens"` + InputTokens string `json:"input_tokens"` + CacheReadTokens string `json:"cache_read_tokens"` + CacheWrite5MTokens string `json:"cache_write_5m_tokens"` + CacheWrite1HTokens string `json:"cache_write_1h_tokens"` + CacheWriteUnknownTokens string `json:"cache_write_unknown_tokens"` + OutputTokens string `json:"output_tokens"` EstimatedCostNanoUSD string `json:"estimated_cost_nano_usd"` } +type requestLogDetailResponse struct { + requestLogItemResponse + Attempts []requestLogAttemptResponse `json:"attempts"` +} + type requestLogListResponse struct { Items []requestLogItemResponse `json:"items"` NextCursor *string `json:"next_cursor"` @@ -110,6 +149,17 @@ func (service *Service) ListRequestLogs( return page, nil } +func (service *Service) GetRequestLog(ctx context.Context, requestID string) (requestlog.Record, error) { + if service.requestLogs == nil { + return requestlog.Record{}, app_errors.ErrInternalServer + } + record, err := service.requestLogs.Get(ctx, requestID) + if err != nil { + return requestlog.Record{}, app_errors.ParseDBError(err) + } + return record, nil +} + func (s *Server) handleListRequestLogs(c *gin.Context) { query, apiErr := parseRequestLogQuery(c.Request.URL.RawQuery) if apiErr != nil { @@ -129,6 +179,25 @@ func (s *Server) handleListRequestLogs(c *gin.Context) { response.SuccessI18n(c, "common.success", result) } +func (s *Server) handleGetRequestLog(c *gin.Context) { + requestID := c.Param("request_id") + if !canonicalLowercaseUUIDv4.MatchString(requestID) { + writeServiceError(c, "get_request_log", app_errors.ErrBadRequest) + return + } + record, err := s.service.GetRequestLog(c.Request.Context(), requestID) + if err != nil { + writeServiceError(c, "get_request_log", err) + return + } + result, err := mapRequestLogDetailResponse(record) + if err != nil { + writeServiceError(c, "get_request_log", err) + return + } + response.SuccessI18n(c, "common.success", result) +} + func parseRequestLogQuery(rawQuery string) (requestlog.ListQuery, *app_errors.APIError) { values, err := url.ParseQuery(rawQuery) if err != nil { @@ -136,7 +205,16 @@ func parseRequestLogQuery(rawQuery string) (requestlog.ListQuery, *app_errors.AP } allowed := map[string]struct{}{ "from_ms": {}, "to_ms": {}, "group_id": {}, "client_model": {}, "upstream_model": {}, "access_key_id": {}, - "status": {}, "request_id": {}, "limit": {}, "cursor": {}, + "status": {}, "request_id": {}, "protocol": {}, "stream": {}, "final_status_code": {}, + "usage_state": {}, "cost_state": {}, "pricing_completeness": {}, "cache_present": {}, + "upstream_key_id": {}, "attempt_status_code": {}, "failure_category": {}, "error_code": {}, + "retry_state": {}, "retry_count_min": {}, "retry_count_max": {}, + "first_response_min_ms": {}, "first_response_max_ms": {}, + "duration_min_ms": {}, "duration_max_ms": {}, + "input_tokens_min": {}, "input_tokens_max": {}, + "output_tokens_min": {}, "output_tokens_max": {}, + "cost_min_nano_usd": {}, "cost_max_nano_usd": {}, + "limit": {}, "cursor": {}, } for key, value := range values { if _, ok := allowed[key]; !ok || len(value) != 1 { @@ -170,13 +248,13 @@ func parseRequestLogQuery(rawQuery string) (requestlog.ListQuery, *app_errors.AP query.GroupID = &parsed } if value, ok := singleQueryValue(values, "client_model"); ok { - if value == "" { + if !validUsageModel(value) { return requestlog.ListQuery{}, app_errors.ErrValidation } query.ClientModel = value } if value, ok := singleQueryValue(values, "upstream_model"); ok { - if value == "" { + if !validUsageModel(value) { return requestlog.ListQuery{}, app_errors.ErrValidation } query.UpstreamModel = value @@ -188,6 +266,27 @@ func parseRequestLogQuery(rawQuery string) (requestlog.ListQuery, *app_errors.AP } query.AccessKeyID = &parsed } + if value, ok := singleQueryValue(values, "protocol"); ok { + parsed := protocol.Protocol(value) + if !parsed.Valid() { + return requestlog.ListQuery{}, app_errors.ErrValidation + } + query.Protocol = parsed + } + if value, ok := singleQueryValue(values, "stream"); ok { + parsed, valid := parseRequestLogBool(value) + if !valid { + return requestlog.ListQuery{}, app_errors.ErrValidation + } + query.Stream = &parsed + } + if value, ok := singleQueryValue(values, "final_status_code"); ok { + parsed, apiErr := parseRequestLogStatusCode(value) + if apiErr != nil { + return requestlog.ListQuery{}, apiErr + } + query.FinalStatusCode = &parsed + } if value, ok := singleQueryValue(values, "status"); ok { status := telemetry.RequestStatus(value) switch status { @@ -200,6 +299,119 @@ func parseRequestLogQuery(rawQuery string) (requestlog.ListQuery, *app_errors.AP return requestlog.ListQuery{}, app_errors.ErrValidation } } + if value, ok := singleQueryValue(values, "usage_state"); ok { + state := usage.State(value) + switch state { + case usage.StateComplete, usage.StatePartial, usage.StateMissing, usage.StateNotApplicable: + query.UsageState = state + default: + return requestlog.ListQuery{}, app_errors.ErrValidation + } + } + if value, ok := singleQueryValue(values, "cost_state"); ok { + state := pricing.CostState(value) + switch state { + case pricing.CostStatePriced, pricing.CostStateUnpriced, pricing.CostStateNotApplicable: + query.CostState = state + default: + return requestlog.ListQuery{}, app_errors.ErrValidation + } + } + if value, ok := singleQueryValue(values, "pricing_completeness"); ok { + completeness := pricing.Completeness(value) + switch completeness { + case pricing.CompletenessComplete, + pricing.CompletenessPartial, + pricing.CompletenessUnavailable, + pricing.CompletenessNotApplicable: + query.PricingCompleteness = completeness + default: + return requestlog.ListQuery{}, app_errors.ErrValidation + } + } + if value, ok := singleQueryValue(values, "cache_present"); ok { + parsed, valid := parseRequestLogBool(value) + if !valid { + return requestlog.ListQuery{}, app_errors.ErrValidation + } + query.CachePresent = &parsed + } + if value, ok := singleQueryValue(values, "upstream_key_id"); ok { + parsed, apiErr := parseRequestLogID(value) + if apiErr != nil { + return requestlog.ListQuery{}, apiErr + } + query.UpstreamKeyID = &parsed + } + if value, ok := singleQueryValue(values, "attempt_status_code"); ok { + parsed, apiErr := parseRequestLogStatusCode(value) + if apiErr != nil { + return requestlog.ListQuery{}, apiErr + } + query.AttemptStatusCode = &parsed + } + if value, ok := singleQueryValue(values, "failure_category"); ok { + category := telemetry.FailureCategory(value) + switch category { + case telemetry.FailureCategoryOK, + telemetry.FailureCategoryRateLimited, + telemetry.FailureCategoryModelUnavailable, + telemetry.FailureCategoryInvalidKey, + telemetry.FailureCategoryUpstreamHost, + telemetry.FailureCategoryClientError, + telemetry.FailureCategoryDownstreamCancel, + telemetry.FailureCategoryAmbiguous: + query.FailureCategory = category + default: + return requestlog.ListQuery{}, app_errors.ErrValidation + } + } + if value, ok := singleQueryValue(values, "error_code"); ok { + if !validUsageModel(value) { + return requestlog.ListQuery{}, app_errors.ErrValidation + } + query.AttemptErrorCode = value + } + if value, ok := singleQueryValue(values, "retry_state"); ok { + state := requestlog.RetryState(value) + switch state { + case requestlog.RetryStateRetried, requestlog.RetryStateNotRetried: + query.RetryState = state + default: + return requestlog.ListQuery{}, app_errors.ErrValidation + } + } + if apiErr := parseRequestLogIntRange( + values, + "retry_count_min", + "retry_count_max", + &query.RetryCountMin, + &query.RetryCountMax, + ); apiErr != nil { + return requestlog.ListQuery{}, apiErr + } + for _, target := range []struct { + minimumKey string + maximumKey string + minimum **int64 + maximum **int64 + }{ + {"first_response_min_ms", "first_response_max_ms", &query.FirstResponseMinMS, &query.FirstResponseMaxMS}, + {"duration_min_ms", "duration_max_ms", &query.DurationMinMS, &query.DurationMaxMS}, + {"input_tokens_min", "input_tokens_max", &query.InputTokensMin, &query.InputTokensMax}, + {"output_tokens_min", "output_tokens_max", &query.OutputTokensMin, &query.OutputTokensMax}, + {"cost_min_nano_usd", "cost_max_nano_usd", &query.CostMinNanoUSD, &query.CostMaxNanoUSD}, + } { + if apiErr := parseRequestLogInt64Range( + values, + target.minimumKey, + target.maximumKey, + target.minimum, + target.maximum, + ); apiErr != nil { + return requestlog.ListQuery{}, apiErr + } + } if value, ok := singleQueryValue(values, "request_id"); ok { if !canonicalLowercaseUUIDv4.MatchString(value) { return requestlog.ListQuery{}, app_errors.ErrBadRequest @@ -251,6 +463,98 @@ func parseRequestLogID(value string) (uint, *app_errors.APIError) { return uint(parsed), nil } +func parseRequestLogBool(value string) (bool, bool) { + switch value { + case "true": + return true, true + case "false": + return false, true + default: + return false, false + } +} + +func parseRequestLogStatusCode(value string) (int, *app_errors.APIError) { + parsed, err := parseCanonicalNonNegativeInt64(value) + if err != nil { + return 0, app_errors.ErrBadRequest + } + if parsed > 999 { + return 0, app_errors.ErrValidation + } + return int(parsed), nil +} + +func parseRequestLogIntRange( + values url.Values, + minimumKey string, + maximumKey string, + minimum **int, + maximum **int, +) *app_errors.APIError { + var parsedMinimum *int64 + var parsedMaximum *int64 + if apiErr := parseRequestLogInt64Range( + values, + minimumKey, + maximumKey, + &parsedMinimum, + &parsedMaximum, + ); apiErr != nil { + return apiErr + } + if parsedMinimum != nil { + value := int(*parsedMinimum) + if int64(value) != *parsedMinimum { + return app_errors.ErrValidation + } + *minimum = &value + } + if parsedMaximum != nil { + value := int(*parsedMaximum) + if int64(value) != *parsedMaximum { + return app_errors.ErrValidation + } + *maximum = &value + } + return nil +} + +func parseRequestLogInt64Range( + values url.Values, + minimumKey string, + maximumKey string, + minimum **int64, + maximum **int64, +) *app_errors.APIError { + if value, ok := singleQueryValue(values, minimumKey); ok { + parsed, err := parseCanonicalNonNegativeInt64(value) + if err != nil { + return app_errors.ErrBadRequest + } + *minimum = &parsed + } + if value, ok := singleQueryValue(values, maximumKey); ok { + parsed, err := parseCanonicalNonNegativeInt64(value) + if err != nil { + return app_errors.ErrBadRequest + } + *maximum = &parsed + } + if *minimum != nil && *maximum != nil && **minimum > **maximum { + return app_errors.ErrValidation + } + return nil +} + +func parseCanonicalNonNegativeInt64(value string) (int64, error) { + parsed, err := strconv.ParseInt(value, 10, 64) + if err != nil || parsed < 0 || strconv.FormatInt(parsed, 10) != value { + return 0, fmt.Errorf("value must be a canonical non-negative integer") + } + return parsed, nil +} + func decodeRequestLogCursor(encoded string) (*requestlog.Cursor, error) { raw, err := base64.RawURLEncoding.DecodeString(encoded) if err != nil { @@ -370,54 +674,11 @@ func mapRequestLogListResponse(page requestlog.Page) (requestLogListResponse, er if err != nil { return requestLogListResponse{}, err } - attempts := make([]requestLogAttemptResponse, 0, len(record.Attempts)) - for _, attempt := range record.Attempts { - attempts = append(attempts, requestLogAttemptResponse{ - Sequence: attempt.Sequence, - GroupID: attempt.GroupID, - GroupName: attempt.GroupName, - KeyID: attempt.KeyID, - UpstreamModel: nullableRequestLogModel(attempt.UpstreamModel), - StatusCode: attempt.StatusCode, - DurationMs: attempt.DurationMs, - FailureCategory: attempt.FailureCategory, - Action: attempt.Action, - WillRetry: attempt.WillRetry, - ErrorCode: attempt.ErrorCode, - ErrorSummary: attempt.ErrorSummary, - Committed: attempt.Committed, - }) + item, err := mapRequestLogItemResponse(record, usageCost) + if err != nil { + return requestLogListResponse{}, err } - result.Items = append(result.Items, requestLogItemResponse{ - RequestID: record.RequestID, - CompletedAtMS: record.CompletedAtMS, - AccessKey: requestLogAccessKeyResponse{ - ID: record.AccessKey.ID, - Name: record.AccessKey.Name, - Deleted: record.AccessKey.Deleted, - }, - Protocol: string(record.Protocol), - ClientModel: nullableRequestLogModel(record.ClientModel), - UpstreamModel: nullableRequestLogModel(record.UpstreamModel), - Status: record.Status, - StatusCode: record.StatusCode, - DurationMs: record.DurationMs, - ErrorCode: record.ErrorCode, - ErrorSummary: record.ErrorSummary, - AffinityHit: record.AffinityHit, - Attempts: attempts, - GroupID: usageCost.groupID, - UsageState: record.UsageState, - CostState: record.CostState, - PricingCompleteness: record.PricingCompleteness, - UncachedInputTokens: record.UncachedInputTokens, - CacheReadTokens: record.CacheReadTokens, - CacheWrite5MTokens: record.CacheWrite5MTokens, - CacheWrite1HTokens: record.CacheWrite1HTokens, - CacheWriteUnknownTokens: record.CacheWriteUnknownTokens, - OutputTokens: record.OutputTokens, - EstimatedCostNanoUSD: usageCost.estimatedCostNanoUSD, - }) + result.Items = append(result.Items, item) } if page.NextCursor != nil { encoded, err := encodeRequestLogCursor(*page.NextCursor) @@ -429,6 +690,148 @@ func mapRequestLogListResponse(page requestlog.Page) (requestLogListResponse, er return result, nil } +func mapRequestLogItemResponse( + record requestlog.Record, + usageCost requestLogUsageCostResponse, +) (requestLogItemResponse, error) { + inputTokens, ok := checkedRequestLogInputTokens(record) + if !ok { + return requestLogItemResponse{}, fmt.Errorf("map request log input tokens: overflow") + } + return requestLogItemResponse{ + RequestID: record.RequestID, + CompletedAtMS: record.CompletedAtMS, + AccessKey: requestLogAccessKeyResponse{ + ID: record.AccessKey.ID, + Name: record.AccessKey.Name, + Deleted: record.AccessKey.Deleted, + }, + Protocol: string(record.Protocol), + ClientModel: nullableRequestLogModel(record.ClientModel), + UpstreamModel: nullableRequestLogModel(record.UpstreamModel), + Status: record.Status, + StatusCode: record.StatusCode, + Stream: record.Stream, + FirstResponseMs: record.FirstResponseMs, + DurationMs: record.DurationMs, + AttemptCount: record.AttemptCount, + ErrorCode: record.ErrorCode, + ErrorSummary: record.ErrorSummary, + AffinityHit: record.AffinityHit, + GroupID: usageCost.groupID, + UsageState: record.UsageState, + CostState: record.CostState, + PricingCompleteness: record.PricingCompleteness, + InputTokens: strconv.FormatInt(inputTokens, 10), + CacheReadTokens: strconv.FormatInt(record.CacheReadTokens, 10), + CacheWrite5MTokens: strconv.FormatInt(record.CacheWrite5MTokens, 10), + CacheWrite1HTokens: strconv.FormatInt(record.CacheWrite1HTokens, 10), + CacheWriteUnknownTokens: strconv.FormatInt(record.CacheWriteUnknownTokens, 10), + OutputTokens: strconv.FormatInt(record.OutputTokens, 10), + EstimatedCostNanoUSD: usageCost.estimatedCostNanoUSD, + }, nil +} + +func checkedRequestLogInputTokens(record requestlog.Record) (int64, bool) { + total := int64(0) + for _, value := range []int64{ + record.UncachedInputTokens, + record.CacheReadTokens, + record.CacheWrite5MTokens, + record.CacheWrite1HTokens, + record.CacheWriteUnknownTokens, + } { + var ok bool + total, ok = usage.CheckedAdd(total, value) + if !ok { + return 0, false + } + } + return total, true +} + +func mapRequestLogDetailResponse(record requestlog.Record) (requestLogDetailResponse, error) { + usageCost, err := mapRequestLogUsageCost(record) + if err != nil { + return requestLogDetailResponse{}, err + } + item, err := mapRequestLogItemResponse(record, usageCost) + if err != nil { + return requestLogDetailResponse{}, err + } + attempts := make([]requestLogAttemptResponse, 0, len(record.Attempts)) + for _, attempt := range record.Attempts { + receipt, err := mapRequestLogPricingReceipt(attempt.PricingReceipt) + if err != nil { + return requestLogDetailResponse{}, err + } + attempts = append(attempts, requestLogAttemptResponse{ + Sequence: attempt.Sequence, + GroupID: attempt.GroupID, + GroupName: attempt.GroupName, + KeyID: attempt.KeyID, + UpstreamModel: nullableRequestLogModel(attempt.UpstreamModel), + StatusCode: attempt.StatusCode, + DurationMs: attempt.DurationMs, + FailureCategory: attempt.FailureCategory, + Action: attempt.Action, + WillRetry: attempt.WillRetry, + ErrorCode: attempt.ErrorCode, + ErrorSummary: attempt.ErrorSummary, + PricingReceipt: receipt, + }) + } + return requestLogDetailResponse{requestLogItemResponse: item, Attempts: attempts}, nil +} + +func mapRequestLogPricingReceipt( + receipt *pricing.Receipt, +) (*requestLogPricingReceiptResponse, error) { + if receipt == nil { + return nil, nil + } + if err := pricing.ValidateReceipt(*receipt); err != nil { + return nil, fmt.Errorf("map request log pricing receipt: %w", err) + } + result := &requestLogPricingReceiptResponse{ + SchemaVersion: receipt.SchemaVersion, + Method: receipt.Method, + MethodVersion: receipt.MethodVersion, + Currency: receipt.Currency, + Rule: requestLogPricingIdentityResponse{ + ScopeKey: receipt.Rule.ScopeKey, + ModelID: receipt.Rule.ModelID, + }, + LineItems: make([]requestLogPricingLineResponse, 0, len(receipt.LineItems)), + TotalNanoUSD: strconv.FormatInt(receipt.TotalNanoUSD, 10), + } + if receipt.ContextThresholdTokens != nil { + value := strconv.FormatInt(*receipt.ContextThresholdTokens, 10) + result.ContextThresholdTokens = &value + } + for _, line := range receipt.LineItems { + mapped := requestLogPricingLineResponse{ + Code: line.Code, + Quantity: strconv.FormatInt(line.Quantity, 10), + Multiplier: requestLogPricingMultiplierResponse{ + Numerator: strconv.FormatInt(line.Multiplier.Numerator, 10), + Denominator: strconv.FormatInt(line.Multiplier.Denominator, 10), + }, + State: line.State, + } + if line.RateNanoUSDPerMillion != nil { + value := strconv.FormatInt(*line.RateNanoUSDPerMillion, 10) + mapped.RateNanoUSDPerMillion = &value + } + if line.AmountNanoUSD != nil { + value := strconv.FormatInt(*line.AmountNanoUSD, 10) + mapped.AmountNanoUSD = &value + } + result.LineItems = append(result.LineItems, mapped) + } + return result, nil +} + func nullableRequestLogModel(value string) *string { if value == "" { return nil @@ -458,8 +861,8 @@ func mapRequestLogUsageCost(record requestlog.Record) (requestLogUsageCostRespon record.CacheWriteUnknownTokens, record.OutputTokens, } { - if value < 0 || value > maxSafeInteger { - return requestLogUsageCostResponse{}, fmt.Errorf("map request log usage tokens: unsafe value") + if value < 0 { + return requestLogUsageCostResponse{}, fmt.Errorf("map request log usage tokens: negative value") } } if _, ok := usage.CheckedTotal(usage.Tokens{ diff --git a/internal/control/request_logs_test.go b/internal/control/request_logs_test.go index cd555778..f334956b 100644 --- a/internal/control/request_logs_test.go +++ b/internal/control/request_logs_test.go @@ -141,6 +141,107 @@ func TestRequestLogEndpointAcceptsCanonicalNumericBoundaries(t *testing.T) { } } +func TestRequestLogEndpointParsesAdvancedFilters(t *testing.T) { + reader := &recordingRequestLogReader{} + engine := newRequestLogTestEngine(t, reader) + query := strings.Join([]string{ + "protocol=anthropic", + "stream=true", + "final_status_code=529", + "usage_state=partial", + "cost_state=priced", + "pricing_completeness=partial", + "cache_present=true", + "upstream_key_id=9", + "attempt_status_code=429", + "failure_category=rate_limited", + "error_code=provider_rate_limit", + "retry_state=retried", + "retry_count_min=1", + "retry_count_max=3", + "first_response_min_ms=10", + "first_response_max_ms=900", + "duration_min_ms=20", + "duration_max_ms=2000", + "input_tokens_min=100", + "input_tokens_max=2000", + "output_tokens_min=10", + "output_tokens_max=500", + "cost_min_nano_usd=1000", + "cost_max_nano_usd=9000000", + }, "&") + recorder := performRequestLogRequest(engine, "test-auth-key", query) + if recorder.Code != http.StatusOK { + t.Fatalf("response = %d %s, want 200", recorder.Code, recorder.Body.String()) + } + if len(reader.queries) != 1 { + t.Fatalf("Reader calls = %d, want one", len(reader.queries)) + } + got := reader.queries[0] + if got.Protocol != protocol.Anthropic || got.Stream == nil || !*got.Stream || + got.FinalStatusCode == nil || *got.FinalStatusCode != 529 || + got.UsageState != usage.StatePartial || got.CostState != pricing.CostStatePriced || + got.PricingCompleteness != pricing.CompletenessPartial || + got.CachePresent == nil || !*got.CachePresent || + got.UpstreamKeyID == nil || *got.UpstreamKeyID != 9 || + got.AttemptStatusCode == nil || *got.AttemptStatusCode != 429 || + got.FailureCategory != telemetry.FailureCategoryRateLimited || + got.AttemptErrorCode != "provider_rate_limit" || got.RetryState != requestlog.RetryStateRetried || + got.RetryCountMin == nil || *got.RetryCountMin != 1 || + got.RetryCountMax == nil || *got.RetryCountMax != 3 || + got.FirstResponseMinMS == nil || *got.FirstResponseMinMS != 10 || + got.FirstResponseMaxMS == nil || *got.FirstResponseMaxMS != 900 || + got.DurationMinMS == nil || *got.DurationMinMS != 20 || + got.DurationMaxMS == nil || *got.DurationMaxMS != 2000 || + got.InputTokensMin == nil || *got.InputTokensMin != 100 || + got.InputTokensMax == nil || *got.InputTokensMax != 2000 || + got.OutputTokensMin == nil || *got.OutputTokensMin != 10 || + got.OutputTokensMax == nil || *got.OutputTokensMax != 500 || + got.CostMinNanoUSD == nil || *got.CostMinNanoUSD != 1000 || + got.CostMaxNanoUSD == nil || *got.CostMaxNanoUSD != 9000000 { + t.Fatalf("parsed advanced query = %#v", got) + } +} + +func TestRequestLogEndpointRejectsInvalidAdvancedFilters(t *testing.T) { + tests := []string{ + "protocol=openai", + "stream=1", + "final_status_code=1000", + "usage_state=unknown", + "cost_state=unknown", + "pricing_completeness=unknown", + "cache_present=yes", + "upstream_key_id=0", + "attempt_status_code=-1", + "failure_category=unknown", + "error_code=", + "retry_state=unknown", + "retry_count_min=4&retry_count_max=3", + "first_response_min_ms=20&first_response_max_ms=10", + "duration_min_ms=20&duration_max_ms=10", + "input_tokens_min=20&input_tokens_max=10", + "output_tokens_min=20&output_tokens_max=10", + "cost_min_nano_usd=20&cost_max_nano_usd=10", + } + for _, query := range tests { + t.Run(query, func(t *testing.T) { + reader := &recordingRequestLogReader{} + recorder := performRequestLogRequest( + newRequestLogTestEngine(t, reader), + "test-auth-key", + query, + ) + if recorder.Code != http.StatusBadRequest { + t.Fatalf("response = %d %s, want 400", recorder.Code, recorder.Body.String()) + } + if len(reader.queries) != 0 { + t.Fatalf("Reader calls = %d, want zero", len(reader.queries)) + } + }) + } +} + func TestRequestLogEndpointReturnsOpaqueCursorAndSafeDTO(t *testing.T) { completedAt := time.Date(2026, time.July, 24, 12, 0, 0, 123456789, time.UTC) completedAtMS := completedAt.UnixMilli() @@ -168,18 +269,7 @@ func TestRequestLogEndpointReturnsOpaqueCursorAndSafeDTO(t *testing.T) { UsageState: usage.StateNotApplicable, CostState: pricing.CostStateNotApplicable, PricingCompleteness: pricing.CompletenessNotApplicable, - Attempts: []requestlog.Attempt{{ - Sequence: 1, - GroupID: 12, - GroupName: "Primary", - KeyID: 11, - UpstreamModel: "upstream-model", - StatusCode: 200, - DurationMs: 1234, - FailureCategory: telemetry.FailureCategoryOK, - Action: telemetry.ActionTerminate, - Committed: true, - }}, + AttemptCount: 1, }}, NextCursor: nextCursor, }, @@ -232,16 +322,8 @@ func TestRequestLogEndpointReturnsOpaqueCursorAndSafeDTO(t *testing.T) { envelope.Data.NextCursor == nil || *envelope.Data.NextCursor == "" { t.Fatalf("first response envelope = %#v", envelope) } - attempts, ok := envelope.Data.Items[0]["attempts"].([]any) - if !ok || len(attempts) != 1 { - t.Fatalf("attempts = %#v, want one", envelope.Data.Items[0]["attempts"]) - } - attempt, ok := attempts[0].(map[string]any) - if !ok || attempt["key_id"] != float64(11) { - t.Fatalf("attempt = %#v, want key_id 11", attempts[0]) - } - if _, exists := attempt["key_mask"]; exists { - t.Fatalf("attempt exposes key_mask: %#v", attempt) + if _, exists := envelope.Data.Items[0]["attempts"]; exists { + t.Fatalf("list item unexpectedly exposes attempts: %#v", envelope.Data.Items[0]) } for _, forbidden := range []string{"headers", "body", "url"} { if strings.Contains(strings.ToLower(recorder.Body.String()), forbidden) { @@ -291,6 +373,94 @@ func TestRequestLogEndpointReturnsOpaqueCursorAndSafeDTO(t *testing.T) { } } +func TestRequestLogDetailEndpointReturnsAttemptsAndFrozenPricingReceipt(t *testing.T) { + requestID := "00000000-0000-4000-8000-000000000611" + rate := int64(1_000_000_000) + amount := int64(1_000_000) + receipt := &pricing.Receipt{ + SchemaVersion: 1, + Method: pricing.ReceiptMethodUnitRateSum, + MethodVersion: 1, + Currency: "USD", + Rule: pricing.Identity{ScopeKey: "group:12", ModelID: "gpt-4.1"}, + LineItems: []pricing.ReceiptLine{{ + Code: "input", + Quantity: 1000, + RateNanoUSDPerMillion: &rate, + Multiplier: pricing.Multiplier{Numerator: 1, Denominator: 1}, + State: pricing.ReceiptLinePriced, + AmountNanoUSD: &amount, + }}, + TotalNanoUSD: amount, + } + reader := &recordingRequestLogReader{details: map[string]requestlog.Record{ + requestID: { + RequestID: requestID, + CompletedAtMS: 1_784_894_400_000, + Protocol: protocol.OpenAICompletions, + Status: telemetry.RequestStatusSuccess, + StatusCode: http.StatusOK, + AttemptCount: 1, + UsageState: usage.StateComplete, + CostState: pricing.CostStatePriced, + PricingCompleteness: pricing.CompletenessComplete, + UncachedInputTokens: 1000, + EstimatedCostNanoUSD: amount, + Attempts: []requestlog.Attempt{{ + Sequence: 1, + GroupID: 12, + GroupName: "Primary", + KeyID: 99, + UpstreamModel: "gpt-4.1", + StatusCode: http.StatusOK, + DurationMs: 1200, + FailureCategory: telemetry.FailureCategoryOK, + Action: telemetry.ActionTerminate, + PricingReceipt: receipt, + }}, + }, + }} + engine := newRequestLogTestEngine(t, reader) + request := httptest.NewRequest(http.MethodGet, "/api/logs/"+requestID, nil) + request.Header.Set("Authorization", "Bearer test-auth-key") + recorder := httptest.NewRecorder() + engine.ServeHTTP(recorder, request) + if recorder.Code != http.StatusOK { + t.Fatalf("response = %d %s, want 200", recorder.Code, recorder.Body.String()) + } + var envelope struct { + Data struct { + RequestID string `json:"request_id"` + Attempts []struct { + KeyID uint `json:"key_id"` + PricingReceipt struct { + Method string `json:"method"` + TotalNanoUSD string `json:"total_nano_usd"` + LineItems []struct { + Quantity string `json:"quantity"` + AmountNanoUSD string `json:"amount_nano_usd"` + } `json:"line_items"` + } `json:"pricing_receipt"` + } `json:"attempts"` + } `json:"data"` + } + if err := json.Unmarshal(recorder.Body.Bytes(), &envelope); err != nil { + t.Fatalf("decode response: %v", err) + } + if envelope.Data.RequestID != requestID || len(envelope.Data.Attempts) != 1 || + envelope.Data.Attempts[0].KeyID != 99 || + envelope.Data.Attempts[0].PricingReceipt.Method != pricing.ReceiptMethodUnitRateSum || + envelope.Data.Attempts[0].PricingReceipt.TotalNanoUSD != "1000000" || + len(envelope.Data.Attempts[0].PricingReceipt.LineItems) != 1 || + envelope.Data.Attempts[0].PricingReceipt.LineItems[0].Quantity != "1000" || + envelope.Data.Attempts[0].PricingReceipt.LineItems[0].AmountNanoUSD != "1000000" { + t.Fatalf("detail projection = %#v", envelope.Data) + } + if strings.Contains(strings.ToLower(recorder.Body.String()), "committed") { + t.Fatalf("detail exposes internal committed flag: %s", recorder.Body.String()) + } +} + func TestRequestLogEndpointProjectsUsageCostAndNullGroupZero(t *testing.T) { reader := &recordingRequestLogReader{pages: []requestlog.Page{{Items: []requestlog.Record{ { @@ -307,9 +477,8 @@ func TestRequestLogEndpointProjectsUsageCostAndNullGroupZero(t *testing.T) { CacheWrite5MTokens: 3, CacheWrite1HTokens: 4, CacheWriteUnknownTokens: 6, - OutputTokens: 5, + OutputTokens: maxSafeInteger + 1, EstimatedCostNanoUSD: 123_456_789_012, - Attempts: []requestlog.Attempt{}, }, }}}} recorder := performRequestLogRequest(newRequestLogTestEngine(t, reader), "test-auth-key", "") @@ -323,12 +492,12 @@ func TestRequestLogEndpointProjectsUsageCostAndNullGroupZero(t *testing.T) { UsageState string `json:"usage_state"` CostState string `json:"cost_state"` PricingCompleteness string `json:"pricing_completeness"` - UncachedInputTokens int64 `json:"uncached_input_tokens"` - CacheReadTokens int64 `json:"cache_read_tokens"` - CacheWrite5MTokens int64 `json:"cache_write_5m_tokens"` - CacheWrite1HTokens int64 `json:"cache_write_1h_tokens"` - CacheWriteUnknownTokens int64 `json:"cache_write_unknown_tokens"` - OutputTokens int64 `json:"output_tokens"` + InputTokens string `json:"input_tokens"` + CacheReadTokens string `json:"cache_read_tokens"` + CacheWrite5MTokens string `json:"cache_write_5m_tokens"` + CacheWrite1HTokens string `json:"cache_write_1h_tokens"` + CacheWriteUnknownTokens string `json:"cache_write_unknown_tokens"` + OutputTokens string `json:"output_tokens"` EstimatedCostNanoUSD string `json:"estimated_cost_nano_usd"` } `json:"items"` } `json:"data"` @@ -342,10 +511,10 @@ func TestRequestLogEndpointProjectsUsageCostAndNullGroupZero(t *testing.T) { item := envelope.Data.Items[0] if item.GroupID != nil || item.UsageState != "complete" || item.CostState != "priced" || item.PricingCompleteness != "complete" || - item.UncachedInputTokens != 1 || item.CacheReadTokens != 2 || - item.CacheWrite5MTokens != 3 || item.CacheWrite1HTokens != 4 || - item.CacheWriteUnknownTokens != 6 || - item.OutputTokens != 5 || item.EstimatedCostNanoUSD != "123456789012" { + item.InputTokens != "16" || item.CacheReadTokens != "2" || + item.CacheWrite5MTokens != "3" || item.CacheWrite1HTokens != "4" || + item.CacheWriteUnknownTokens != "6" || + item.OutputTokens != "9007199254740992" || item.EstimatedCostNanoUSD != "123456789012" { t.Fatalf("usage/cost projection = %#v", item) } } @@ -360,17 +529,6 @@ func TestRequestLogResponseUsesNullModelsForProtocolOnlyResponsesResources(t *te UsageState: usage.StateNotApplicable, CostState: pricing.CostStateNotApplicable, PricingCompleteness: pricing.CompletenessNotApplicable, - Attempts: []requestlog.Attempt{{ - Sequence: 1, - GroupID: 12, - GroupName: "Primary", - KeyID: 11, - UpstreamModel: "", - StatusCode: http.StatusOK, - FailureCategory: telemetry.FailureCategoryOK, - Action: telemetry.ActionTerminate, - Committed: true, - }}, }}, }) if err != nil { @@ -399,7 +557,6 @@ func TestRequestLogUsageCostProjectionRejectsUnsafeValues(t *testing.T) { {name: "usage state", mutate: func(record *requestlog.Record) { record.UsageState = "invalid" }}, {name: "cost state", mutate: func(record *requestlog.Record) { record.CostState = "invalid" }}, {name: "negative token", mutate: func(record *requestlog.Record) { record.OutputTokens = -1 }}, - {name: "unsafe token", mutate: func(record *requestlog.Record) { record.OutputTokens = maxSafeInteger + 1 }}, {name: "negative cost", mutate: func(record *requestlog.Record) { record.EstimatedCostNanoUSD = -1 }}, { name: "missing usage cannot be priced", @@ -503,7 +660,6 @@ func TestRequestLogEndpointFailsClosedOnCorruptReaderUsageCost(t *testing.T) { CompletedAtMS: time.Date(2026, time.July, 27, 0, 0, 0, 0, time.UTC).UnixMilli(), UsageState: usage.StateComplete, CostState: pricing.CostStatePriced, - Attempts: []requestlog.Attempt{}, } test.mutate(&record) reader := &recordingRequestLogReader{ @@ -540,6 +696,8 @@ type recordingRequestLogReader struct { pages []requestlog.Page queries []requestlog.ListQuery err error + details map[string]requestlog.Record + getErr error } func (reader *recordingRequestLogReader) List( @@ -557,6 +715,19 @@ func (reader *recordingRequestLogReader) List( return reader.pages[index], nil } +func (reader *recordingRequestLogReader) Get( + _ context.Context, + requestID string, +) (requestlog.Record, error) { + if reader.getErr != nil { + return requestlog.Record{}, reader.getErr + } + if record, ok := reader.details[requestID]; ok { + return record, nil + } + return requestlog.Record{}, fmt.Errorf("request log %s not found", requestID) +} + func newRequestLogTestEngine(t *testing.T, reader RequestLogReader) *gin.Engine { t.Helper() initControlI18n(t) diff --git a/internal/gateway/forward.go b/internal/gateway/forward.go index f119d40e..ad3c54de 100644 --- a/internal/gateway/forward.go +++ b/internal/gateway/forward.go @@ -37,6 +37,7 @@ type ForwardInput struct { ExternalModel string UpstreamModelID string OnStreamReady func() + OnFirstResponse func() } type UpstreamResult struct { @@ -425,6 +426,9 @@ func (forwarder *Forwarder) ForwardStream( result.Stream = observeStreamTermination(ctx, err, streamEvents) return result } + if input.OnFirstResponse != nil { + input.OnFirstResponse() + } if rewrittenStream.consumeReadTerminalBoundary() { streamEvents.markTerminalForwarded() } diff --git a/internal/gateway/handler.go b/internal/gateway/handler.go index 6a9aa2c2..12156df8 100644 --- a/internal/gateway/handler.go +++ b/internal/gateway/handler.go @@ -378,6 +378,7 @@ func (handler *Handler) Handle(ginContext *gin.Context) { allowedKeyRefs[ref.ID] = ref } recorder.setClientModel(model) + recorder.setStream(metadata.Stream) recorder.setUsageApplicable(metadata.ObserveUsage) recorder.setUsageDiagnostics(metadata.UsageDiagnostics) @@ -551,6 +552,9 @@ func (handler *Handler) executeAttempts( OnStreamReady: func() { handler.recordSuccess(selectedKeyID, handler.now()) }, + OnFirstResponse: func() { + recorder.recordFirstResponse() + }, } if recorder != nil { recorder.freezeNextAttemptPricing( diff --git a/internal/gateway/request_log.go b/internal/gateway/request_log.go index 8d6de32c..b286664f 100644 --- a/internal/gateway/request_log.go +++ b/internal/gateway/request_log.go @@ -50,6 +50,8 @@ type requestRecorder struct { accessKeyID uint protocol protocol.Protocol clientModel string + stream bool + firstResponseMs *int64 usageApplicable bool usageDiagnostics usage.Diagnostics attempts []telemetry.Attempt @@ -109,20 +111,22 @@ func (recorder *requestRecorder) emit() { duration = 0 } recorder.sink.Emit(telemetry.RequestEvent{ - RequestID: recorder.requestID, - CompletedAt: completedAt.UTC(), - AccessKeyID: recorder.accessKeyID, - Protocol: recorder.protocol, - ClientModel: recorder.clientModel, - UpstreamModel: recorder.outcome.upstreamModel, - Status: recorder.outcome.status, - StatusCode: recorder.outcome.statusCode, - ErrorCode: recorder.outcome.errorCode, - ErrorSummary: recorder.outcome.errorSummary, - DurationMs: duration.Milliseconds(), - AffinityHit: false, - Attempts: append([]telemetry.Attempt(nil), recorder.attempts...), - Usage: recorder.usage, + RequestID: recorder.requestID, + CompletedAt: completedAt.UTC(), + AccessKeyID: recorder.accessKeyID, + Protocol: recorder.protocol, + ClientModel: recorder.clientModel, + UpstreamModel: recorder.outcome.upstreamModel, + Status: recorder.outcome.status, + StatusCode: recorder.outcome.statusCode, + ErrorCode: recorder.outcome.errorCode, + ErrorSummary: recorder.outcome.errorSummary, + Stream: recorder.stream, + FirstResponseMs: recorder.firstResponseMs, + DurationMs: duration.Milliseconds(), + AffinityHit: false, + Attempts: append([]telemetry.Attempt(nil), recorder.attempts...), + Usage: recorder.usage, }) } @@ -132,6 +136,24 @@ func (recorder *requestRecorder) setClientModel(model string) { } } +func (recorder *requestRecorder) setStream(stream bool) { + if recorder != nil { + recorder.stream = stream + } +} + +func (recorder *requestRecorder) recordFirstResponse() { + if recorder == nil || !recorder.stream || recorder.firstResponseMs != nil || recorder.now == nil { + return + } + duration := recorder.now().Sub(recorder.startedAt) + if duration < 0 { + duration = 0 + } + value := duration.Milliseconds() + recorder.firstResponseMs = &value +} + func (recorder *requestRecorder) setUsageApplicable(applicable bool) { if recorder != nil { recorder.usageApplicable = applicable @@ -426,13 +448,18 @@ func quoteFrozenAttempt( if frozen.table == nil || frozen.scopeKey == "" || frozen.upstreamModel == "" { return observation } - quote := frozen.table.Quote(pricing.Identity{ + quote, receipt := frozen.table.QuoteWithReceipt(pricing.Identity{ ScopeKey: frozen.scopeKey, ModelID: frozen.upstreamModel, }, result) observation.CostState = string(quote.State) observation.PricingCompleteness = string(quote.Completeness) observation.EstimatedCostNanoUSD = int64(quote.EstimatedCostNanoUSD) + if receipt != nil { + if encoded, err := json.Marshal(receipt); err == nil { + observation.ReceiptJSON = string(encoded) + } + } return observation } diff --git a/internal/gateway/request_log_test.go b/internal/gateway/request_log_test.go index d1f05a18..c49a2699 100644 --- a/internal/gateway/request_log_test.go +++ b/internal/gateway/request_log_test.go @@ -33,6 +33,40 @@ import ( "gpt-load/internal/usage" ) +func TestRequestRecorderCapturesFirstResponseAfterDownstreamCommit(t *testing.T) { + startedAt := time.Date(2026, time.August, 5, 8, 0, 0, 0, time.UTC) + sink := &recordingRequestLogSink{} + times := []time.Time{startedAt.Add(340 * time.Millisecond), startedAt.Add(2 * time.Second)} + now := func() time.Time { + value := times[0] + times = times[1:] + return value + } + recorder := newRequestRecorder( + sink, + "00000000-0000-4000-8000-000000000001", + startedAt, + 1, + protocol.OpenAICompletions, + now, + ) + recorder.setStream(true) + recorder.recordFirstResponse() + recorder.recordFirstResponse() + recorder.emit() + + events := sink.snapshot() + if len(events) != 1 || !events[0].Stream || events[0].FirstResponseMs == nil || + *events[0].FirstResponseMs != 340 || events[0].DurationMs != 2_000 { + t.Fatalf("captured timing = %#v", events) + } +} + +func withoutPricingReceipt(value telemetry.PricingObservation) telemetry.PricingObservation { + value.ReceiptJSON = "" + return value +} + const fixedRequestID = "11111111-2222-4333-8444-555555555555" type rpmLimiterCall struct { @@ -223,7 +257,7 @@ func TestHandlerRecordsProtocolOnlyResponsesResourceWithoutFabricatingModels(t * len(event.Attempts) != 1 || event.Attempts[0].UpstreamModel != "" || event.Usage.Result.State != usage.StateNotApplicable || - event.Usage.Pricing != (telemetry.PricingObservation{ + withoutPricingReceipt(event.Usage.Pricing) != (telemetry.PricingObservation{ CostState: "not_applicable", PricingCompleteness: "not_applicable", }) { t.Fatalf("event = %#v", event) @@ -265,7 +299,7 @@ func TestHandlerBillableResponsesUsageWithoutModelIsUnpriced(t *testing.T) { engine.ServeHTTP(httptest.NewRecorder(), request) events := sink.snapshot() - if len(events) != 1 || events[0].Usage.Pricing != (telemetry.PricingObservation{ + if len(events) != 1 || withoutPricingReceipt(events[0].Usage.Pricing) != (telemetry.PricingObservation{ CostState: "unpriced", PricingCompleteness: "unavailable", }) { t.Fatalf("events = %#v", events) @@ -410,7 +444,7 @@ func TestHandlerFreezesAttemptPriceBeforeForward(t *testing.T) { PricingCompleteness: string(pricing.CompletenessComplete), EstimatedCostNanoUSD: 2_000_000_000, } - if events[0].Usage.Pricing != want { + if withoutPricingReceipt(events[0].Usage.Pricing) != want { t.Fatalf("frozen pricing = %#v, want %#v", events[0].Usage.Pricing, want) } if provider.LoadCount() != 1 { @@ -445,7 +479,7 @@ func TestRequestRecorderPreservesKnownCostWhenUsedOutputPriceIsUnavailable(t *te }, }, health.Result{}, model, index) - if got := recorder.usage.Pricing; got != (telemetry.PricingObservation{ + if got := withoutPricingReceipt(recorder.usage.Pricing); got != (telemetry.PricingObservation{ PriceScopeKey: "group:1", UpstreamModel: model, CostState: "priced", PricingCompleteness: "partial", EstimatedCostNanoUSD: 2_000_000_000, @@ -487,7 +521,7 @@ func TestRequestRecorderMergesRequestPricingDiagnosticsIntoKnownCost(t *testing. if !recorder.usage.Result.Diagnostics.Has(usage.DiagnosticUnsupportedBillableDetail) { t.Fatalf("usage diagnostics = %#v, want unsupported billable detail", recorder.usage.Result.Diagnostics) } - if got := recorder.usage.Pricing; got != (telemetry.PricingObservation{ + if got := withoutPricingReceipt(recorder.usage.Pricing); got != (telemetry.PricingObservation{ PriceScopeKey: "group:1", UpstreamModel: model, CostState: "priced", PricingCompleteness: "partial", EstimatedCostNanoUSD: 4_000_000_000, @@ -541,7 +575,7 @@ func TestHandlerUsesSelectedProviderModelForPricingInsteadOfAliasOrBodyModel(t * events := sink.snapshot() if len(events) != 1 || events[0].ClientModel != "client-alias" || - events[0].UpstreamModel != model || events[0].Usage.Pricing != (telemetry.PricingObservation{ + events[0].UpstreamModel != model || withoutPricingReceipt(events[0].Usage.Pricing) != (telemetry.PricingObservation{ PriceScopeKey: "provider:openai", UpstreamModel: model, CostState: "priced", PricingCompleteness: "complete", EstimatedCostNanoUSD: 3_000_000_000, @@ -580,7 +614,7 @@ func TestHandlerMarksExplicitUnsupportedPricingModePartial(t *testing.T) { t.Fatalf("events = %#v, want one", events) } if !events[0].Usage.Result.Diagnostics.Has(usage.DiagnosticUnsupportedBillableDetail) || - events[0].Usage.Pricing != (telemetry.PricingObservation{ + withoutPricingReceipt(events[0].Usage.Pricing) != (telemetry.PricingObservation{ PriceScopeKey: "group:1", UpstreamModel: "gpt-4o", CostState: "priced", PricingCompleteness: "partial", EstimatedCostNanoUSD: 4_000_000_000, @@ -785,7 +819,7 @@ func TestHandlerRetryExhaustionUsesProviderErrorAttemptAndItsFrozenPrice(t *test } event := events[0] if event.Usage.GroupID != 1 || event.Usage.KeyID != 1 || - event.Usage.AttemptSequence != 1 || event.Usage.Pricing != (telemetry.PricingObservation{ + event.Usage.AttemptSequence != 1 || withoutPricingReceipt(event.Usage.Pricing) != (telemetry.PricingObservation{ PriceScopeKey: "group:1", UpstreamModel: "gpt-4o", CostState: string(pricing.CostStatePriced), diff --git a/internal/pricing/nanousd.go b/internal/pricing/nanousd.go index 84e8f80e..56bfdd63 100644 --- a/internal/pricing/nanousd.go +++ b/internal/pricing/nanousd.go @@ -15,8 +15,8 @@ type NanoUSD int64 // Multiplier applies an exact positive ratio to a price component. type Multiplier struct { - Numerator int64 - Denominator int64 + Numerator int64 `json:"numerator"` + Denominator int64 `json:"denominator"` } // ParseUSD parses a non-negative decimal USD amount with at most nine decimal places. diff --git a/internal/pricing/quote.go b/internal/pricing/quote.go index 6facb9a9..589ad7fa 100644 --- a/internal/pricing/quote.go +++ b/internal/pricing/quote.go @@ -11,46 +11,69 @@ var ( // Quote prices a finalized usage result without modifying it. func (table *Table) Quote(identity Identity, result usage.Result) Quote { + quote, _ := table.QuoteWithReceipt(identity, result) + return quote +} + +// QuoteWithReceipt prices a finalized usage result and freezes the exact rule, +// tier, rates, multipliers, and component amounts used for the calculation. +func (table *Table) QuoteWithReceipt( + identity Identity, + result usage.Result, +) (Quote, *Receipt) { switch result.State { case usage.StateNotApplicable: - return Quote{State: CostStateNotApplicable, Completeness: CompletenessNotApplicable} + return Quote{State: CostStateNotApplicable, Completeness: CompletenessNotApplicable}, nil case usage.StateMissing: - return unavailableQuote() + return unavailableQuote(), nil case usage.StateComplete, usage.StatePartial: default: - return unavailableQuote() + return unavailableQuote(), nil } rule, ok := table.Lookup(identity) if !ok { - return unavailableQuote() + return unavailableQuote(), nil } if _, ok := usage.CheckedTotal(result.Tokens); !ok { - return unavailableQuote() + return unavailableQuote(), nil } inputTokens, ok := checkedInputTokens(result.Tokens) if !ok { - return unavailableQuote() + return unavailableQuote(), nil } prices := rule.Prices + var selectedThreshold *int64 for _, tier := range rule.ContextTiers { if inputTokens < tier.InputThresholdTokens { break } prices = tier.Prices + threshold := tier.InputThresholdTokens + selectedThreshold = &threshold } components := [...]struct { + code string tokens int64 price Price multiplier Multiplier }{ - {tokens: result.Tokens.UncachedInput, price: prices.Input, multiplier: directPriceMultiplier}, - {tokens: result.Tokens.CacheRead, price: prices.CacheRead, multiplier: directPriceMultiplier}, - {tokens: result.Tokens.CacheWrite5M, price: prices.CacheWrite, multiplier: directPriceMultiplier}, - {tokens: result.Tokens.CacheWrite1H, price: prices.CacheWrite, multiplier: cacheWriteOneHourMultiplier}, - {tokens: result.Tokens.Output, price: prices.Output, multiplier: directPriceMultiplier}, + {code: "input", tokens: result.Tokens.UncachedInput, price: prices.Input, multiplier: directPriceMultiplier}, + {code: "cache_read", tokens: result.Tokens.CacheRead, price: prices.CacheRead, multiplier: directPriceMultiplier}, + {code: "cache_write_5m", tokens: result.Tokens.CacheWrite5M, price: prices.CacheWrite, multiplier: directPriceMultiplier}, + {code: "cache_write_1h", tokens: result.Tokens.CacheWrite1H, price: prices.CacheWrite, multiplier: cacheWriteOneHourMultiplier}, + {code: "output", tokens: result.Tokens.Output, price: prices.Output, multiplier: directPriceMultiplier}, + } + receipt := &Receipt{ + SchemaVersion: 1, + Method: ReceiptMethodUnitRateSum, + MethodVersion: 1, + Currency: "USD", + Rule: identity, + ContextThresholdTokens: selectedThreshold, + LineItems: make([]ReceiptLine, 0, len(components)+1), } positiveBillable := result.Tokens.CacheWriteUnknown > 0 @@ -64,8 +87,15 @@ func (table *Table) Quote(identity Identity, result usage.Result) Quote { continue } positiveBillable = true + line := ReceiptLine{ + Code: component.code, + Quantity: component.tokens, + Multiplier: component.multiplier, + State: ReceiptLineUnpriced, + } if !component.price.Set { partial = true + receipt.LineItems = append(receipt.LineItems, line) continue } componentCost, ok := QuoteComponent( @@ -74,17 +104,32 @@ func (table *Table) Quote(identity Identity, result usage.Result) Quote { component.multiplier, ) if !ok { - return unavailableQuote() + return unavailableQuote(), nil } cost, ok = CheckedAddNanoUSD(cost, componentCost) if !ok { - return unavailableQuote() + return unavailableQuote(), nil } + rate := int64(component.price.NanoUSDPerMillion) + amount := int64(componentCost) + line.RateNanoUSDPerMillion = &rate + line.AmountNanoUSD = &amount + line.State = ReceiptLinePriced + receipt.LineItems = append(receipt.LineItems, line) pricedPositive = true } + if result.Tokens.CacheWriteUnknown > 0 { + receipt.LineItems = append(receipt.LineItems, ReceiptLine{ + Code: "cache_write", + Quantity: result.Tokens.CacheWriteUnknown, + Multiplier: directPriceMultiplier, + State: ReceiptLineUnpriced, + }) + } + receipt.TotalNanoUSD = int64(cost) if positiveBillable && !pricedPositive { - return unavailableQuote() + return unavailableQuote(), receipt } completeness := CompletenessComplete if partial { @@ -94,7 +139,7 @@ func (table *Table) Quote(identity Identity, result usage.Result) Quote { State: CostStatePriced, Completeness: completeness, EstimatedCostNanoUSD: cost, - } + }, receipt } func checkedInputTokens(tokens usage.Tokens) (int64, bool) { diff --git a/internal/pricing/quote_test.go b/internal/pricing/quote_test.go index ed0cde9c..c5f1ca8a 100644 --- a/internal/pricing/quote_test.go +++ b/internal/pricing/quote_test.go @@ -228,3 +228,71 @@ func TestQuotePartialUsageKeepsKnownCostAndPartialCompleteness(t *testing.T) { t.Fatalf("Quote() = %#v, want partial known cost %#v", quote, want) } } + +func TestQuoteWithReceiptFreezesExactTieredCalculation(t *testing.T) { + identity := Identity{ScopeKey: "provider:anthropic", ModelID: "claude-sonnet"} + threshold := int64(1_000) + table := mustTable(t, Rule{ + Identity: identity, + Prices: Prices{ + Input: fixedPrice(2), Output: fixedPrice(8), + CacheRead: fixedPrice(1), CacheWrite: fixedPrice(5), + }, + ContextTiers: []ContextTier{{ + InputThresholdTokens: threshold, + Prices: Prices{ + Input: fixedPrice(3), Output: fixedPrice(9), + CacheRead: fixedPrice(1), CacheWrite: fixedPrice(5), + }, + }}, + }) + + quote, receipt := table.QuoteWithReceipt(identity, usage.Result{ + Tokens: usage.Tokens{ + UncachedInput: 1_000_000, + CacheRead: 2_000_000, + CacheWrite5M: 1_000_000, + CacheWrite1H: 1_000_000, + Output: 1_000_000, + }, + State: usage.StateComplete, + }) + if quote != (Quote{ + State: CostStatePriced, Completeness: CompletenessComplete, + EstimatedCostNanoUSD: 27, + }) { + t.Fatalf("QuoteWithReceipt() quote = %#v", quote) + } + if receipt == nil || receipt.SchemaVersion != 1 || receipt.Method != "unit_rate_sum" || + receipt.MethodVersion != 1 || receipt.Currency != "USD" || + receipt.Rule != identity || receipt.ContextThresholdTokens == nil || + *receipt.ContextThresholdTokens != threshold || receipt.TotalNanoUSD != 27 { + t.Fatalf("QuoteWithReceipt() receipt = %#v", receipt) + } + if got, want := len(receipt.LineItems), 5; got != want { + t.Fatalf("receipt line items = %d, want %d: %#v", got, want, receipt.LineItems) + } + if receipt.LineItems[3].Code != "cache_write_1h" || + receipt.LineItems[3].Multiplier != (Multiplier{Numerator: 8, Denominator: 5}) || + receipt.LineItems[3].AmountNanoUSD == nil || *receipt.LineItems[3].AmountNanoUSD != 8 { + t.Fatalf("one-hour cache receipt line = %#v", receipt.LineItems[3]) + } +} + +func TestQuoteWithReceiptPreservesUnpricedPositiveComponents(t *testing.T) { + identity := Identity{ScopeKey: "provider:openai", ModelID: "gpt-4.1"} + table := mustTable(t, Rule{Identity: identity, Prices: Prices{Input: fixedPrice(7)}}) + + quote, receipt := table.QuoteWithReceipt(identity, usage.Result{ + Tokens: usage.Tokens{UncachedInput: 1_000_000, Output: 10}, + State: usage.StateComplete, + }) + if quote.Completeness != CompletenessPartial || receipt == nil || len(receipt.LineItems) != 2 { + t.Fatalf("QuoteWithReceipt() = %#v, %#v", quote, receipt) + } + output := receipt.LineItems[1] + if output.Code != "output" || output.State != ReceiptLineUnpriced || + output.RateNanoUSDPerMillion != nil || output.AmountNanoUSD != nil { + t.Fatalf("unpriced output receipt line = %#v", output) + } +} diff --git a/internal/pricing/receipt.go b/internal/pricing/receipt.go new file mode 100644 index 00000000..bb5f39c6 --- /dev/null +++ b/internal/pricing/receipt.go @@ -0,0 +1,70 @@ +package pricing + +import "fmt" + +// ValidateReceipt verifies a persisted request-time receipt without consulting +// the mutable current pricing table. +func ValidateReceipt(receipt Receipt) error { + if receipt.SchemaVersion != 1 || receipt.Method != ReceiptMethodUnitRateSum || + receipt.MethodVersion != 1 || receipt.Currency != "USD" { + return fmt.Errorf("unsupported pricing receipt contract") + } + if err := validateIdentity(receipt.Rule); err != nil { + return fmt.Errorf("invalid pricing receipt rule: %w", err) + } + if receipt.ContextThresholdTokens != nil && *receipt.ContextThresholdTokens < 0 { + return fmt.Errorf("invalid pricing receipt context threshold") + } + if receipt.TotalNanoUSD < 0 { + return fmt.Errorf("invalid pricing receipt total") + } + + allowed := map[string]struct{}{ + "input": {}, "cache_read": {}, "cache_write_5m": {}, + "cache_write_1h": {}, "cache_write": {}, "output": {}, + } + seen := make(map[string]struct{}, len(receipt.LineItems)) + total := NanoUSD(0) + for _, line := range receipt.LineItems { + if _, ok := allowed[line.Code]; !ok { + return fmt.Errorf("invalid pricing receipt line code %q", line.Code) + } + if _, exists := seen[line.Code]; exists { + return fmt.Errorf("duplicate pricing receipt line code %q", line.Code) + } + seen[line.Code] = struct{}{} + if line.Quantity <= 0 || line.Multiplier.Numerator <= 0 || + line.Multiplier.Denominator <= 0 { + return fmt.Errorf("invalid pricing receipt line quantity or multiplier") + } + switch line.State { + case ReceiptLinePriced: + if line.RateNanoUSDPerMillion == nil || line.AmountNanoUSD == nil || + *line.RateNanoUSDPerMillion < 0 || *line.AmountNanoUSD < 0 { + return fmt.Errorf("invalid priced receipt line") + } + amount, ok := QuoteComponent( + line.Quantity, + NanoUSD(*line.RateNanoUSDPerMillion), + line.Multiplier, + ) + if !ok || int64(amount) != *line.AmountNanoUSD { + return fmt.Errorf("pricing receipt line amount mismatch") + } + total, ok = CheckedAddNanoUSD(total, amount) + if !ok { + return fmt.Errorf("pricing receipt total overflows") + } + case ReceiptLineUnpriced: + if line.RateNanoUSDPerMillion != nil || line.AmountNanoUSD != nil { + return fmt.Errorf("invalid unpriced receipt line") + } + default: + return fmt.Errorf("invalid pricing receipt line state") + } + } + if int64(total) != receipt.TotalNanoUSD { + return fmt.Errorf("pricing receipt total mismatch") + } + return nil +} diff --git a/internal/pricing/types.go b/internal/pricing/types.go index a1b4927c..dc443184 100644 --- a/internal/pricing/types.go +++ b/internal/pricing/types.go @@ -18,8 +18,8 @@ type Prices struct { // Identity is the exact pricing identity of a real upstream model in one // canonical provider or group scope. type Identity struct { - ScopeKey string - ModelID string + ScopeKey string `json:"scope_key"` + ModelID string `json:"model_id"` } // ContextTier replaces all base prices once its inclusive threshold is met. @@ -62,6 +62,42 @@ type Quote struct { EstimatedCostNanoUSD NanoUSD } +// ReceiptMethodUnitRateSum identifies the stable line-item calculation used by +// the first persisted pricing receipt schema. +const ReceiptMethodUnitRateSum = "unit_rate_sum" + +// ReceiptLineState distinguishes a priced component from a positive component +// whose exact rate was unavailable at request time. +type ReceiptLineState string + +const ( + ReceiptLinePriced ReceiptLineState = "priced" + ReceiptLineUnpriced ReceiptLineState = "unpriced" +) + +// ReceiptLine is one frozen term in the request-time cost calculation. +type ReceiptLine struct { + Code string `json:"code"` + Quantity int64 `json:"quantity"` + RateNanoUSDPerMillion *int64 `json:"rate_nano_usd_per_million,omitempty"` + Multiplier Multiplier `json:"multiplier"` + State ReceiptLineState `json:"state"` + AmountNanoUSD *int64 `json:"amount_nano_usd,omitempty"` +} + +// Receipt is the immutable, versioned explanation of one request-time quote. +// It deliberately stores calculation inputs instead of a presentation string. +type Receipt struct { + SchemaVersion int `json:"schema_version"` + Method string `json:"method"` + MethodVersion int `json:"method_version"` + Currency string `json:"currency"` + Rule Identity `json:"rule"` + ContextThresholdTokens *int64 `json:"context_threshold_tokens,omitempty"` + LineItems []ReceiptLine `json:"line_items"` + TotalNanoUSD int64 `json:"total_nano_usd"` +} + // Table is an immutable exact pricing snapshot. type Table struct { rules map[Identity]Rule diff --git a/internal/requestlog/mapper.go b/internal/requestlog/mapper.go index d6360c81..407be0ee 100644 --- a/internal/requestlog/mapper.go +++ b/internal/requestlog/mapper.go @@ -33,28 +33,34 @@ func mapEvent( return models.RequestLog{}, fmt.Errorf("map request event usage/pricing: %w", err) } - attempts := make([]Attempt, 0, len(event.Attempts)) + receipt, err := canonicalPricingReceipt(event.Usage.Pricing) + if err != nil { + return models.RequestLog{}, fmt.Errorf("map request event pricing receipt: %w", err) + } + attempts := make([]models.RequestLogAttempt, 0, len(event.Attempts)) for _, attempt := range event.Attempts { - attempts = append(attempts, Attempt{ + attemptReceipt := models.JSON(nil) + if attempt.Sequence == event.Usage.AttemptSequence { + attemptReceipt = receipt + } + attempts = append(attempts, models.RequestLogAttempt{ + RequestID: event.RequestID, Sequence: attempt.Sequence, + CompletedAtMS: completedAtMS, GroupID: attempt.GroupID, GroupName: redactIdentityValue(redactor, attempt.GroupName), KeyID: attempt.KeyID, UpstreamModel: redactIdentityValue(redactor, projectModel(attempt.UpstreamModel)), StatusCode: attempt.StatusCode, DurationMs: attempt.DurationMs, - FailureCategory: attempt.FailureCategory, - Action: attempt.Action, + FailureCategory: string(attempt.FailureCategory), + Action: string(attempt.Action), WillRetry: attempt.WillRetry, ErrorCode: attempt.ErrorCode, ErrorSummary: sanitizeSummary(redactor, attempt.ErrorSummary), - Committed: attempt.Committed, + PricingReceipt: attemptReceipt, }) } - encodedAttempts, err := json.Marshal(attempts) - if err != nil { - encodedAttempts = []byte("[]") - } result := event.Usage.Result pricingObservation := event.Usage.Pricing @@ -69,10 +75,13 @@ func mapEvent( UpstreamModel: redactIdentityValue(redactor, projectModel(event.UpstreamModel)), Status: string(event.Status), StatusCode: event.StatusCode, + Stream: event.Stream, + FirstResponseMs: event.FirstResponseMs, DurationMs: event.DurationMs, + AttemptCount: len(attempts), ErrorCode: event.ErrorCode, ErrorSummary: sanitizeSummary(redactor, event.ErrorSummary), - AffinityHit: false, + AffinityHit: event.AffinityHit, UncachedInputTokens: result.Tokens.UncachedInput, OutputTokens: result.Tokens.Output, CacheReadTokens: result.Tokens.CacheRead, @@ -83,11 +92,43 @@ func mapEvent( UsageState: string(result.State), CostState: pricingObservation.CostState, PricingCompleteness: pricingObservation.PricingCompleteness, - Attempts: models.JSON(encodedAttempts), + AttemptRows: attempts, }, nil } +func canonicalPricingReceipt(observation telemetry.PricingObservation) (models.JSON, error) { + if observation.ReceiptJSON == "" { + return nil, nil + } + var receipt pricing.Receipt + if err := json.Unmarshal([]byte(observation.ReceiptJSON), &receipt); err != nil { + return nil, fmt.Errorf("decode receipt: %w", err) + } + if err := pricing.ValidateReceipt(receipt); err != nil { + return nil, err + } + if receipt.Rule != (pricing.Identity{ + ScopeKey: observation.PriceScopeKey, + ModelID: observation.UpstreamModel, + }) || receipt.TotalNanoUSD != observation.EstimatedCostNanoUSD { + return nil, fmt.Errorf("receipt does not match frozen pricing observation") + } + encoded, err := json.Marshal(receipt) + if err != nil { + return nil, fmt.Errorf("encode receipt: %w", err) + } + return models.JSON(encoded), nil +} + func validateFrozenObservation(event telemetry.RequestEvent) error { + if event.DurationMs < 0 { + return fmt.Errorf("negative request duration") + } + if event.FirstResponseMs != nil { + if !event.Stream || *event.FirstResponseMs < 0 || *event.FirstResponseMs > event.DurationMs { + return fmt.Errorf("invalid first response duration") + } + } result := event.Usage.Result for _, value := range [...]int64{ result.Tokens.UncachedInput, diff --git a/internal/requestlog/mapper_test.go b/internal/requestlog/mapper_test.go index 348be011..5a418e0d 100644 --- a/internal/requestlog/mapper_test.go +++ b/internal/requestlog/mapper_test.go @@ -1,7 +1,6 @@ package requestlog import ( - "encoding/json" "math" "strings" "testing" @@ -57,12 +56,9 @@ func TestMapEventPersistsFrozenUsagePricingAndAttribution(t *testing.T) { t.Fatalf("persisted frozen pricing = %+v", row) } - var attempts []Attempt - if err := json.Unmarshal(row.Attempts, &attempts); err != nil { - t.Fatalf("unmarshal attempts: %v", err) - } - if len(attempts) != 1 || attempts[0].GroupID != 7 || attempts[0].KeyID != 8 { - t.Fatalf("attempts = %+v", attempts) + if len(row.AttemptRows) != 1 || row.AttemptRows[0].GroupID != 7 || + row.AttemptRows[0].KeyID != 8 { + t.Fatalf("attempts = %+v", row.AttemptRows) } } @@ -201,13 +197,9 @@ func TestMapEventDefensivelyRedactsAndBoundsSummaries(t *testing.T) { strings.Contains(row.ErrorSummary, secret) || !strings.HasSuffix(row.ErrorSummary, truncatedMarker) { t.Fatalf("request summary was not sanitized: %q", row.ErrorSummary) } - var attempts []Attempt - if err := json.Unmarshal(row.Attempts, &attempts); err != nil { - t.Fatal(err) - } - if len(attempts) != 1 || strings.Contains(attempts[0].ErrorSummary, secret) || - !strings.HasSuffix(attempts[0].ErrorSummary, truncatedMarker) { - t.Fatalf("attempt summary was not sanitized: %+v", attempts) + if len(row.AttemptRows) != 1 || strings.Contains(row.AttemptRows[0].ErrorSummary, secret) || + !strings.HasSuffix(row.AttemptRows[0].ErrorSummary, truncatedMarker) { + t.Fatalf("attempt summary was not sanitized: %+v", row.AttemptRows) } } @@ -215,13 +207,10 @@ func TestMapEventBoundsUnattributedAttemptModelsButRejectsOversizedBoundModel(t event := testEvent("model-bounds") event.Attempts = append(event.Attempts, telemetry.Attempt{Sequence: 2, UpstreamModel: strings.Repeat("界", 100)}) row := mustMapEvent(t, redact.New(), event) - var attempts []Attempt - if err := json.Unmarshal(row.Attempts, &attempts); err != nil { - t.Fatal(err) - } - if len(attempts[1].UpstreamModel) > maxModelBytes || !utf8.ValidString(attempts[1].UpstreamModel) || - !strings.HasSuffix(attempts[1].UpstreamModel, truncatedMarker) { - t.Fatalf("unattributed attempt model = %q", attempts[1].UpstreamModel) + if len(row.AttemptRows[1].UpstreamModel) > maxModelBytes || + !utf8.ValidString(row.AttemptRows[1].UpstreamModel) || + !strings.HasSuffix(row.AttemptRows[1].UpstreamModel, truncatedMarker) { + t.Fatalf("unattributed attempt model = %q", row.AttemptRows[1].UpstreamModel) } overlong := strings.Repeat("x", maxModelBytes+1) diff --git a/internal/requestlog/query.go b/internal/requestlog/query.go index c2eaf36a..05410b52 100644 --- a/internal/requestlog/query.go +++ b/internal/requestlog/query.go @@ -4,6 +4,9 @@ import ( "context" "encoding/json" "fmt" + "strings" + + "gorm.io/gorm" "gpt-load/internal/pricing" "gpt-load/internal/protocol" @@ -31,22 +34,9 @@ func (service *Service) List(ctx context.Context, input ListQuery) (Page, error) if input.ToMS != nil { query = query.Where("completed_at_ms < ?", *input.ToMS) } - if input.GroupID != nil { - query = query.Where(` - EXISTS ( - SELECT 1 - FROM json_each(COALESCE(request_logs.attempts, '[]')) AS attempt - WHERE json_type(attempt.value, '$.group_id') = 'integer' - AND json_extract(attempt.value, '$.group_id') = ? - ) - `, *input.GroupID) - } if input.ClientModel != "" { query = query.Where("client_model = ?", input.ClientModel) } - if input.UpstreamModel != "" { - query = query.Where("upstream_model = ?", input.UpstreamModel) - } if input.AccessKeyID != nil { query = query.Where("access_key_id = ?", *input.AccessKeyID) } @@ -56,6 +46,54 @@ func (service *Service) List(ctx context.Context, input ListQuery) (Page, error) if input.RequestID != "" { query = query.Where("id = ?", input.RequestID) } + if input.Protocol != "" { + query = query.Where("protocol = ?", input.Protocol) + } + if input.Stream != nil { + query = query.Where("stream = ?", *input.Stream) + } + if input.FinalStatusCode != nil { + query = query.Where("status_code = ?", *input.FinalStatusCode) + } + if input.UsageState != "" { + query = query.Where("usage_state = ?", input.UsageState) + } + if input.CostState != "" { + query = query.Where("cost_state = ?", input.CostState) + } + if input.PricingCompleteness != "" { + query = query.Where("pricing_completeness = ?", input.PricingCompleteness) + } + if input.CachePresent != nil { + expression := `(cache_read_tokens + cache_write_5m_tokens + cache_write_1h_tokens + cache_write_unknown_tokens) > 0` + if !*input.CachePresent { + expression = `(cache_read_tokens + cache_write_5m_tokens + cache_write_1h_tokens + cache_write_unknown_tokens) = 0` + } + query = query.Where(expression) + } + if input.RetryState == RetryStateRetried { + query = query.Where("attempt_count > 1") + } else if input.RetryState == RetryStateNotRetried { + query = query.Where("attempt_count <= 1") + } + retryCountExpression := "CASE WHEN attempt_count > 1 THEN attempt_count - 1 ELSE 0 END" + if input.RetryCountMin != nil { + query = query.Where(retryCountExpression+" >= ?", *input.RetryCountMin) + } + if input.RetryCountMax != nil { + query = query.Where(retryCountExpression+" <= ?", *input.RetryCountMax) + } + query = applyNullableRange(query, "first_response_ms", input.FirstResponseMinMS, input.FirstResponseMaxMS) + query = applyNullableRange(query, "duration_ms", input.DurationMinMS, input.DurationMaxMS) + query = applyNullableRange( + query, + "(uncached_input_tokens + cache_read_tokens + cache_write_5m_tokens + cache_write_1h_tokens + cache_write_unknown_tokens)", + input.InputTokensMin, + input.InputTokensMax, + ) + query = applyNullableRange(query, "output_tokens", input.OutputTokensMin, input.OutputTokensMax) + query = applyNullableRange(query, "estimated_cost_nano_usd", input.CostMinNanoUSD, input.CostMaxNanoUSD) + query = applyAttemptFilters(query, input) if input.Cursor != nil { query = query.Where( "completed_at_ms < ? OR (completed_at_ms = ? AND id < ?)", @@ -93,18 +131,131 @@ func (service *Service) List(ctx context.Context, input ListQuery) (Page, error) return page, nil } +func applyNullableRange[T int | int64]( + query *gorm.DB, + expression string, + minimum *T, + maximum *T, +) *gorm.DB { + if minimum != nil { + query = query.Where(expression+" >= ?", *minimum) + } + if maximum != nil { + query = query.Where(expression+" <= ?", *maximum) + } + return query +} + +func applyAttemptFilters(query *gorm.DB, input ListQuery) *gorm.DB { + conditions := make([]string, 0, 6) + arguments := make([]any, 0, 6) + if input.GroupID != nil { + conditions = append(conditions, "attempt.group_id = ?") + arguments = append(arguments, *input.GroupID) + } + if input.UpstreamKeyID != nil { + conditions = append(conditions, "attempt.key_id = ?") + arguments = append(arguments, *input.UpstreamKeyID) + } + if input.UpstreamModel != "" { + conditions = append(conditions, "attempt.upstream_model = ?") + arguments = append(arguments, input.UpstreamModel) + } + if input.AttemptStatusCode != nil { + conditions = append(conditions, "attempt.status_code = ?") + arguments = append(arguments, *input.AttemptStatusCode) + } + if input.FailureCategory != "" { + conditions = append(conditions, "attempt.failure_category = ?") + arguments = append(arguments, input.FailureCategory) + } + if input.AttemptErrorCode != "" { + conditions = append(conditions, "attempt.error_code = ?") + arguments = append(arguments, input.AttemptErrorCode) + } + if len(conditions) == 0 { + return query + } + statement := `EXISTS ( + SELECT 1 FROM request_log_attempts AS attempt + WHERE attempt.request_id = request_logs.id AND ` + + strings.Join(conditions, " AND ") + ` + )` + return query.Where(statement, arguments...) +} + +// Get returns one request with all retry attempts and its frozen pricing receipt. +func (service *Service) Get(ctx context.Context, requestID string) (Record, error) { + var record Record + err := service.db.WithContext(ctx).Transaction(func(tx *gorm.DB) error { + var row models.RequestLog + if err := tx.Where("id = ?", requestID).First(&row).Error; err != nil { + return fmt.Errorf("query request log detail: %w", err) + } + records, err := decodeRequestLogRows([]models.RequestLog{row}) + if err != nil { + return err + } + if err := loadAccessKeyRefs(ctx, tx, records); err != nil { + return err + } + + var attemptRows []models.RequestLogAttempt + if err := tx.Where("request_id = ?", requestID). + Order("sequence ASC"). + Find(&attemptRows).Error; err != nil { + return fmt.Errorf("query request log attempts: %w", err) + } + attempts, err := decodeAttemptRows(attemptRows) + if err != nil { + return err + } + records[0].Attempts = attempts + record = records[0] + return nil + }) + if err != nil { + return Record{}, err + } + return record, nil +} + +func decodeAttemptRows(rows []models.RequestLogAttempt) ([]Attempt, error) { + attempts := make([]Attempt, 0, len(rows)) + for _, row := range rows { + var receipt *pricing.Receipt + if len(row.PricingReceipt) > 0 && string(row.PricingReceipt) != "null" { + var decoded pricing.Receipt + if err := json.Unmarshal(row.PricingReceipt, &decoded); err != nil { + return nil, fmt.Errorf("decode request log pricing receipt: %w", err) + } + if err := pricing.ValidateReceipt(decoded); err != nil { + return nil, fmt.Errorf("decode request log pricing receipt: %w", err) + } + receipt = &decoded + } + attempts = append(attempts, Attempt{ + Sequence: row.Sequence, + GroupID: row.GroupID, + GroupName: row.GroupName, + KeyID: row.KeyID, + UpstreamModel: row.UpstreamModel, + StatusCode: row.StatusCode, + DurationMs: row.DurationMs, + FailureCategory: telemetry.FailureCategory(row.FailureCategory), + Action: telemetry.Action(row.Action), + WillRetry: row.WillRetry, + ErrorCode: row.ErrorCode, + ErrorSummary: row.ErrorSummary, + PricingReceipt: receipt, + }) + } + return attempts, nil +} + func decodeRequestLogRows(rows []models.RequestLog) ([]Record, error) { records := make([]Record, 0, len(rows)) for _, row := range rows { - attempts := make([]Attempt, 0) - if len(row.Attempts) > 0 && string(row.Attempts) != "null" { - if err := json.Unmarshal(row.Attempts, &attempts); err != nil { - return nil, fmt.Errorf("decode request log attempts: %w", err) - } - if attempts == nil { - attempts = make([]Attempt, 0) - } - } if err := validateRequestLogUsageCost(row); err != nil { return nil, err } @@ -117,11 +268,14 @@ func decodeRequestLogRows(rows []models.RequestLog) ([]Record, error) { UpstreamModel: row.UpstreamModel, Status: telemetry.RequestStatus(row.Status), StatusCode: row.StatusCode, + Stream: row.Stream, + FirstResponseMs: row.FirstResponseMs, DurationMs: row.DurationMs, + AttemptCount: row.AttemptCount, ErrorCode: row.ErrorCode, ErrorSummary: row.ErrorSummary, AffinityHit: row.AffinityHit, - Attempts: attempts, + Attempts: nil, GroupID: row.GroupID, UsageState: usage.State(row.UsageState), CostState: pricing.CostState(row.CostState), @@ -173,6 +327,10 @@ func validateRequestLogUsageCost(row models.RequestLog) error { } func (service *Service) loadAccessKeyRefs(ctx context.Context, records []Record) error { + return loadAccessKeyRefs(ctx, service.db, records) +} + +func loadAccessKeyRefs(ctx context.Context, db *gorm.DB, records []Record) error { if len(records) == 0 { return nil } @@ -191,7 +349,7 @@ func (service *Service) loadAccessKeyRefs(ctx context.Context, records []Record) ID uint Name string } - if err := service.db.WithContext(ctx). + if err := db.WithContext(ctx). Model(&models.AccessKey{}). Select("id", "name"). Where("id IN ?", ids). diff --git a/internal/requestlog/query_test.go b/internal/requestlog/query_test.go index d7fbbe1d..3bd66c82 100644 --- a/internal/requestlog/query_test.go +++ b/internal/requestlog/query_test.go @@ -40,7 +40,6 @@ func TestDecodeRequestLogRowsPreservesUsageCostAttribution(t *testing.T) { UsageState: string(usage.StateComplete), CostState: string(pricing.CostStatePriced), PricingCompleteness: string(pricing.CompletenessComplete), - Attempts: models.JSON(`[]`), }} records, err := decodeRequestLogRows(rows) @@ -61,28 +60,26 @@ func TestDecodeRequestLogRowsPreservesUsageCostAttribution(t *testing.T) { } } -func TestDecodeRequestLogRowsIgnoresHistoricalKeyMask(t *testing.T) { - rows := []models.RequestLog{{ - ID: "00000000-0000-4000-8000-000000000605", - CompletedAtMS: 1_785_110_400_000, - Protocol: string(protocol.OpenAICompletions), - Status: string(telemetry.RequestStatusSuccess), - UsageState: string(usage.StateNotApplicable), - CostState: string(pricing.CostStateNotApplicable), - PricingCompleteness: string(pricing.CompletenessNotApplicable), - Attempts: models.JSON( - `[{"sequence":1,"group_id":7,"group_name":"Primary","key_id":11,"key_mask":"prov****safe","upstream_model":"model","status_code":200,"duration_ms":10,"failure_category":"ok","action":"terminate","will_retry":false,"error_code":"","error_summary":"","committed":true}]`, - ), - }} - - records, err := decodeRequestLogRows(rows) +func TestDecodeAttemptRowsExposesOnlyNormalizedSafeFields(t *testing.T) { + attempts, err := decodeAttemptRows([]models.RequestLogAttempt{{ + RequestID: "00000000-0000-4000-8000-000000000605", + Sequence: 1, + GroupID: 7, + GroupName: "Primary", + KeyID: 11, + UpstreamModel: "model", + StatusCode: 200, + DurationMs: 10, + FailureCategory: string(telemetry.FailureCategoryOK), + Action: string(telemetry.ActionTerminate), + }}) if err != nil { - t.Fatalf("decodeRequestLogRows() error = %v", err) + t.Fatalf("decodeAttemptRows() error = %v", err) } - if len(records) != 1 || len(records[0].Attempts) != 1 { - t.Fatalf("records = %#v, want one historical attempt", records) + if len(attempts) != 1 { + t.Fatalf("attempts = %#v, want one attempt", attempts) } - encoded, err := json.Marshal(records[0].Attempts[0]) + encoded, err := json.Marshal(attempts[0]) if err != nil { t.Fatalf("marshal decoded attempt: %v", err) } @@ -102,7 +99,6 @@ func TestDecodeRequestLogRowsRejectsInvalidUsageCostValues(t *testing.T) { UsageState: string(usage.StateComplete), CostState: string(pricing.CostStatePriced), PricingCompleteness: string(pricing.CompletenessComplete), - Attempts: models.JSON(`[]`), } tests := []struct { name string @@ -190,7 +186,6 @@ func TestDecodeRequestLogRowsAcceptsApprovedUsageCostMatrix(t *testing.T) { CostState: string(test.costState), PricingCompleteness: string(test.completeness), EstimatedCostNanoUSD: test.cost, - Attempts: models.JSON(`[]`), } records, err := decodeRequestLogRows([]models.RequestLog{row}) if err != nil { @@ -263,8 +258,8 @@ func TestServiceListAppliesAllFiltersAndGroupJSON(t *testing.T) { to := from.Add(time.Hour) targetID := "00000000-0000-4000-8000-000000000201" integerAttempts := []Attempt{ - {Sequence: 1, GroupID: 12, GroupName: "retry-first", WillRetry: true}, - {Sequence: 2, GroupID: 13, GroupName: "retry-second"}, + {Sequence: 1, GroupID: 12, GroupName: "retry-first", UpstreamModel: "different-upstream-model", WillRetry: true}, + {Sequence: 2, GroupID: 13, GroupName: "retry-second", UpstreamModel: "different-upstream-model"}, } target := requestLogQueryRow(targetID, from, 71, "client-model", integerAttempts) target.UpstreamModel = "different-upstream-model" @@ -299,7 +294,6 @@ func TestServiceListAppliesAllFiltersAndGroupJSON(t *testing.T) { nil, ) stringGroup.Status = string(telemetry.RequestStatusError) - stringGroup.Attempts = models.JSON(`[{"group_id":"12"}]`) createRequestLogQueryRow(t, db, stringGroup) realGroup := requestLogQueryRow( @@ -310,7 +304,6 @@ func TestServiceListAppliesAllFiltersAndGroupJSON(t *testing.T) { nil, ) realGroup.Status = string(telemetry.RequestStatusError) - realGroup.Attempts = models.JSON(`[{"group_id":12.0}]`) createRequestLogQueryRow(t, db, realGroup) upstreamOnly := requestLogQueryRow( @@ -351,7 +344,6 @@ func TestServiceListAppliesAllFiltersAndGroupJSON(t *testing.T) { nil, ) zeroAttempts.Status = string(telemetry.RequestStatusError) - zeroAttempts.Attempts = nil createRequestLogQueryRow(t, db, zeroAttempts) groupID := uint(12) @@ -404,8 +396,8 @@ func TestServiceListGroupFilterUsesAnyAttemptWhileAttributionUsesFinalGroup(t *t db := openRequestLogQueryDB(t) event := testEvent("00000000-0000-4000-8000-000000000210") event.Attempts = []telemetry.Attempt{ - {Sequence: 1, GroupID: 12, KeyID: 1, UpstreamModel: "retry-model", WillRetry: true}, - {Sequence: 2, GroupID: 13, KeyID: 2, UpstreamModel: "final-model"}, + {Sequence: 1, GroupID: 12, GroupName: "retry", KeyID: 1, UpstreamModel: "retry-model", FailureCategory: telemetry.FailureCategoryRateLimited, Action: telemetry.ActionRetry, WillRetry: true}, + {Sequence: 2, GroupID: 13, GroupName: "final", KeyID: 2, UpstreamModel: "final-model", FailureCategory: telemetry.FailureCategoryOK, Action: telemetry.ActionTerminate}, } event.UpstreamModel = "final-model" event.Usage = telemetry.UsageObservation{ @@ -422,9 +414,7 @@ func TestServiceListGroupFilterUsesAnyAttemptWhileAttributionUsesFinalGroup(t *t if row.GroupID != 13 { t.Fatalf("top-level GroupID = %d, want final attribution 13", row.GroupID) } - if err := db.Create(&row).Error; err != nil { - t.Fatalf("create attributed RequestLog: %v", err) - } + createRequestLogQueryRow(t, db, row) service := newRequestLogTestService(db) for _, groupID := range []uint{12, 13} { @@ -441,6 +431,86 @@ func TestServiceListGroupFilterUsesAnyAttemptWhileAttributionUsesFinalGroup(t *t } } +func TestServiceListAttemptFiltersMustMatchTheSameAttempt(t *testing.T) { + db := openRequestLogQueryDB(t) + row := requestLogQueryRow( + "00000000-0000-4000-8000-000000000211", + time.Date(2026, time.July, 24, 12, 0, 0, 0, time.UTC), + 71, + "client-model", + []Attempt{ + { + Sequence: 1, GroupID: 12, GroupName: "retry", KeyID: 1, + StatusCode: 429, FailureCategory: telemetry.FailureCategoryRateLimited, + Action: telemetry.ActionRetry, WillRetry: true, + }, + { + Sequence: 2, GroupID: 13, GroupName: "final", KeyID: 2, + StatusCode: 200, FailureCategory: telemetry.FailureCategoryOK, + Action: telemetry.ActionTerminate, + }, + }, + ) + createRequestLogQueryRow(t, db, row) + service := newRequestLogTestService(db) + groupID := uint(12) + statusOK := 200 + + page, err := service.List(context.Background(), ListQuery{ + GroupID: &groupID, AttemptStatusCode: &statusOK, Limit: 50, + }) + if err != nil { + t.Fatalf("List() mismatched attempt filters error = %v", err) + } + if len(page.Items) != 0 { + t.Fatalf("mismatched attempt filters returned %#v, want empty", page.Items) + } + + statusRateLimited := 429 + page, err = service.List(context.Background(), ListQuery{ + GroupID: &groupID, AttemptStatusCode: &statusRateLimited, + FailureCategory: telemetry.FailureCategoryRateLimited, Limit: 50, + }) + if err != nil { + t.Fatalf("List() matching attempt filters error = %v", err) + } + if got, want := requestIDs(page.Items), []string{row.ID}; !reflect.DeepEqual(got, want) { + t.Fatalf("matching attempt filters IDs = %v, want %v", got, want) + } +} + +func TestServiceListZeroRetryRangeIncludesRequestsWithoutUpstreamAttempts(t *testing.T) { + db := openRequestLogQueryDB(t) + base := time.Date(2026, time.July, 24, 12, 0, 0, 0, time.UTC) + zero := requestLogQueryRow( + "00000000-0000-4000-8000-000000000212", base, 71, "zero", nil, + ) + single := requestLogQueryRow( + "00000000-0000-4000-8000-000000000213", base.Add(time.Second), 71, "single", + []Attempt{{Sequence: 1, GroupID: 12, GroupName: "single", KeyID: 1}}, + ) + retried := requestLogQueryRow( + "00000000-0000-4000-8000-000000000214", base.Add(2*time.Second), 71, "retried", + []Attempt{ + {Sequence: 1, GroupID: 12, GroupName: "retry", KeyID: 1, WillRetry: true}, + {Sequence: 2, GroupID: 12, GroupName: "final", KeyID: 2}, + }, + ) + for _, row := range []models.RequestLog{zero, single, retried} { + createRequestLogQueryRow(t, db, row) + } + minimum, maximum := 0, 0 + page, err := newRequestLogTestService(db).List(context.Background(), ListQuery{ + RetryCountMin: &minimum, RetryCountMax: &maximum, Limit: 50, + }) + if err != nil { + t.Fatalf("List() zero retry range error = %v", err) + } + if got, want := requestIDs(page.Items), []string{single.ID, zero.ID}; !reflect.DeepEqual(got, want) { + t.Fatalf("zero retry range IDs = %v, want %v", got, want) + } +} + func TestServiceListBatchLoadsCurrentAccessKeyNames(t *testing.T) { db := openRequestLogQueryDB(t) current := models.AccessKey{ @@ -515,7 +585,7 @@ func TestServiceListBatchLoadsCurrentAccessKeyNames(t *testing.T) { } } -func TestServiceListNormalizesNullAttemptsToEmptyArray(t *testing.T) { +func TestServiceListOmitsAttemptsAndDetailLoadsThem(t *testing.T) { db := openRequestLogQueryDB(t) row := requestLogQueryRow( "00000000-0000-4000-8000-000000000401", @@ -524,23 +594,34 @@ func TestServiceListNormalizesNullAttemptsToEmptyArray(t *testing.T) { "zero-attempt", nil, ) - row.Attempts = nil + row.AttemptRows = []models.RequestLogAttempt{{ + RequestID: row.ID, + Sequence: 1, + CompletedAtMS: row.CompletedAtMS, + GroupID: 7, + GroupName: "Primary", + KeyID: 9, + StatusCode: 200, + DurationMs: 10, + FailureCategory: string(telemetry.FailureCategoryOK), + Action: string(telemetry.ActionTerminate), + }} + row.AttemptCount = 1 createRequestLogQueryRow(t, db, row) page, err := newRequestLogTestService(db).List(context.Background(), ListQuery{Limit: 50}) if err != nil { t.Fatalf("List() error = %v", err) } - if len(page.Items) != 1 || page.Items[0].Attempts == nil || - len(page.Items[0].Attempts) != 0 { - t.Fatalf("Attempts = %#v, want non-nil empty slice", page.Items) + if len(page.Items) != 1 || page.Items[0].Attempts != nil || page.Items[0].AttemptCount != 1 { + t.Fatalf("list item = %#v, want lightweight item without attempts", page.Items) } - encoded, err := json.Marshal(page.Items[0]) + detail, err := newRequestLogTestService(db).Get(context.Background(), row.ID) if err != nil { - t.Fatalf("json.Marshal() error = %v", err) + t.Fatalf("Get() error = %v", err) } - if string(encoded) == "" || !containsJSONFragment(encoded, `"Attempts":[]`) { - t.Fatalf("encoded Record = %s, want empty attempts array", encoded) + if len(detail.Attempts) != 1 || detail.Attempts[0].GroupName != "Primary" { + t.Fatalf("detail attempts = %#v", detail.Attempts) } } @@ -572,9 +653,44 @@ func requestLogQueryRow( clientModel string, attempts []Attempt, ) models.RequestLog { - encodedAttempts, err := json.Marshal(attempts) - if err != nil { - panic(err) + attemptRows := make([]models.RequestLogAttempt, 0, len(attempts)) + for index, attempt := range attempts { + groupID := attempt.GroupID + if groupID == 0 { + groupID = 1 + } + keyID := attempt.KeyID + if keyID == 0 { + keyID = 1 + } + sequence := attempt.Sequence + if sequence == 0 { + sequence = index + 1 + } + failureCategory := attempt.FailureCategory + if failureCategory == "" { + failureCategory = telemetry.FailureCategoryOK + } + action := attempt.Action + if action == "" { + action = telemetry.ActionTerminate + } + attemptRows = append(attemptRows, models.RequestLogAttempt{ + RequestID: id, + Sequence: sequence, + CompletedAtMS: completedAt.UTC().UnixMilli(), + GroupID: groupID, + GroupName: attempt.GroupName, + KeyID: keyID, + UpstreamModel: attempt.UpstreamModel, + StatusCode: attempt.StatusCode, + DurationMs: attempt.DurationMs, + FailureCategory: string(failureCategory), + Action: string(action), + WillRetry: attempt.WillRetry, + ErrorCode: attempt.ErrorCode, + ErrorSummary: attempt.ErrorSummary, + }) } return models.RequestLog{ ID: id, @@ -586,9 +702,10 @@ func requestLogQueryRow( Status: string(telemetry.RequestStatusSuccess), StatusCode: 200, DurationMs: 25, + AttemptCount: len(attemptRows), UsageState: string(usage.StateNotApplicable), CostState: string(pricing.CostStateNotApplicable), - Attempts: models.JSON(encodedAttempts), + AttemptRows: attemptRows, } } @@ -597,6 +714,11 @@ func createRequestLogQueryRow(t *testing.T, db *gorm.DB, row models.RequestLog) if err := db.Create(&row).Error; err != nil { t.Fatalf("create RequestLog %s: %v", row.ID, err) } + if len(row.AttemptRows) > 0 { + if err := db.Create(&row.AttemptRows).Error; err != nil { + t.Fatalf("create RequestLog attempts %s: %v", row.ID, err) + } + } } func requestIDs(records []Record) []string { diff --git a/internal/requestlog/service_test.go b/internal/requestlog/service_test.go index 2921de4c..e3ff06e4 100644 --- a/internal/requestlog/service_test.go +++ b/internal/requestlog/service_test.go @@ -197,12 +197,8 @@ func TestServiceEmitLifecycleAndDeepCopy(t *testing.T) { if len(rows) != 1 || rows[0].ID != "deep-copy" { t.Fatalf("written rows = %+v, want original request", rows) } - var attempts []Attempt - if err := json.Unmarshal(rows[0].Attempts, &attempts); err != nil { - t.Fatalf("unmarshal attempts: %v", err) - } - if len(attempts) != 1 || attempts[0].GroupName != "primary" { - t.Fatalf("written attempts = %+v, want original deep copy", attempts) + if len(rows[0].AttemptRows) != 1 || rows[0].AttemptRows[0].GroupName != "primary" { + t.Fatalf("written attempts = %+v, want original deep copy", rows[0].AttemptRows) } if err := service.Stop(context.Background()); err != nil { diff --git a/internal/requestlog/test_helpers_test.go b/internal/requestlog/test_helpers_test.go index 221e6629..594f5ebd 100644 --- a/internal/requestlog/test_helpers_test.go +++ b/internal/requestlog/test_helpers_test.go @@ -202,7 +202,6 @@ func aggregationRow( UsageState: string(usage.StateComplete), CostState: string(pricing.CostStatePriced), PricingCompleteness: string(pricing.CompletenessComplete), - Attempts: models.JSON(`[]`), } } diff --git a/internal/requestlog/types.go b/internal/requestlog/types.go index 1518daa2..d87d5792 100644 --- a/internal/requestlog/types.go +++ b/internal/requestlog/types.go @@ -37,25 +37,56 @@ type Attempt struct { WillRetry bool `json:"will_retry"` ErrorCode string `json:"error_code"` ErrorSummary string `json:"error_summary"` - Committed bool `json:"committed"` + PricingReceipt *pricing.Receipt `json:"pricing_receipt,omitempty"` } +type RetryState string + +const ( + RetryStateRetried RetryState = "retried" + RetryStateNotRetried RetryState = "not_retried" +) + type Cursor struct { CompletedAtMS int64 RequestID string } type ListQuery struct { - FromMS *int64 - ToMS *int64 - GroupID *uint - ClientModel string - UpstreamModel string - AccessKeyID *uint - Status telemetry.RequestStatus - RequestID string - Limit int - Cursor *Cursor + FromMS *int64 + ToMS *int64 + GroupID *uint + ClientModel string + UpstreamModel string + AccessKeyID *uint + Status telemetry.RequestStatus + RequestID string + Protocol protocol.Protocol + Stream *bool + FinalStatusCode *int + UsageState usage.State + CostState pricing.CostState + PricingCompleteness pricing.Completeness + CachePresent *bool + UpstreamKeyID *uint + AttemptStatusCode *int + FailureCategory telemetry.FailureCategory + AttemptErrorCode string + RetryState RetryState + RetryCountMin *int + RetryCountMax *int + FirstResponseMinMS *int64 + FirstResponseMaxMS *int64 + DurationMinMS *int64 + DurationMaxMS *int64 + InputTokensMin *int64 + InputTokensMax *int64 + OutputTokensMin *int64 + OutputTokensMax *int64 + CostMinNanoUSD *int64 + CostMaxNanoUSD *int64 + Limit int + Cursor *Cursor } type AccessKeyRef struct { @@ -73,7 +104,10 @@ type Record struct { UpstreamModel string Status telemetry.RequestStatus StatusCode int + Stream bool + FirstResponseMs *int64 DurationMs int64 + AttemptCount int ErrorCode string ErrorSummary string AffinityHit bool diff --git a/internal/requestlog/worker.go b/internal/requestlog/worker.go index 8c416474..9744eeb3 100644 --- a/internal/requestlog/worker.go +++ b/internal/requestlog/worker.go @@ -178,6 +178,15 @@ func writeRequestLogBatch(tx *gorm.DB, rows []models.RequestLog) error { if err := tx.CreateInBatches(newRows, batchSize).Error; err != nil { return fmt.Errorf("insert request logs: %w", err) } + attemptRows := make([]models.RequestLogAttempt, 0) + for _, row := range newRows { + attemptRows = append(attemptRows, row.AttemptRows...) + } + if len(attemptRows) > 0 { + if err := tx.CreateInBatches(attemptRows, batchSize).Error; err != nil { + return fmt.Errorf("insert request log attempts: %w", err) + } + } deltas, err := buildUsageStatDeltas(newRows) if err != nil { diff --git a/internal/storage/db.go b/internal/storage/db.go index 8ad9ca08..4285ef93 100644 --- a/internal/storage/db.go +++ b/internal/storage/db.go @@ -20,7 +20,7 @@ import ( ) // CurrentSchemaVersion identifies the SQLite schema supported by this binary. -const CurrentSchemaVersion uint = 4 +const CurrentSchemaVersion uint = 5 const sqliteBusyTimeoutMS = 5000 @@ -121,19 +121,19 @@ func AutoMigrate(db *gorm.DB) error { } } return db.Transaction(func(tx *gorm.DB) error { - if err := createSchemaV4Tables(tx); err != nil { + if err := createSchemaV5Tables(tx); err != nil { return err } - if err := createSchemaV4InfoTable(tx); err != nil { + if err := createSchemaV5InfoTable(tx); err != nil { return err } - if err := createSchemaV4Indexes(tx); err != nil { + if err := createSchemaV5Indexes(tx); err != nil { return err } if err := tx.Create(&schemaInfo{Version: CurrentSchemaVersion}).Error; err != nil { return fmt.Errorf("initialize schema_info: %w", err) } - return validateSchemaV4(tx) + return validateSchemaV5(tx) }) } @@ -148,7 +148,7 @@ func AutoMigrate(db *gorm.DB) error { CurrentSchemaVersion, ) } - return validateSchemaV4(db) + return validateSchemaV5(db) } func readSchemaVersion(db *gorm.DB) (uint, error) { diff --git a/internal/storage/db_test.go b/internal/storage/db_test.go index 74c210c3..11609c11 100644 --- a/internal/storage/db_test.go +++ b/internal/storage/db_test.go @@ -669,8 +669,8 @@ func TestAutoMigrateCreatesRequestLogFieldsAndCompositeIndexes(t *testing.T) { } } - if storage.CurrentSchemaVersion != 4 { - t.Fatalf("CurrentSchemaVersion = %d, want 4", storage.CurrentSchemaVersion) + if storage.CurrentSchemaVersion != 5 { + t.Fatalf("CurrentSchemaVersion = %d, want 5", storage.CurrentSchemaVersion) } } diff --git a/internal/storage/models/request.go b/internal/storage/models/request.go index 8f19a6c3..79ddf7d9 100644 --- a/internal/storage/models/request.go +++ b/internal/storage/models/request.go @@ -2,30 +2,54 @@ package models // RequestLog is the durable request-level audit and usage record. type RequestLog struct { - ID string `gorm:"type:varchar(36);primaryKey;not null;index:idx_request_logs_completed_id,priority:2,sort:desc;index:idx_request_logs_access_completed_id,priority:3,sort:desc;index:idx_request_logs_status_completed_id,priority:3,sort:desc;index:idx_request_logs_model_completed_id,priority:3,sort:desc;index:idx_request_logs_upstream_model_completed_id,priority:3,sort:desc"` - CompletedAtMS int64 `gorm:"column:completed_at_ms;not null;index:idx_request_logs_completed_id,priority:1,sort:desc;index:idx_request_logs_access_completed_id,priority:2,sort:desc;index:idx_request_logs_status_completed_id,priority:2,sort:desc;index:idx_request_logs_model_completed_id,priority:2,sort:desc;index:idx_request_logs_upstream_model_completed_id,priority:2,sort:desc"` - AccessKeyID uint `gorm:"not null;index:idx_request_logs_access_completed_id,priority:1"` - GroupID uint `gorm:"not null;default:0"` - Protocol string `gorm:"type:varchar(32);not null"` - ClientModel string `gorm:"type:varchar(255);not null;index:idx_request_logs_model_completed_id,priority:1"` - UpstreamModel string `gorm:"type:varchar(255);not null;index:idx_request_logs_upstream_model_completed_id,priority:1"` - Status string `gorm:"type:varchar(32);not null;index:idx_request_logs_status_completed_id,priority:1"` - StatusCode int `gorm:"not null"` - DurationMs int64 `gorm:"not null"` - ErrorCode string `gorm:"type:varchar(64);not null;default:''"` - ErrorSummary string `gorm:"type:text;not null;default:''"` - AffinityHit bool `gorm:"not null;default:false"` - UncachedInputTokens int64 `gorm:"column:uncached_input_tokens;not null;default:0"` - OutputTokens int64 `gorm:"not null;default:0"` - CacheReadTokens int64 `gorm:"not null;default:0"` - CacheWrite5MTokens int64 `gorm:"column:cache_write_5m_tokens;not null;default:0"` - CacheWrite1HTokens int64 `gorm:"column:cache_write_1h_tokens;not null;default:0"` - CacheWriteUnknownTokens int64 `gorm:"column:cache_write_unknown_tokens;not null;default:0"` - EstimatedCostNanoUSD int64 `gorm:"column:estimated_cost_nano_usd;not null;default:0;check:chk_request_log_cost_nano,estimated_cost_nano_usd >= 0"` - UsageState string `gorm:"type:varchar(32);not null;default:'not_applicable';check:chk_request_log_usage_state,usage_state IN ('complete','partial','missing','not_applicable')"` - CostState string `gorm:"type:varchar(32);not null;default:'not_applicable';check:chk_request_log_cost_state,cost_state IN ('priced','unpriced','not_applicable')"` - PricingCompleteness string `gorm:"type:varchar(32);not null;default:'not_applicable';check:chk_request_log_pricing_completeness,pricing_completeness IN ('complete','partial','unavailable','not_applicable')"` - Attempts JSON `gorm:"type:json"` + ID string `gorm:"type:varchar(36);primaryKey;not null;index:idx_request_logs_completed_id,priority:2,sort:desc;index:idx_request_logs_access_completed_id,priority:3,sort:desc;index:idx_request_logs_status_completed_id,priority:3,sort:desc;index:idx_request_logs_model_completed_id,priority:3,sort:desc;index:idx_request_logs_upstream_model_completed_id,priority:3,sort:desc"` + CompletedAtMS int64 `gorm:"column:completed_at_ms;not null;index:idx_request_logs_completed_id,priority:1,sort:desc;index:idx_request_logs_access_completed_id,priority:2,sort:desc;index:idx_request_logs_status_completed_id,priority:2,sort:desc;index:idx_request_logs_model_completed_id,priority:2,sort:desc;index:idx_request_logs_upstream_model_completed_id,priority:2,sort:desc"` + AccessKeyID uint `gorm:"not null;index:idx_request_logs_access_completed_id,priority:1"` + GroupID uint `gorm:"not null;default:0"` + Protocol string `gorm:"type:varchar(32);not null"` + ClientModel string `gorm:"type:varchar(255);not null;index:idx_request_logs_model_completed_id,priority:1"` + UpstreamModel string `gorm:"type:varchar(255);not null;index:idx_request_logs_upstream_model_completed_id,priority:1"` + Status string `gorm:"type:varchar(32);not null;index:idx_request_logs_status_completed_id,priority:1"` + StatusCode int `gorm:"not null"` + Stream bool `gorm:"not null;default:false"` + FirstResponseMs *int64 `gorm:"column:first_response_ms"` + DurationMs int64 `gorm:"not null"` + AttemptCount int `gorm:"not null;default:0"` + ErrorCode string `gorm:"type:varchar(64);not null;default:''"` + ErrorSummary string `gorm:"type:text;not null;default:''"` + AffinityHit bool `gorm:"not null;default:false"` + UncachedInputTokens int64 `gorm:"column:uncached_input_tokens;not null;default:0"` + OutputTokens int64 `gorm:"not null;default:0"` + CacheReadTokens int64 `gorm:"not null;default:0"` + CacheWrite5MTokens int64 `gorm:"column:cache_write_5m_tokens;not null;default:0"` + CacheWrite1HTokens int64 `gorm:"column:cache_write_1h_tokens;not null;default:0"` + CacheWriteUnknownTokens int64 `gorm:"column:cache_write_unknown_tokens;not null;default:0"` + EstimatedCostNanoUSD int64 `gorm:"column:estimated_cost_nano_usd;not null;default:0;check:chk_request_log_cost_nano,estimated_cost_nano_usd >= 0"` + UsageState string `gorm:"type:varchar(32);not null;default:'not_applicable';check:chk_request_log_usage_state,usage_state IN ('complete','partial','missing','not_applicable')"` + CostState string `gorm:"type:varchar(32);not null;default:'not_applicable';check:chk_request_log_cost_state,cost_state IN ('priced','unpriced','not_applicable')"` + PricingCompleteness string `gorm:"type:varchar(32);not null;default:'not_applicable';check:chk_request_log_pricing_completeness,pricing_completeness IN ('complete','partial','unavailable','not_applicable')"` + AttemptRows []RequestLogAttempt `gorm:"-"` +} + +// RequestLogAttempt is one durable upstream attempt belonging to a client +// request. Identity fields are snapshots and intentionally do not reference +// mutable Group or Key catalog rows. +type RequestLogAttempt struct { + RequestID string `gorm:"type:varchar(36);primaryKey;not null"` + Sequence int `gorm:"primaryKey;not null"` + CompletedAtMS int64 `gorm:"column:completed_at_ms;not null"` + GroupID uint `gorm:"not null"` + GroupName string `gorm:"type:varchar(255);not null"` + KeyID uint `gorm:"not null"` + UpstreamModel string `gorm:"type:varchar(255);not null;default:''"` + StatusCode int `gorm:"not null"` + DurationMs int64 `gorm:"not null"` + FailureCategory string `gorm:"type:varchar(32);not null"` + Action string `gorm:"type:varchar(32);not null"` + WillRetry bool `gorm:"not null;default:false"` + ErrorCode string `gorm:"type:varchar(64);not null;default:''"` + ErrorSummary string `gorm:"type:text;not null;default:''"` + PricingReceipt JSON `gorm:"type:json"` } // UsageStat is an hourly aggregate by access key, upstream group, and upstream model. diff --git a/internal/storage/schema_v4.go b/internal/storage/schema_v5.go similarity index 79% rename from internal/storage/schema_v4.go rename to internal/storage/schema_v5.go index 1f78c5d2..cd76754c 100644 --- a/internal/storage/schema_v4.go +++ b/internal/storage/schema_v5.go @@ -6,16 +6,16 @@ import ( "gorm.io/gorm" ) -func createSchemaV4Tables(db *gorm.DB) error { - for _, statement := range schemaV4TableStatements() { +func createSchemaV5Tables(db *gorm.DB) error { + for _, statement := range schemaV5TableStatements() { if err := db.Exec(statement).Error; err != nil { - return fmt.Errorf("create schema v4 table: %w", err) + return fmt.Errorf("create schema v5 table: %w", err) } } return nil } -func schemaV4TableStatements() []string { +func schemaV5TableStatements() []string { return []string{ `CREATE TABLE groups ( id integer PRIMARY KEY AUTOINCREMENT, @@ -78,7 +78,11 @@ func schemaV4TableStatements() []string { upstream_model varchar(255) NOT NULL, status varchar(32) NOT NULL, status_code integer NOT NULL, + stream numeric NOT NULL DEFAULT false, + first_response_ms integer + CHECK (first_response_ms IS NULL OR first_response_ms >= 0), duration_ms integer NOT NULL CHECK (duration_ms >= 0), + attempt_count integer NOT NULL DEFAULT 0 CHECK (attempt_count >= 0), error_code varchar(64) NOT NULL DEFAULT '', error_summary text NOT NULL DEFAULT '', affinity_hit numeric NOT NULL DEFAULT false, @@ -96,7 +100,6 @@ func schemaV4TableStatements() []string { usage_state varchar(32) NOT NULL DEFAULT 'not_applicable', cost_state varchar(32) NOT NULL DEFAULT 'not_applicable', pricing_completeness varchar(32) NOT NULL DEFAULT 'not_applicable', - attempts json, CONSTRAINT chk_request_log_cost_nano CHECK (estimated_cost_nano_usd >= 0), CONSTRAINT chk_request_log_status @@ -126,6 +129,35 @@ func schemaV4TableStatements() []string { )) ) )`, + `CREATE TABLE request_log_attempts ( + request_id varchar(36) NOT NULL, + sequence integer NOT NULL CHECK (sequence > 0), + completed_at_ms integer NOT NULL CHECK (completed_at_ms >= 0), + group_id integer NOT NULL CHECK (group_id > 0), + group_name varchar(255) NOT NULL, + key_id integer NOT NULL CHECK (key_id > 0), + upstream_model varchar(255) NOT NULL DEFAULT '', + status_code integer NOT NULL, + duration_ms integer NOT NULL CHECK (duration_ms >= 0), + failure_category varchar(32) NOT NULL, + action varchar(32) NOT NULL, + will_retry numeric NOT NULL DEFAULT false, + error_code varchar(64) NOT NULL DEFAULT '', + error_summary text NOT NULL DEFAULT '', + pricing_receipt json, + PRIMARY KEY (request_id, sequence), + CONSTRAINT chk_request_log_attempt_failure_category CHECK ( + failure_category IN ( + 'ok','rate_limited','model_unavailable','invalid_key', + 'upstream_host_error','client_error','downstream_cancel','ambiguous' + ) + ), + CONSTRAINT chk_request_log_attempt_action CHECK ( + action IN ('terminate','retry','cooldown_key','fail_key','skip_group') + ), + FOREIGN KEY (request_id) REFERENCES request_logs(id) + ON UPDATE CASCADE ON DELETE CASCADE + )`, `CREATE TABLE usage_stats ( id integer PRIMARY KEY AUTOINCREMENT, bucket_start_ms integer NOT NULL CHECK (bucket_start_ms >= 0), @@ -229,16 +261,16 @@ func schemaV4TableStatements() []string { } } -func createSchemaV4Indexes(db *gorm.DB) error { - for _, statement := range schemaV4IndexStatements() { +func createSchemaV5Indexes(db *gorm.DB) error { + for _, statement := range schemaV5IndexStatements() { if err := db.Exec(statement).Error; err != nil { - return fmt.Errorf("create schema v4 index: %w", err) + return fmt.Errorf("create schema v5 index: %w", err) } } return nil } -func schemaV4IndexStatements() []string { +func schemaV5IndexStatements() []string { return []string{ `CREATE UNIQUE INDEX idx_groups_name ON groups(name)`, `CREATE UNIQUE INDEX idx_upstream_keys_group_hash @@ -254,6 +286,18 @@ func schemaV4IndexStatements() []string { ON request_logs(client_model, completed_at_ms DESC, id DESC)`, `CREATE INDEX idx_request_logs_upstream_model_completed_id ON request_logs(upstream_model, completed_at_ms DESC, id DESC)`, + `CREATE INDEX idx_request_log_attempts_group_completed_request + ON request_log_attempts(group_id, completed_at_ms DESC, request_id)`, + `CREATE INDEX idx_request_log_attempts_key_completed_request + ON request_log_attempts(key_id, completed_at_ms DESC, request_id)`, + `CREATE INDEX idx_request_log_attempts_model_completed_request + ON request_log_attempts(upstream_model, completed_at_ms DESC, request_id)`, + `CREATE INDEX idx_request_log_attempts_status_completed_request + ON request_log_attempts(status_code, completed_at_ms DESC, request_id)`, + `CREATE INDEX idx_request_log_attempts_failure_completed_request + ON request_log_attempts(failure_category, completed_at_ms DESC, request_id)`, + `CREATE INDEX idx_request_log_attempts_error_completed_request + ON request_log_attempts(error_code, completed_at_ms DESC, request_id)`, `CREATE UNIQUE INDEX idx_usage_stats_bucket_access_group_model ON usage_stats(bucket_start_ms, access_key_id, group_id, model)`, `CREATE UNIQUE INDEX idx_model_prices_scope_model @@ -270,16 +314,16 @@ func schemaV4IndexStatements() []string { } } -func validateSchemaV4ForeignKeys(db *gorm.DB) error { +func validateSchemaV5ForeignKeys(db *gorm.DB) error { var violations []struct { Table string RowID int64 `gorm:"column:rowid"` } if err := db.Raw("PRAGMA foreign_key_check").Scan(&violations).Error; err != nil { - return fmt.Errorf("validate schema v4 foreign keys: %w", err) + return fmt.Errorf("validate schema v5 foreign keys: %w", err) } if len(violations) != 0 { - return fmt.Errorf("validate schema v4 foreign keys: %d violation(s)", len(violations)) + return fmt.Errorf("validate schema v5 foreign keys: %d violation(s)", len(violations)) } return nil } diff --git a/internal/storage/schema_v4_test.go b/internal/storage/schema_v5_test.go similarity index 86% rename from internal/storage/schema_v4_test.go rename to internal/storage/schema_v5_test.go index 707b591a..e5c6ca34 100644 --- a/internal/storage/schema_v4_test.go +++ b/internal/storage/schema_v5_test.go @@ -13,7 +13,7 @@ import ( "gpt-load/internal/storage/models" ) -type schemaV4Column struct { +type schemaV5Column struct { Name string Type string NotNull int `gorm:"column:notnull"` @@ -21,12 +21,12 @@ type schemaV4Column struct { } func TestAutoMigrateCreatesFinalPricingSchema(t *testing.T) { - db := openSchemaV4TestDatabase(t) + db := openSchemaV5TestDatabase(t) if err := storage.AutoMigrate(db); err != nil { t.Fatal(err) } - if storage.CurrentSchemaVersion != 4 { - t.Fatalf("CurrentSchemaVersion = %d, want 4", storage.CurrentSchemaVersion) + if storage.CurrentSchemaVersion != 5 { + t.Fatalf("CurrentSchemaVersion = %d, want 5", storage.CurrentSchemaVersion) } assertColumns(t, db, "model_prices", []string{ "price_scope_key", "model_id", @@ -39,7 +39,7 @@ func TestAutoMigrateCreatesFinalPricingSchema(t *testing.T) { assertUniqueIndex(t, db, "model_prices", "idx_model_prices_scope_model", []string{"price_scope_key", "model_id"}) - columns := schemaV4Columns(t, db, "model_prices") + columns := schemaV5Columns(t, db, "model_prices") for _, name := range []string{ "input_price_nano_usd_per_million_tokens", "output_price_nano_usd_per_million_tokens", @@ -62,10 +62,50 @@ func TestAutoMigrateCreatesFinalPricingSchema(t *testing.T) { } } +func TestAutoMigrateCreatesNormalizedRequestLogSchemaV5(t *testing.T) { + db := openSchemaV5TestDatabase(t) + if err := storage.AutoMigrate(db); err != nil { + t.Fatal(err) + } + if storage.CurrentSchemaVersion != 5 { + t.Fatalf("CurrentSchemaVersion = %d, want 5", storage.CurrentSchemaVersion) + } + requestColumns := schemaV5Columns(t, db, "request_logs") + for _, name := range []string{"stream", "first_response_ms", "attempt_count"} { + if _, ok := requestColumns[name]; !ok { + t.Errorf("request_logs.%s is missing", name) + } + } + if _, ok := requestColumns["attempts"]; ok { + t.Error("request_logs.attempts JSON column still exists") + } + assertColumns(t, db, "request_log_attempts", []string{ + "request_id", "sequence", "completed_at_ms", "group_id", "group_name", + "key_id", "upstream_model", "status_code", "duration_ms", + "failure_category", "action", "will_retry", "error_code", "error_summary", + "pricing_receipt", + }) + + var foreignKeys []struct { + Table string + From string + To string + OnDelete string `gorm:"column:on_delete"` + } + if err := db.Raw("PRAGMA foreign_key_list('request_log_attempts')").Scan(&foreignKeys).Error; err != nil { + t.Fatalf("inspect request_log_attempts foreign keys: %v", err) + } + if len(foreignKeys) != 1 || foreignKeys[0].Table != "request_logs" || + foreignKeys[0].From != "request_id" || foreignKeys[0].To != "id" || + foreignKeys[0].OnDelete != "CASCADE" { + t.Fatalf("request_log_attempts foreign keys = %#v", foreignKeys) + } +} + func TestAutoMigrateRejectsUnreleasedLegacySchema(t *testing.T) { - for _, version := range []uint{1, 2, 3} { + for _, version := range []uint{1, 2, 3, 4} { t.Run(fmt.Sprintf("version_%d", version), func(t *testing.T) { - db := openSchemaV4TestDatabase(t) + db := openSchemaV5TestDatabase(t) if err := db.Exec("CREATE TABLE schema_info (version integer PRIMARY KEY)").Error; err != nil { t.Fatal(err) } @@ -81,12 +121,12 @@ func TestAutoMigrateRejectsUnreleasedLegacySchema(t *testing.T) { } func TestAutoMigrateCreatesFinalCatalogAndUsageColumns(t *testing.T) { - db := openSchemaV4TestDatabase(t) + db := openSchemaV5TestDatabase(t) if err := storage.AutoMigrate(db); err != nil { t.Fatal(err) } - groups := schemaV4Columns(t, db, "groups") + groups := schemaV5Columns(t, db, "groups") providerID, ok := groups["provider_id"] if !ok { t.Fatal("groups.provider_id is missing") @@ -100,7 +140,7 @@ func TestAutoMigrateCreatesFinalCatalogAndUsageColumns(t *testing.T) { "request_logs": {"cache_write_unknown_tokens", "pricing_completeness"}, "usage_stats": {"cache_write_unknown_tokens", "pricing_partial_count"}, } { - got := schemaV4Columns(t, db, table) + got := schemaV5Columns(t, db, table) for _, name := range columns { column, found := got[name] if !found { @@ -113,7 +153,7 @@ func TestAutoMigrateCreatesFinalCatalogAndUsageColumns(t *testing.T) { } } } - pricingCompleteness := schemaV4Columns(t, db, "request_logs")["pricing_completeness"] + pricingCompleteness := schemaV5Columns(t, db, "request_logs")["pricing_completeness"] if pricingCompleteness.DefaultValue == nil || strings.Trim(*pricingCompleteness.DefaultValue, "'\"") != "not_applicable" { t.Errorf("request_logs.pricing_completeness default = %v, want not_applicable", @@ -122,7 +162,7 @@ func TestAutoMigrateCreatesFinalCatalogAndUsageColumns(t *testing.T) { } func TestFinalModelPriceRejectsNegativeScalarPrices(t *testing.T) { - db := openMigratedSchemaV4TestDatabase(t) + db := openMigratedSchemaV5TestDatabase(t) priceColumns := []string{ "input_price_nano_usd_per_million_tokens", "output_price_nano_usd_per_million_tokens", @@ -142,7 +182,7 @@ func TestFinalModelPriceRejectsNegativeScalarPrices(t *testing.T) { } func TestModelPriceValidatesAndNormalizesContextTiersBeforePersistence(t *testing.T) { - db := openMigratedSchemaV4TestDatabase(t) + db := openMigratedSchemaV5TestDatabase(t) empty := models.ModelPrice{ PriceScopeKey: "provider:openai", @@ -270,7 +310,7 @@ func TestModelPriceValidatesContextTiersAcrossGORMWritePaths(t *testing.T) { } func TestFinalRequestLogEnforcesStateContract(t *testing.T) { - db := openMigratedSchemaV4TestDatabase(t) + db := openMigratedSchemaV5TestDatabase(t) valid := []requestStateFixture{ {id: "valid-priced-complete", status: "success", usage: "complete", cost: "priced", pricing: "complete", estimatedCost: 1}, {id: "valid-priced-partial", status: "incomplete", usage: "partial", cost: "priced", pricing: "partial", estimatedCost: 0}, @@ -302,7 +342,7 @@ func TestFinalRequestLogEnforcesStateContract(t *testing.T) { } func TestFinalSchemaUsesMillisecondIntegersAndEnforcesCounters(t *testing.T) { - db := openMigratedSchemaV4TestDatabase(t) + db := openMigratedSchemaV5TestDatabase(t) for table, names := range map[string][]string{ "groups": {"created_at_ms", "updated_at_ms"}, @@ -315,7 +355,7 @@ func TestFinalSchemaUsesMillisecondIntegersAndEnforcesCounters(t *testing.T) { "jobs": {"created_at_ms", "started_at_ms", "finished_at_ms"}, "control_operations": {"completed_at_ms", "compacted_at_ms", "created_at_ms", "updated_at_ms"}, } { - columns := schemaV4Columns(t, db, table) + columns := schemaV5Columns(t, db, table) for _, name := range names { column, ok := columns[name] if !ok { @@ -356,10 +396,10 @@ func TestFinalSchemaUsesMillisecondIntegersAndEnforcesCounters(t *testing.T) { id, completed_at_ms, access_key_id, group_id, protocol, client_model, upstream_model, status, status_code, duration_ms, error_code, error_summary, affinity_hit, estimated_cost_nano_usd, usage_state, cost_state, - pricing_completeness, attempts + pricing_completeness ) VALUES ('negative-request-duration', 1, 0, 0, 'openai-completions', '', '', 'success', 200, -1, '', '', false, 0, - 'complete', 'priced', 'complete', '[]')`, + 'complete', 'priced', 'complete')`, }, { name: "negative request token", @@ -368,10 +408,10 @@ func TestFinalSchemaUsesMillisecondIntegersAndEnforcesCounters(t *testing.T) { upstream_model, status, status_code, duration_ms, error_code, error_summary, affinity_hit, uncached_input_tokens, output_tokens, cache_read_tokens, cache_write_5m_tokens, cache_write_1h_tokens, cache_write_unknown_tokens, - estimated_cost_nano_usd, usage_state, cost_state, pricing_completeness, attempts + estimated_cost_nano_usd, usage_state, cost_state, pricing_completeness ) VALUES ('negative-request-token', 1, 0, 0, 'openai-completions', '', '', 'success', 200, 0, '', '', false, 0, 0, 0, 0, 0, -1, 0, - 'complete', 'priced', 'complete', '[]')`, + 'complete', 'priced', 'complete')`, }, { name: "negative request cost", @@ -379,10 +419,10 @@ func TestFinalSchemaUsesMillisecondIntegersAndEnforcesCounters(t *testing.T) { id, completed_at_ms, access_key_id, group_id, protocol, client_model, upstream_model, status, status_code, duration_ms, error_code, error_summary, affinity_hit, estimated_cost_nano_usd, usage_state, cost_state, - pricing_completeness, attempts + pricing_completeness ) VALUES ('negative-request-cost', 1, 0, 0, 'openai-completions', '', '', 'success', 200, 0, '', '', false, -1, - 'complete', 'priced', 'complete', '[]')`, + 'complete', 'priced', 'complete')`, }, { name: "negative usage unknown cache write", @@ -423,7 +463,7 @@ func TestFinalSchemaUsesMillisecondIntegersAndEnforcesCounters(t *testing.T) { } func TestAutoMigrateRejectsCorruptCanonicalTable(t *testing.T) { - db := openMigratedSchemaV4TestDatabase(t) + db := openMigratedSchemaV5TestDatabase(t) if err := db.Exec(`ALTER TABLE usage_stats RENAME TO usage_stats_checked`).Error; err != nil { t.Fatal(err) } @@ -435,17 +475,17 @@ func TestAutoMigrateRejectsCorruptCanonicalTable(t *testing.T) { t.Fatal(err) } if err := storage.AutoMigrate(db); err == nil || !strings.Contains(err.Error(), "table usage_stats differs") { - t.Fatalf("AutoMigrate(corrupt v4 table) error = %v", err) + t.Fatalf("AutoMigrate(corrupt v5 table) error = %v", err) } } -func TestAutoMigrateValidatesExistingVersionFourSchema(t *testing.T) { - db := openMigratedSchemaV4TestDatabase(t) +func TestAutoMigrateValidatesExistingVersionFiveSchema(t *testing.T) { + db := openMigratedSchemaV5TestDatabase(t) if err := db.Exec("DROP INDEX idx_model_prices_scope_model").Error; err != nil { t.Fatal(err) } if err := storage.AutoMigrate(db); err == nil || !strings.Contains(err.Error(), "idx_model_prices_scope_model") { - t.Fatalf("AutoMigrate(corrupt v4) error = %v, want missing-index validation", err) + t.Fatalf("AutoMigrate(corrupt v5) error = %v, want missing-index validation", err) } } @@ -464,9 +504,9 @@ func insertRequestStateFixture(db *gorm.DB, fixture requestStateFixture) error { upstream_model, status, status_code, duration_ms, error_code, error_summary, affinity_hit, uncached_input_tokens, output_tokens, cache_read_tokens, cache_write_5m_tokens, cache_write_1h_tokens, cache_write_unknown_tokens, - estimated_cost_nano_usd, usage_state, cost_state, pricing_completeness, attempts + estimated_cost_nano_usd, usage_state, cost_state, pricing_completeness ) VALUES (?, 1, 0, 0, 'openai-completions', '', '', ?, 200, 0, '', '', - false, 0, 0, 0, 0, 0, 0, ?, ?, ?, ?, '[]')`, + false, 0, 0, 0, 0, 0, 0, ?, ?, ?, ?)`, fixture.id, fixture.status, fixture.estimatedCost, fixture.usage, fixture.cost, fixture.pricing, ).Error @@ -474,7 +514,7 @@ func insertRequestStateFixture(db *gorm.DB, fixture requestStateFixture) error { func createModelPriceForWritePath(t *testing.T, modelID string) (*gorm.DB, models.ModelPrice) { t.Helper() - db := openMigratedSchemaV4TestDatabase(t) + db := openMigratedSchemaV5TestDatabase(t) row := models.ModelPrice{ PriceScopeKey: "provider:openai", ModelID: modelID, @@ -506,7 +546,7 @@ func assertModelPriceTiersNull( } } -func openSchemaV4TestDatabase(t *testing.T) *gorm.DB { +func openSchemaV5TestDatabase(t *testing.T) *gorm.DB { t.Helper() db, err := storage.Open(":memory:") if err != nil { @@ -524,22 +564,22 @@ func openSchemaV4TestDatabase(t *testing.T) *gorm.DB { return db } -func openMigratedSchemaV4TestDatabase(t *testing.T) *gorm.DB { +func openMigratedSchemaV5TestDatabase(t *testing.T) *gorm.DB { t.Helper() - db := openSchemaV4TestDatabase(t) + db := openSchemaV5TestDatabase(t) if err := storage.AutoMigrate(db); err != nil { t.Fatalf("AutoMigrate() error = %v", err) } return db } -func schemaV4Columns(t *testing.T, db *gorm.DB, table string) map[string]schemaV4Column { +func schemaV5Columns(t *testing.T, db *gorm.DB, table string) map[string]schemaV5Column { t.Helper() - var columns []schemaV4Column + var columns []schemaV5Column if err := db.Raw("PRAGMA table_info('" + table + "')").Scan(&columns).Error; err != nil { t.Fatalf("inspect %s columns: %v", table, err) } - result := make(map[string]schemaV4Column, len(columns)) + result := make(map[string]schemaV5Column, len(columns)) for _, column := range columns { result[column.Name] = column } @@ -548,7 +588,7 @@ func schemaV4Columns(t *testing.T, db *gorm.DB, table string) map[string]schemaV func assertColumns(t *testing.T, db *gorm.DB, table string, want []string) { t.Helper() - got := schemaV4Columns(t, db, table) + got := schemaV5Columns(t, db, table) for _, name := range want { if _, ok := got[name]; !ok { t.Errorf("%s.%s is missing", table, name) diff --git a/internal/storage/schema_v4_validation.go b/internal/storage/schema_v5_validation.go similarity index 61% rename from internal/storage/schema_v4_validation.go rename to internal/storage/schema_v5_validation.go index af0c235c..14ee5e1c 100644 --- a/internal/storage/schema_v4_validation.go +++ b/internal/storage/schema_v5_validation.go @@ -7,23 +7,23 @@ import ( "gorm.io/gorm" ) -const schemaV4InfoTableSQL = `CREATE TABLE schema_info ( +const schemaV5InfoTableSQL = `CREATE TABLE schema_info ( version integer PRIMARY KEY NOT NULL, - CONSTRAINT chk_schema_info_version CHECK (version = 4) + CONSTRAINT chk_schema_info_version CHECK (version = 5) )` -func createSchemaV4InfoTable(db *gorm.DB) error { - if err := db.Exec(schemaV4InfoTableSQL).Error; err != nil { - return fmt.Errorf("create schema v4 info table: %w", err) +func createSchemaV5InfoTable(db *gorm.DB) error { + if err := db.Exec(schemaV5InfoTableSQL).Error; err != nil { + return fmt.Errorf("create schema v5 info table: %w", err) } return nil } -func validateSchemaV4(db *gorm.DB) error { - for _, expected := range append(schemaV4TableStatements(), schemaV4InfoTableSQL) { +func validateSchemaV5(db *gorm.DB) error { + for _, expected := range append(schemaV5TableStatements(), schemaV5InfoTableSQL) { fields := strings.Fields(expected) if len(fields) < 3 { - return fmt.Errorf("validate SQLite schema version 4: invalid canonical table DDL") + return fmt.Errorf("validate SQLite schema version 5: invalid canonical table DDL") } name := fields[2] actual, err := sqliteSchemaSQL(db, "table", name) @@ -31,14 +31,14 @@ func validateSchemaV4(db *gorm.DB) error { return err } if normalizeSQLiteDDL(actual) != normalizeSQLiteDDL(expected) { - return fmt.Errorf("validate SQLite schema version 4: table %s differs", name) + return fmt.Errorf("validate SQLite schema version 5: table %s differs", name) } } - for _, expected := range schemaV4IndexStatements() { + for _, expected := range schemaV5IndexStatements() { fields := strings.Fields(expected) if len(fields) < 4 { - return fmt.Errorf("validate SQLite schema version 4: invalid canonical index DDL") + return fmt.Errorf("validate SQLite schema version 5: invalid canonical index DDL") } nameIndex := 2 if strings.EqualFold(fields[1], "unique") { @@ -50,10 +50,10 @@ func validateSchemaV4(db *gorm.DB) error { return err } if normalizeSQLiteDDL(actual) != normalizeSQLiteDDL(expected) { - return fmt.Errorf("validate SQLite schema version 4: critical index %s differs", name) + return fmt.Errorf("validate SQLite schema version 5: critical index %s differs", name) } } - return validateSchemaV4ForeignKeys(db) + return validateSchemaV5ForeignKeys(db) } func sqliteSchemaSQL(db *gorm.DB, objectType, name string) (string, error) { @@ -65,7 +65,7 @@ func sqliteSchemaSQL(db *gorm.DB, objectType, name string) (string, error) { ).Scan(&statement) if result.Error != nil { return "", fmt.Errorf( - "validate SQLite schema version 4: read %s %s: %w", + "validate SQLite schema version 5: read %s %s: %w", objectType, name, result.Error, @@ -73,7 +73,7 @@ func sqliteSchemaSQL(db *gorm.DB, objectType, name string) (string, error) { } if result.RowsAffected != 1 || strings.TrimSpace(statement) == "" { return "", fmt.Errorf( - "validate SQLite schema version 4: %s %s is missing", + "validate SQLite schema version 5: %s %s is missing", objectType, name, ) diff --git a/internal/telemetry/requestlog.go b/internal/telemetry/requestlog.go index 75fcb085..cbceb76f 100644 --- a/internal/telemetry/requestlog.go +++ b/internal/telemetry/requestlog.go @@ -63,6 +63,7 @@ type PricingObservation struct { CostState string PricingCompleteness string EstimatedCostNanoUSD int64 + ReceiptJSON string } type UsageObservation struct { @@ -74,20 +75,22 @@ type UsageObservation struct { } type RequestEvent struct { - RequestID string - CompletedAt time.Time - AccessKeyID uint - Protocol protocol.Protocol - ClientModel string - UpstreamModel string - Status RequestStatus - StatusCode int - ErrorCode string - ErrorSummary string - DurationMs int64 - AffinityHit bool - Attempts []Attempt - Usage UsageObservation + RequestID string + CompletedAt time.Time + AccessKeyID uint + Protocol protocol.Protocol + ClientModel string + UpstreamModel string + Status RequestStatus + StatusCode int + ErrorCode string + ErrorSummary string + Stream bool + FirstResponseMs *int64 + DurationMs int64 + AffinityHit bool + Attempts []Attempt + Usage UsageObservation } type RequestLogSink interface { diff --git a/internal/telemetry/requestlog_test.go b/internal/telemetry/requestlog_test.go index a398fc3e..4d0eaa30 100644 --- a/internal/telemetry/requestlog_test.go +++ b/internal/telemetry/requestlog_test.go @@ -27,6 +27,8 @@ func TestRequestTelemetryContractUsesExactFieldAllowlist(t *testing.T) { "StatusCode", "ErrorCode", "ErrorSummary", + "Stream", + "FirstResponseMs", "DurationMs", "AffinityHit", "Attempts", @@ -53,6 +55,7 @@ func TestRequestTelemetryContractUsesExactFieldAllowlist(t *testing.T) { "CostState", "PricingCompleteness", "EstimatedCostNanoUSD", + "ReceiptJSON", }, reflect.TypeOf(UsageObservation{}): { "Result", diff --git a/web/src/app/query-keys.ts b/web/src/app/query-keys.ts index 7cc8b7e5..bc2ca2ff 100644 --- a/web/src/app/query-keys.ts +++ b/web/src/app/query-keys.ts @@ -56,10 +56,35 @@ function normalizeLogFilters(filters: RequestLogFilters): RequestLogFilters { 'from_ms', 'to_ms', 'group_id', - 'model', + 'client_model', + 'upstream_model', 'access_key_id', 'status', 'request_id', + 'protocol', + 'stream', + 'final_status_code', + 'usage_state', + 'cost_state', + 'pricing_completeness', + 'cache_present', + 'upstream_key_id', + 'attempt_status_code', + 'failure_category', + 'error_code', + 'retry_state', + 'retry_count_min', + 'retry_count_max', + 'first_response_min_ms', + 'first_response_max_ms', + 'duration_min_ms', + 'duration_max_ms', + 'input_tokens_min', + 'input_tokens_max', + 'output_tokens_min', + 'output_tokens_max', + 'cost_min_nano_usd', + 'cost_max_nano_usd', ] as const) { const value = filters[field] if (value !== undefined) Object.assign(result, { [field]: value }) @@ -107,6 +132,8 @@ export const controlQueryKeys = { all: ['control', 'logs'] as const, list: (filters: RequestLogFilters) => ['control', 'logs', 'list', normalizeLogFilters(filters)] as const, + details: () => ['control', 'logs', 'detail'] as const, + detail: (requestID: string) => ['control', 'logs', 'detail', requestID] as const, }, usage: { all: ['control', 'usage'] as const, diff --git a/web/src/app/resources/request-logs.ts b/web/src/app/resources/request-logs.ts index 6326594c..3e0f63bf 100644 --- a/web/src/app/resources/request-logs.ts +++ b/web/src/app/resources/request-logs.ts @@ -1,3 +1,4 @@ +import { keepPreviousData, queryOptions } from '@tanstack/vue-query' import { computed, toValue, type MaybeRefOrGetter } from 'vue' import type { ApiClient } from '@/api/client' @@ -19,23 +20,71 @@ import { } from './projector' export type RequestLogStatus = 'success' | 'error' | 'incomplete' | 'canceled' - -export type { FailureCategory } from '@/api/control/types' - export type RequestLogAction = 'terminate' | 'retry' | 'cooldown_key' | 'fail_key' | 'skip_group' export type RequestLogUsageState = 'complete' | 'partial' | 'missing' | 'not_applicable' export type RequestLogCostState = 'priced' | 'unpriced' | 'not_applicable' export type RequestLogPricingCompleteness = 'complete' | 'partial' | 'unavailable' | 'not_applicable' +export type RequestLogRetryState = 'retried' | 'not_retried' +export type RequestLogReceiptLineState = 'priced' | 'unpriced' +export type RequestLogPageSize = 20 | 50 | 100 + +export type { FailureCategory } from '@/api/control/types' export interface RequestLogFilters { from_ms?: number to_ms?: number + limit?: RequestLogPageSize group_id?: number - model?: string + client_model?: string + upstream_model?: string access_key_id?: number status?: RequestLogStatus request_id?: string + protocol?: AccessProtocol + stream?: boolean + final_status_code?: number + usage_state?: RequestLogUsageState + cost_state?: RequestLogCostState + pricing_completeness?: RequestLogPricingCompleteness + cache_present?: boolean + upstream_key_id?: number + attempt_status_code?: number + failure_category?: FailureCategory + error_code?: string + retry_state?: RequestLogRetryState + retry_count_min?: number + retry_count_max?: number + first_response_min_ms?: number + first_response_max_ms?: number + duration_min_ms?: number + duration_max_ms?: number + input_tokens_min?: number + input_tokens_max?: number + output_tokens_min?: number + output_tokens_max?: number + cost_min_nano_usd?: string + cost_max_nano_usd?: string +} + +export interface RequestLogPricingLineDto { + code: 'input' | 'cache_read' | 'cache_write_5m' | 'cache_write_1h' | 'cache_write' | 'output' + quantity: string + rate_nano_usd_per_million: string | null + multiplier: { numerator: string; denominator: string } + state: RequestLogReceiptLineState + amount_nano_usd: string | null +} + +export interface RequestLogPricingReceiptDto { + schema_version: 1 + method: 'unit_rate_sum' + method_version: 1 + currency: 'USD' + rule: { scope_key: string; model_id: string } + context_threshold_tokens: string | null + line_items: RequestLogPricingLineDto[] + total_nano_usd: string } export interface RequestLogAttemptDto { @@ -51,40 +100,42 @@ export interface RequestLogAttemptDto { will_retry: boolean error_code: string error_summary: string - committed: boolean + pricing_receipt: RequestLogPricingReceiptDto | null } export interface RequestLogItemDto { request_id: string completed_at_ms: number - access_key: { - id: number - name: string | null - deleted: boolean - } + access_key: { id: number; name: string | null; deleted: boolean } protocol: AccessProtocol client_model: string | null upstream_model: string | null status: RequestLogStatus status_code: number + stream: boolean + first_response_ms: number | null duration_ms: number + attempt_count: number error_code: string error_summary: string affinity_hit: boolean - attempts: RequestLogAttemptDto[] group_id: number | null usage_state: RequestLogUsageState cost_state: RequestLogCostState pricing_completeness: RequestLogPricingCompleteness - uncached_input_tokens: number - cache_read_tokens: number - cache_write_5m_tokens: number - cache_write_1h_tokens: number - cache_write_unknown_tokens: number - output_tokens: number + input_tokens: string + cache_read_tokens: string + cache_write_5m_tokens: string + cache_write_1h_tokens: string + cache_write_unknown_tokens: string + output_tokens: string estimated_cost_nano_usd: string } +export interface RequestLogDetailDto extends RequestLogItemDto { + attempts: RequestLogAttemptDto[] +} + export interface RequestLogPageDto { items: RequestLogItemDto[] next_cursor: string | null @@ -106,21 +157,15 @@ const actions = ['terminate', 'retry', 'cooldown_key', 'fail_key', 'skip_group'] const usageStates = ['complete', 'partial', 'missing', 'not_applicable'] as const const costStates = ['priced', 'unpriced', 'not_applicable'] as const const pricingCompletenessValues = ['complete', 'partial', 'unavailable', 'not_applicable'] as const -const attemptFields = [ - 'sequence', - 'group_id', - 'group_name', - 'key_id', - 'upstream_model', - 'status_code', - 'duration_ms', - 'failure_category', - 'action', - 'will_retry', - 'error_code', - 'error_summary', - 'committed', +const receiptCodes = [ + 'input', + 'cache_read', + 'cache_write_5m', + 'cache_write_1h', + 'cache_write', + 'output', ] as const +const receiptLineStates = ['priced', 'unpriced'] as const const itemFields = [ 'request_id', 'completed_at_ms', @@ -130,16 +175,18 @@ const itemFields = [ 'upstream_model', 'status', 'status_code', + 'stream', + 'first_response_ms', 'duration_ms', + 'attempt_count', 'error_code', 'error_summary', 'affinity_hit', - 'attempts', 'group_id', 'usage_state', 'cost_state', 'pricing_completeness', - 'uncached_input_tokens', + 'input_tokens', 'cache_read_tokens', 'cache_write_5m_tokens', 'cache_write_1h_tokens', @@ -182,9 +229,87 @@ function projectAccessKey(value: unknown): RequestLogItemDto['access_key'] { } } +function projectPricingReceipt(value: unknown): RequestLogPricingReceiptDto | null { + if (value === null) return null + const record = projectRecord(value) + assertNoSecretLikeFields(record, [ + 'schema_version', + 'method', + 'method_version', + 'currency', + 'rule', + 'context_threshold_tokens', + 'line_items', + 'total_nano_usd', + ]) + const rule = projectRecord(record.rule) + assertNoSecretLikeFields(rule, ['scope_key', 'model_id']) + const lines = projectArray(record.line_items, (lineValue): RequestLogPricingLineDto => { + const line = projectRecord(lineValue) + assertNoSecretLikeFields(line, [ + 'code', + 'quantity', + 'rate_nano_usd_per_million', + 'multiplier', + 'state', + 'amount_nano_usd', + ]) + const multiplier = projectRecord(line.multiplier) + assertNoSecretLikeFields(multiplier, ['numerator', 'denominator']) + const numerator = projectNonNegativeInt64String(multiplier.numerator) + const denominator = projectNonNegativeInt64String(multiplier.denominator) + if (numerator === '0' || denominator === '0') invalidResponse() + return { + code: projectEnum(line.code, receiptCodes), + quantity: projectNonNegativeInt64String(line.quantity), + rate_nano_usd_per_million: + line.rate_nano_usd_per_million === null + ? null + : projectNonNegativeInt64String(line.rate_nano_usd_per_million), + multiplier: { + numerator, + denominator, + }, + state: projectEnum(line.state, receiptLineStates), + amount_nano_usd: + line.amount_nano_usd === null ? null : projectNonNegativeInt64String(line.amount_nano_usd), + } + }) + return { + schema_version: projectSafeInteger(record.schema_version, { minimum: 1, maximum: 1 }) as 1, + method: projectEnum(record.method, ['unit_rate_sum'] as const), + method_version: projectSafeInteger(record.method_version, { minimum: 1, maximum: 1 }) as 1, + currency: projectEnum(record.currency, ['USD'] as const), + rule: { + scope_key: projectNonBlankString(rule.scope_key), + model_id: projectNonBlankString(rule.model_id), + }, + context_threshold_tokens: + record.context_threshold_tokens === null + ? null + : projectNonNegativeInt64String(record.context_threshold_tokens), + line_items: lines, + total_nano_usd: projectNonNegativeInt64String(record.total_nano_usd), + } +} + function projectAttempt(value: unknown): RequestLogAttemptDto { const record = projectRecord(value) - assertNoSecretLikeFields(record, attemptFields) + assertNoSecretLikeFields(record, [ + 'sequence', + 'group_id', + 'group_name', + 'key_id', + 'upstream_model', + 'status_code', + 'duration_ms', + 'failure_category', + 'action', + 'will_retry', + 'error_code', + 'error_summary', + 'pricing_receipt', + ]) return { sequence: projectSafeInteger(record.sequence, { minimum: 1 }), group_id: projectSafeInteger(record.group_id, { minimum: 1 }), @@ -198,7 +323,7 @@ function projectAttempt(value: unknown): RequestLogAttemptDto { will_retry: projectBoolean(record.will_retry), error_code: projectString(record.error_code, { allowEmpty: true }), error_summary: projectString(record.error_summary, { allowEmpty: true }), - committed: projectBoolean(record.committed), + pricing_receipt: projectPricingReceipt(record.pricing_receipt), } } @@ -219,30 +344,23 @@ function projectUsageCost(record: Record) { pricingCompleteness === 'not_applicable') if (!validCombination) invalidResponse() - const tokens = { - uncached_input_tokens: projectSafeInteger(record.uncached_input_tokens, { minimum: 0 }), - cache_read_tokens: projectSafeInteger(record.cache_read_tokens, { minimum: 0 }), - cache_write_5m_tokens: projectSafeInteger(record.cache_write_5m_tokens, { minimum: 0 }), - cache_write_1h_tokens: projectSafeInteger(record.cache_write_1h_tokens, { minimum: 0 }), - cache_write_unknown_tokens: projectSafeInteger(record.cache_write_unknown_tokens, { - minimum: 0, - }), - output_tokens: projectSafeInteger(record.output_tokens, { minimum: 0 }), - } const estimatedCostNanoUSD = projectNonNegativeInt64String(record.estimated_cost_nano_usd) if (costState !== 'priced' && estimatedCostNanoUSD !== '0') invalidResponse() return { usage_state: usageState, cost_state: costState, pricing_completeness: pricingCompleteness, - ...tokens, + input_tokens: projectNonNegativeInt64String(record.input_tokens), + cache_read_tokens: projectNonNegativeInt64String(record.cache_read_tokens), + cache_write_5m_tokens: projectNonNegativeInt64String(record.cache_write_5m_tokens), + cache_write_1h_tokens: projectNonNegativeInt64String(record.cache_write_1h_tokens), + cache_write_unknown_tokens: projectNonNegativeInt64String(record.cache_write_unknown_tokens), + output_tokens: projectNonNegativeInt64String(record.output_tokens), estimated_cost_nano_usd: estimatedCostNanoUSD, } } -export function projectRequestLogItem(value: unknown): RequestLogItemDto { - const record = projectRecord(value) - assertNoSecretLikeFields(record, itemFields) +function projectItemRecord(record: Record): RequestLogItemDto { return { request_id: projectRequestID(record.request_id), completed_at_ms: projectEpochMilliseconds(record.completed_at_ms), @@ -252,41 +370,83 @@ export function projectRequestLogItem(value: unknown): RequestLogItemDto { upstream_model: projectNullableModel(record.upstream_model), status: projectEnum(record.status, statuses), status_code: projectStatusCode(record.status_code), + stream: projectBoolean(record.stream), + first_response_ms: + record.first_response_ms === null + ? null + : projectSafeInteger(record.first_response_ms, { minimum: 0 }), duration_ms: projectSafeInteger(record.duration_ms, { minimum: 0 }), + attempt_count: projectSafeInteger(record.attempt_count, { minimum: 0 }), error_code: projectString(record.error_code, { allowEmpty: true }), error_summary: projectString(record.error_summary, { allowEmpty: true }), affinity_hit: projectBoolean(record.affinity_hit), - attempts: projectArray(record.attempts, projectAttempt), group_id: record.group_id === null ? null : projectSafeInteger(record.group_id, { minimum: 1 }), ...projectUsageCost(record), } } +export function projectRequestLogItem(value: unknown): RequestLogItemDto { + const record = projectRecord(value) + assertNoSecretLikeFields(record, itemFields) + return projectItemRecord(record) +} + +export function projectRequestLogDetail(value: unknown): RequestLogDetailDto { + const record = projectRecord(value) + assertNoSecretLikeFields(record, [...itemFields, 'attempts']) + return { ...projectItemRecord(record), attempts: projectArray(record.attempts, projectAttempt) } +} + export function projectRequestLogPage(value: unknown): RequestLogPageDto { const record = projectRecord(value) assertNoSecretLikeFields(record, ['items', 'next_cursor']) - const nextCursor = record.next_cursor === null ? null : projectNonBlankString(record.next_cursor) return { items: projectArray(record.items, projectRequestLogItem), - next_cursor: nextCursor, + next_cursor: record.next_cursor === null ? null : projectNonBlankString(record.next_cursor), } } +const filterFields = [ + 'from_ms', + 'to_ms', + 'limit', + 'group_id', + 'client_model', + 'upstream_model', + 'access_key_id', + 'status', + 'request_id', + 'protocol', + 'stream', + 'final_status_code', + 'usage_state', + 'cost_state', + 'pricing_completeness', + 'cache_present', + 'upstream_key_id', + 'attempt_status_code', + 'failure_category', + 'error_code', + 'retry_state', + 'retry_count_min', + 'retry_count_max', + 'first_response_min_ms', + 'first_response_max_ms', + 'duration_min_ms', + 'duration_max_ms', + 'input_tokens_min', + 'input_tokens_max', + 'output_tokens_min', + 'output_tokens_max', + 'cost_min_nano_usd', + 'cost_max_nano_usd', +] as const satisfies readonly (keyof RequestLogFilters)[] + export function normalizeRequestLogFilters(filters: RequestLogFilters): RequestLogFilters { const result: RequestLogFilters = {} - for (const field of [ - 'from_ms', - 'to_ms', - 'group_id', - 'model', - 'access_key_id', - 'status', - 'request_id', - ] as const) { + for (const field of filterFields) { const value = filters[field] - if (value !== undefined) { - Object.assign(result, { [field]: value }) - } + if (value !== undefined) Object.assign(result, { [field]: value }) } return result } @@ -301,36 +461,60 @@ export async function listRequestLogs( cursor?: string, signal?: AbortSignal, ): Promise { - const normalized = normalizeRequestLogFilters(filters) const params = new URLSearchParams() - const values: Array<[string, string | number | undefined]> = [ - ['from_ms', normalized.from_ms], - ['to_ms', normalized.to_ms], - ['group_id', normalized.group_id], - ['client_model', normalized.model], - ['access_key_id', normalized.access_key_id], - ['status', normalized.status], - ['request_id', normalized.request_id], - ['cursor', cursor], - ] - for (const [key, value] of values) { - if (value !== undefined) params.append(key, String(value)) + for (const field of filterFields) { + const value = filters[field] + if (value !== undefined) params.append(field, String(value)) } + if (cursor !== undefined) params.append('cursor', cursor) const query = params.toString() const path: `/api/${string}` = query === '' ? '/api/logs' : `/api/logs?${query}` return projectRequestLogPage(await client.request(path, { method: 'GET', signal })) } -export function requestLogInfiniteQueryOptions( +export async function getRequestLog( + client: ApiClient, + requestID: string, + signal?: AbortSignal, +): Promise { + if (!requestIDPattern.test(requestID)) throw new InvalidResponseError() + return projectRequestLogDetail( + await client.request(`/api/logs/${encodeURIComponent(requestID)}`, { method: 'GET', signal }), + ) +} + +export function requestLogQueryOptions( client: ApiClient, filters: MaybeRefOrGetter, + cursor: MaybeRefOrGetter, ) { - return { - queryKey: computed(() => requestLogQueryIdentity(toValue(filters))), - initialPageParam: null as string | null, - queryFn: ({ pageParam, signal }: { pageParam: string | null; signal: AbortSignal }) => - listRequestLogs(client, toValue(filters), pageParam ?? undefined, signal), - getNextPageParam: (lastPage: RequestLogPageDto) => lastPage.next_cursor ?? undefined, + return queryOptions({ + queryKey: computed(() => [ + ...requestLogQueryIdentity(toValue(filters)), + 'cursor', + toValue(cursor) ?? null, + ]), + queryFn: ({ signal }) => listRequestLogs(client, toValue(filters), toValue(cursor), signal), + placeholderData: keepPreviousData, gcTime: 0, - } + }) +} + +export function requestLogDetailQueryOptions( + client: ApiClient, + requestID: MaybeRefOrGetter, +) { + return queryOptions({ + queryKey: computed(() => { + const id = toValue(requestID) + return id === undefined ? controlQueryKeys.logs.details() : controlQueryKeys.logs.detail(id) + }), + queryFn: ({ signal }) => { + const id = toValue(requestID) + if (id === undefined) throw new InvalidResponseError() + return getRequestLog(client, id, signal) + }, + enabled: computed(() => toValue(requestID) !== undefined), + gcTime: 0, + }) } diff --git a/web/src/components/ui/AppDateTime.vue b/web/src/components/ui/AppDateTime.vue index 0a935f62..9e8f9ab2 100644 --- a/web/src/components/ui/AppDateTime.vue +++ b/web/src/components/ui/AppDateTime.vue @@ -1,7 +1,7 @@ diff --git a/web/src/components/ui/AppDateTimeRangePicker.vue b/web/src/components/ui/AppDateTimeRangePicker.vue new file mode 100644 index 00000000..beb2980d --- /dev/null +++ b/web/src/components/ui/AppDateTimeRangePicker.vue @@ -0,0 +1,232 @@ + + + + + diff --git a/web/src/components/ui/AppSearchInput.vue b/web/src/components/ui/AppSearchInput.vue index 7fae5ff9..abbefcb6 100644 --- a/web/src/components/ui/AppSearchInput.vue +++ b/web/src/components/ui/AppSearchInput.vue @@ -13,11 +13,13 @@ withDefaults( placeholder: string clearLabel: string id?: string + list?: string disabled?: boolean describedBy?: string }>(), { id: undefined, + list: undefined, disabled: false, describedBy: undefined, }, @@ -51,6 +53,7 @@ defineExpose({ focus }) ref="input" class="app-search-input__control" type="search" + :list="list" :value="modelValue" :aria-label="label" :aria-describedby="describedBy" @@ -58,6 +61,8 @@ defineExpose({ focus }) :disabled="disabled" autocomplete="off" :spellcheck="false" + data-1p-ignore="true" + data-lpignore="true" @input="emit('update:modelValue', ($event.target as HTMLInputElement).value)" /> () const attrs = useAttrs() +const normalizedOptions = computed(() => + props.options.map((option) => + option.value === '' ? { ...option, value: emptyOptionValue } : option, + ), +) +const normalizedModelValue = computed(() => + props.modelValue === '' ? emptyOptionValue : props.modelValue, +) const selectedLabel = computed( () => props.options.find((option) => option.value === props.modelValue)?.label ?? '', ) @@ -44,9 +57,13 @@ const selectedLabel = computed(