fix(ops): show first-token latency in TTFT request details

This commit is contained in:
chihao.ou
2026-09-10 21:13:17 +08:00
parent 98d86915be
commit e9f5add97c
7 changed files with 188 additions and 17 deletions
@@ -93,6 +93,7 @@ WITH combined AS (
COALESCE(NULLIF(g.platform, ''), NULLIF(a.platform, ''), '') AS platform,
ul.model AS model,
ul.duration_ms AS duration_ms,
ul.first_token_ms AS first_token_ms,
NULL::INT AS status_code,
NULL::BIGINT AS error_id,
NULL::TEXT AS phase,
@@ -117,6 +118,7 @@ WITH combined AS (
COALESCE(NULLIF(o.platform, ''), NULLIF(g.platform, ''), NULLIF(a.platform, ''), '') AS platform,
o.model AS model,
o.duration_ms AS duration_ms,
o.time_to_first_token_ms AS first_token_ms,
o.status_code AS status_code,
o.id AS error_id,
o.error_phase AS phase,
@@ -152,6 +154,8 @@ WITH combined AS (
// default
case "duration_desc":
sort = "ORDER BY duration_ms DESC NULLS LAST, created_at DESC"
case "ttft_desc":
sort = "ORDER BY first_token_ms DESC NULLS LAST, created_at DESC"
default:
return nil, 0, fmt.Errorf("invalid sort")
}
@@ -166,6 +170,7 @@ SELECT
platform,
model,
duration_ms,
first_token_ms,
status_code,
error_id,
phase,
@@ -213,9 +218,10 @@ LIMIT $%d OFFSET $%d
platform sql.NullString
model sql.NullString
durationMs sql.NullInt64
statusCode sql.NullInt64
errorID sql.NullInt64
durationMs sql.NullInt64
firstTokenMs sql.NullInt64
statusCode sql.NullInt64
errorID sql.NullInt64
phase sql.NullString
severity sql.NullString
@@ -236,6 +242,7 @@ LIMIT $%d OFFSET $%d
&platform,
&model,
&durationMs,
&firstTokenMs,
&statusCode,
&errorID,
&phase,
@@ -257,12 +264,13 @@ LIMIT $%d OFFSET $%d
Platform: strings.TrimSpace(platform.String),
Model: strings.TrimSpace(model.String),
DurationMs: toIntPtr(durationMs),
StatusCode: toIntPtr(statusCode),
ErrorID: toInt64Ptr(errorID),
Phase: phase.String,
Severity: severity.String,
Message: message.String,
DurationMs: toIntPtr(durationMs),
FirstTokenMs: toIntPtr(firstTokenMs),
StatusCode: toIntPtr(statusCode),
ErrorID: toInt64Ptr(errorID),
Phase: phase.String,
Severity: severity.String,
Message: message.String,
UserID: toInt64Ptr(userID),
APIKeyID: toInt64Ptr(apiKeyID),
@@ -0,0 +1,63 @@
package repository
import (
"context"
"testing"
"time"
"github.com/DATA-DOG/go-sqlmock"
"github.com/Wei-Shaw/sub2api/internal/service"
"github.com/stretchr/testify/require"
)
func TestOpsRepositoryListRequestDetails_LatencySort(t *testing.T) {
for _, tc := range []struct {
name string
sort string
order string
}{
{name: "TTFT", sort: "ttft_desc", order: "first_token_ms DESC NULLS LAST, created_at DESC"},
{name: "duration", sort: "duration_desc", order: "duration_ms DESC NULLS LAST, created_at DESC"},
{name: "default", order: "created_at DESC"},
} {
t.Run(tc.name, func(t *testing.T) {
db, mock := newSQLMock(t)
repo := &opsRepository{db: db}
start := time.Date(2026, 9, 10, 0, 0, 0, 0, time.UTC)
end := start.Add(time.Hour)
filter := &service.OpsRequestDetailFilter{
StartTime: &start,
EndTime: &end,
Sort: tc.sort,
Page: 2,
PageSize: 10,
}
mock.ExpectQuery(`SELECT COUNT\(1\) FROM combined`).
WithArgs(start, end).
WillReturnRows(sqlmock.NewRows([]string{"count"}).AddRow(13))
rows := sqlmock.NewRows([]string{
"kind", "created_at", "request_id", "platform", "model", "duration_ms", "first_token_ms",
"status_code", "error_id", "phase", "severity", "message", "user_id", "api_key_id", "account_id", "group_id", "stream",
}).
AddRow("success", start, "req-slow", "openai", "gpt-5.5", 12000, 800, nil, nil, nil, nil, nil, 1, 2, 3, 4, true).
AddRow("error", start, "req-zero", "openai", "gpt-5.5", 9000, 0, 502, 5, "upstream", "error", "failed", 1, 2, 3, 4, true).
AddRow("success", start, "req-missing", "openai", "gpt-5.5", 5000, nil, nil, nil, nil, nil, nil, 1, 2, 3, 4, false)
mock.ExpectQuery(`(?s)ul\.first_token_ms AS first_token_ms.*o\.time_to_first_token_ms AS first_token_ms.*SELECT.*duration_ms,\s+first_token_ms,.*ORDER BY ` + tc.order + `\s+LIMIT \$3 OFFSET \$4`).
WithArgs(start, end, 10, 10).
WillReturnRows(rows)
items, total, err := repo.ListRequestDetails(context.Background(), filter)
require.NoError(t, err)
require.EqualValues(t, 13, total)
require.Len(t, items, 3)
require.NotNil(t, items[0].FirstTokenMs)
require.Equal(t, 800, *items[0].FirstTokenMs)
require.Equal(t, 12000, *items[0].DurationMs)
require.NotNil(t, items[1].FirstTokenMs)
require.Zero(t, *items[1].FirstTokenMs)
require.Nil(t, items[2].FirstTokenMs)
require.NoError(t, mock.ExpectationsWereMet())
})
}
}
@@ -22,8 +22,9 @@ type OpsRequestDetail struct {
Platform string `json:"platform,omitempty"`
Model string `json:"model,omitempty"`
DurationMs *int `json:"duration_ms,omitempty"`
StatusCode *int `json:"status_code,omitempty"`
DurationMs *int `json:"duration_ms,omitempty"`
FirstTokenMs *int `json:"first_token_ms,omitempty"`
StatusCode *int `json:"status_code,omitempty"`
// When Kind == "error", ErrorID links to /admin/ops/errors/:id.
ErrorID *int64 `json:"error_id,omitempty"`
@@ -61,7 +62,7 @@ type OpsRequestDetailFilter struct {
MinDurationMs *int
MaxDurationMs *int
// Sort: created_at_desc (default) or duration_desc.
// Sort: created_at_desc (default), duration_desc or ttft_desc.
Sort string
Page int
+2 -1
View File
@@ -107,7 +107,7 @@ export interface OpsThroughputTrendResponse {
export type OpsRequestKind = 'success' | 'error'
export type OpsRequestDetailsKind = OpsRequestKind | 'all'
export type OpsRequestDetailsSort = 'created_at_desc' | 'duration_desc'
export type OpsRequestDetailsSort = 'created_at_desc' | 'duration_desc' | 'ttft_desc'
export interface OpsRequestDetail {
kind: OpsRequestKind
@@ -117,6 +117,7 @@ export interface OpsRequestDetail {
platform?: string
model?: string
duration_ms?: number | null
first_token_ms?: number | null
status_code?: number | null
error_id?: number | null
@@ -1337,7 +1337,7 @@ function handleToolbarRefresh() {
v-if="!props.fullscreen"
class="text-[10px] font-bold text-blue-500 hover:underline"
type="button"
@click="openDetails({ title: t('admin.ops.ttftLabel'), sort: 'duration_desc' })"
@click="openDetails({ title: t('admin.ops.ttftLabel'), kind: 'success', sort: 'ttft_desc' })"
>
{{ t('admin.ops.requestDetails.details') }}
</button>
@@ -47,6 +47,14 @@ const pageSize = ref(10)
const close = () => emit('update:modelValue', false)
const showTTFT = computed(() => props.preset.sort === 'ttft_desc')
const latencyLabel = computed(() => t(showTTFT.value ? 'admin.ops.ttftLabel' : 'admin.ops.requestDetails.table.duration'))
function formatLatency(row: OpsRequestDetail): string {
const value = showTTFT.value ? row.first_token_ms : row.duration_ms
return typeof value === 'number' ? `${value} ms` : '-'
}
const rangeLabel = computed(() => {
const minutes = parseTimeRangeMinutes(props.timeRange)
if (minutes >= 60) return t('admin.ops.requestDetails.rangeHours', { n: Math.round(minutes / 60) })
@@ -205,7 +213,7 @@ const kindBadgeClass = (kind: string) => {
</div>
<div class="break-all text-xs text-gray-600 dark:text-gray-300">{{ row.model || '-' }}</div>
<div class="flex flex-wrap items-center gap-x-3 gap-y-1 text-xs text-gray-600 dark:text-gray-300">
<span>{{ typeof row.duration_ms === 'number' ? `${row.duration_ms} ms` : '-' }}</span>
<span>{{ latencyLabel }}: {{ formatLatency(row) }}</span>
<span>{{ row.status_code ?? '-' }}</span>
</div>
<div v-if="row.request_id" class="flex items-center gap-2">
@@ -244,7 +252,7 @@ const kindBadgeClass = (kind: string) => {
{{ t('admin.ops.requestDetails.table.model') }}
</th>
<th class="px-4 py-3 text-left text-[11px] font-bold uppercase tracking-wider text-gray-500 dark:text-gray-400">
{{ t('admin.ops.requestDetails.table.duration') }}
{{ latencyLabel }}
</th>
<th class="px-4 py-3 text-left text-[11px] font-bold uppercase tracking-wider text-gray-500 dark:text-gray-400">
{{ t('admin.ops.requestDetails.table.status') }}
@@ -274,7 +282,7 @@ const kindBadgeClass = (kind: string) => {
{{ row.model || '-' }}
</td>
<td class="whitespace-nowrap px-4 py-3 text-xs text-gray-600 dark:text-gray-300">
{{ typeof row.duration_ms === 'number' ? `${row.duration_ms} ms` : '-' }}
{{ formatLatency(row) }}
</td>
<td class="whitespace-nowrap px-4 py-3 text-xs text-gray-600 dark:text-gray-300">
{{ row.status_code ?? '-' }}
@@ -0,0 +1,90 @@
import { beforeEach, describe, expect, it, vi } from 'vitest'
import { ref } from 'vue'
import type { OpsDashboardOverview } from '@/api/admin/ops'
import { flushPromises, mount, shallowMount } from '@vue/test-utils'
import OpsDashboardHeader from '../OpsDashboardHeader.vue'
import OpsRequestDetailsModal from '../OpsRequestDetailsModal.vue'
const { listRequestDetails, viewport } = vi.hoisted(() => ({
listRequestDetails: vi.fn(),
viewport: { desktop: true },
}))
vi.mock('@vueuse/core', () => ({ useMediaQuery: () => ref(viewport.desktop) }))
vi.mock('@/api/admin/ops', () => ({ opsAPI: { listRequestDetails } }))
vi.mock('@/api', () => ({ adminAPI: { groups: { getAll: vi.fn().mockResolvedValue([]) } } }))
vi.mock('@/stores', () => ({
useAppStore: () => ({ showError: vi.fn() }),
useAdminSettingsStore: () => ({ opsRealtimeMonitoringEnabled: false }),
}))
vi.mock('@/composables/useClipboard', () => ({ useClipboard: () => ({ copyToClipboard: vi.fn() }) }))
vi.mock('vue-i18n', async (importOriginal) => ({
...await importOriginal<typeof import('vue-i18n')>(),
useI18n: () => ({ t: (key: string) => key }),
}))
async function openDetails(sort: 'duration_desc' | 'ttft_desc') {
const wrapper = mount(OpsRequestDetailsModal, {
props: { modelValue: false, timeRange: '1h', preset: { title: 'Details', sort } },
global: { stubs: { BaseDialog: { template: '<div><slot /></div>' }, Pagination: true } },
})
await wrapper.setProps({ modelValue: true })
await flushPromises()
return wrapper
}
describe('Ops request latency details', () => {
beforeEach(() => {
vi.clearAllMocks()
viewport.desktop = true
listRequestDetails.mockResolvedValue({
items: [
{ kind: 'success', created_at: '2026-09-10T00:00:00Z', duration_ms: 12000, first_token_ms: 800 },
{ kind: 'success', created_at: '2026-09-10T00:00:01Z', duration_ms: 9000, first_token_ms: 0 },
{ kind: 'success', created_at: '2026-09-10T00:00:02Z', duration_ms: 5000, first_token_ms: null },
],
total: 3,
})
})
it('opens the TTFT card with first-token sorting and successful requests', async () => {
const wrapper = shallowMount(OpsDashboardHeader, {
props: { overview: {} as OpsDashboardOverview, platform: '', groupId: null, timeRange: '1h', queryMode: 'auto', loading: false, lastUpdated: null },
})
await flushPromises()
const button = wrapper.findAll('button').find((item) =>
item.text() === 'admin.ops.requestDetails.details' &&
item.element.parentElement?.textContent?.includes('TTFT'),
)
expect(button).toBeDefined()
await button!.trigger('click')
expect(wrapper.emitted('openRequestDetails')).toEqual([[
{ title: 'admin.ops.ttftLabel', kind: 'success', sort: 'ttft_desc' },
]])
wrapper.unmount()
})
it.each([true, false])('shows TTFT rather than total duration (desktop: %s)', async (desktop) => {
viewport.desktop = desktop
const wrapper = await openDetails('ttft_desc')
expect(listRequestDetails).toHaveBeenCalledWith(expect.objectContaining({ sort: 'ttft_desc' }))
expect(wrapper.text()).toContain('admin.ops.ttftLabel')
expect(wrapper.text()).toContain('800 ms')
expect(wrapper.text()).toContain('0 ms')
expect(wrapper.text()).not.toContain('12000 ms')
expect(wrapper.text()).not.toContain('9000 ms')
expect(wrapper.text()).not.toContain('5000 ms')
if (desktop) expect(wrapper.findAll('tbody tr')[2].findAll('td')[4].text()).toBe('-')
else expect(wrapper.text()).toContain('admin.ops.ttftLabel: -')
wrapper.unmount()
})
it('keeps total duration for duration details', async () => {
const wrapper = await openDetails('duration_desc')
expect(listRequestDetails).toHaveBeenCalledWith(expect.objectContaining({ sort: 'duration_desc' }))
expect(wrapper.text()).toContain('admin.ops.requestDetails.table.duration')
expect(wrapper.text()).toContain('12000 ms')
expect(wrapper.text()).not.toContain('800 ms')
wrapper.unmount()
})
})