diff --git a/packages/gooddata-eval/README.md b/packages/gooddata-eval/README.md index d6b614955..c83635c42 100644 --- a/packages/gooddata-eval/README.md +++ b/packages/gooddata-eval/README.md @@ -234,6 +234,11 @@ The JSON report always uses the nested multi-model shape: Winner is selected by **pass rate → quality score → latency** (lower latency wins all-equal ties). +The HTML report orders runs by when they started (`summary.started_at`, an ISO 8601 UTC timestamp that `gd-eval run` writes +into each run's `summary`, `null` when a run was never timed), so the order the files are passed to +`gd-eval report` does not decide which run is the latest. A report without it falls back to the date a run's file is +named for (`2026-09-28.json`), and if any run has neither it keeps the order the files were given in. + Each item reports **how many of its runs passed**, not only whether one did: ```json @@ -308,13 +313,69 @@ The other six agentic kinds report `0.0` for the first three. Trace linking itse runner rather than by `evaluate_agentic_*`, so a direct library caller sees `langfuse_s: 0.0` even though its linking ran. Pass `TAVERN_E2E_SKIP_TRACE_LINK=1` to opt out of linking altogether. +### Latency: single-shot and multi-turn + +`avg_latency_s` is one number over a mixed population. The report instead keeps two kinds of item apart, by +their eval kind, and states latency for each: + +- **Single-shot** — kinds that send exactly one chat message per run: every non-agentic kind, plus + `agentic_general_question`, `agentic_guardrail` and `agentic_search`. +- **Multi-turn** — kinds that drive a simulated user or fixture turns: `agentic_visualization` (and + `vis_agentic`), `agentic_metric_skill`, `agentic_alert_skill`, `agentic_dashboard_skill`, + `agentic_document_skill`, `agentic_kda_skill`, `agentic_anomaly_detection`, `agentic_what_if` and + `agentic_conversation`. + +```json +"summary": { + "by_mode": { + "single_shot": {"total": 12, "passed": 10, + "traces_s": {"n": 24, "mean": 5.39, "trimmed_mean": 5.36, "min": 3.88, "p50": 5.33, "p70": 6.23, "p90": 6.82, "p99": 7.18, "max": 7.22}}, + "multi_turn": {"total": 6, "passed": 4, + "traces_s": {"n": 45, "mean": 6.91, "trimmed_mean": 6.84, "min": 2.78, "p50": 6.52, "p70": 8.03, "p90": 10.79, "p99": 13.57, "max": 14.25}, + "runs_s": {"n": 15, "mean": 23.55, "trimmed_mean": 23.31, "min": 12.64, "p50": 21.23, "p70": 28.52, "p90": 33.02, "p99": 36.94, "max": 37.51}} + } +} +``` + +`by_mode` is in each run's `summary` and in its `comparison` entry. `total` and `passed` count the evaluated +items of that mode (skipped ones belong to neither). Every distribution is `null` when nothing was timed. +Each item also states its `mode`, its `trace_latencies_s` and its `run_latencies_s`. + +- **Per trace is the main figure.** gen-ai starts one trace per chat message, so a trace is one chat turn. + Its latency is that turn's response time, from sending the message to the end of its stream + (`turn_wall_clock_sec`), recorded where the chat client completes the turn. It holds none of the LLM judge, + the simulated user or conversation create/delete. `dashboard_summary` is timed the same way around its one + request. A turn cut off by its turn or item deadline (or ended by an error event) still counts, with the + time it ran for: those are the slowest turns, and the run that scored them is in the per-run figures too. An + item that errored outside its evaluator's own failure reporting contributes neither. +- **Single-shot** runs are exactly one trace, so `traces_s` is also the latency of a run. +- **Multi-turn** runs span several traces, so they get both views: `traces_s` over every turn of every + conversation (comparable with single-shot), and `runs_s`, the wall clock of each whole conversation from just + before its first message to the end of its scoring — every turn, simulated-user reply and judge call, but not + conversation create/delete. `agentic_conversation` drives its fixture once and contributes one run per item. + The two single-shot and multi-turn populations are never mixed. +- **Percentiles** use linear interpolation between closest ranks (NumPy's default), so `p50` is the median and + the report carries no separate median field. On a small sample the high percentiles sit at or near the + maximum: P99 over fewer than 100 samples is effectively the slowest one, which is why `n` always travels with it. +- **Trimmed mean** (`trimmed_mean`) is the average of the middle 80%: the fastest 10% and the slowest 10% of the + samples are dropped from each end (`n * 10 // 100` of them, so 25 samples drop two each) before averaging. It is + not the median, which is one middle value (`p50`). It is `null` below 10 samples, where there is nothing to + trim and the figure would only repeat `mean`. +- **Older reports** have no `by_mode`. The HTML report says so and nothing is backfilled. + +`avg_latency_s` and the other existing fields are unchanged. The console prints each run's pass counts per +mode and one `Latency, (n=...)` line per distribution beneath its summary line, and Trace +P50/P90/P99 columns (single-shot) in the multi-model comparison. + --- ## `gd-eval report` Turns JSON report(s) into one HTML file you can actually navigate. No server, no credentials, no external assets — it opens over `file://`, attaches to a Jira issue and -survives a Slack thread. +survives a Slack thread. It follows GoodData's product look (colours, type, status chips). The faces are Inter, with +Funnel Display for headings, named but never loaded, so a viewer without them gets the system sans and the file stays +self-contained. ```bash # one run @@ -333,25 +394,130 @@ gd-eval report results.json -o customer.html --redact | `--title TEXT` | Title shown in the report header. | | `--redact` | Drop conversation/response ids and raw reasoning, and rename models to `Model A`, `Model B`, … Pass rate, per-item results, questions and latency survive. | -The report is a *view* over the JSON — it computes no numbers of its own. It gives you: - -- **Run cards and a comparison table** — pass rate, quality, latency per run. -- **An item table** with a pass/fail column per run, so a model or run-over-run - regression is one glance rather than a hand-assembled spreadsheet. -- **An expression filter** for cross-cutting questions the fixed filters can't - anticipate, e.g. `d.filter_ranking_score === false` or +The report is a *view* over the JSON. Unfiltered, every figure on it is read from the report, so it cannot +disagree with the console or the JSON. Narrow the selection with a filter and the figures are recomputed in the +page from the selected items' own records, by the same rules gd-eval uses. The page reads top to bottom as a +document, in plain words: a *test case* is one prompt given to the assistant, an *attempt* is one go at it, and the +two formats are *single-question* tests (one answer, no follow-up) and *conversation* tests (a back-and-forth with a +simulated user), which are `single_shot` and `multi_turn` in the JSON. + +- **A masthead** with the report's title (`--title`, or "Run history", "Run comparison", "Model comparison" or + "Run results" plus the model and workspace), when it was generated in the reader's own time zone, and a **Run setup** tooltip listing what + is the same in every run (model, provider, workspace, dataset, test cases, attempts per test case, pass rule) and + what differs. Results from different setups are not directly comparable, so a caution icon on a latency row and the + *New* / *Removed* marks in the test case table say where two runs stopped being alike. +- **View by** — a dropdown above the filters that lays the same report out two ways. **Date** is the layout the + rest of this list describes: a column per run, oldest to latest by start time, with change lines, sparklines and the latency line + chart. **Model** compares language models instead: a column per model, ranked best first by the console's winner + rule (pass rate, then quality, then the quicker average), with no time axis. Where a model has several runs its + latest stands for it, so each model is read at its most recent state. The Run filter becomes a Model filter, the hint + beside the dropdown says what is being compared (and names the dates when the compared runs differ in date), and the + Run setup tooltip does not flag the model itself as a difference. Every report opens on Date, including one that + compares several models (`gd-eval run --model a --model b --html`); choose Model to compare them. A single run has + nothing to switch between, so the dropdown is hidden. In the Model view the page reads, top to bottom: + - **Results** — one row per model, best pass rate first, with a bar of how its evaluated test cases ended (passed + green, failed red, could not be graded orange), so the green part is the pass rate beside it, and the **Median + latency** of one attempt (half the attempts were faster, half slower). A list under the table says what each term means. The counts and the + caution icon (a model evaluated on different test cases than the one with the most) are the date view's Outcomes + table. There are no headline cards by model: the table is the first thing on the page. + - **Quality against speed** — each model as a point: the share of test cases it passed against the median time of + one attempt, the same pass rate as the Results table and the same median as the latency tables. Up and to the left is better. Time runs from zero; + the pass rate uses the range the models span. It needs two models with timings. + - **By category** — a heat map of the pass rate per category and model, the best model in each row marked, the + categories where the models differ most first. Every cell prints its share and its counts, so the shade is never the + only signal. This is where a model that wins overall but loses on one category shows. + - **Consistency across attempts** — per model, the share of test cases that passed on at least one attempt (pass@K, + the light bar) beside the share that passed on every attempt (pass^K, the dark bar), and how many passed only some. + A long gap is a model that can do the task but not reliably. It appears only for a report that recorded + `pass_power_k` and attempted a test case more than once. + - **Latency sections** — the same four percentiles, one row per model, quickest first, with a bar per figure drawn + from zero beside the numbers. The quickest and slowest model in each column are marked as in the date view. + - **Test cases** — one result column per model in ranked order, a response-time column per model, and an **Across + models** column in place of *Since previous run*: *Mixed* (some models passed and some did not; hover to see who), + *All pass* or *All fail*. A skipped or ungraded test case is left out of the verdict. The table opens on the + *Mixed* ones, the test cases where the models differ. +- **Filters in two tiers** — the **Filter the report** bar at the top (category, format, result and run) decides what + the whole page covers: the Results cards, the outcomes table, the latency tables and the test case table all follow it, so the runs stay + comparable. The Test cases section repeats those four and adds the search box and the expression; they narrow the + table only, inside whatever the top bar allows, and only offer what the top bar leaves. Category, result and run are + attribute filters like the product's: a search box, an All row, the values with an **Only** shortcut and a count, + then Cancel and Apply. Changes are staged in the popup and take effect on Apply; closing it any other way discards + them. Nothing ticked means all. The run filter chooses which runs are shown; a result matches a test case when any of + the runs in play has it (so "Failed" over previous and latest finds every test case that broke in either), and the + expression is evaluated once per run in play with the same any-run rule. A filtered page states how many test cases + it covers, and each tier has its own Reset. +- **Results** — three headline cards for the latest run: test cases passed (of those evaluated: skipped ones are not + counted, as in the console's percentage), the average quality score and the median time per attempt. With an earlier run each card carries one change line in words, "down from 86% on Sep 28", rather + than a signed number. The line is green when that direction is good and red when it is not, with a chevron and + screen-reader text (*Better* / *Worse*) so colour is not the only signal. From three runs each card also has a + sparkline of every run: hover a point for its value, click it to compare the latest run with that one instead of the + previous. The dot being compared with is drawn white, and a key under the cards says so (latest run, compared with, + other runs) and that a click on any other dot moves the comparison; it shows only when a sparkline does. A pick that + a filter has removed, or that has become the latest run, falls back to the previous run. The + pass-rate card links to the test case table to see *which* ones changed; the split by format lives in that table's + filters. +- **Outcomes** — how every test case ended, as a table with one row per run, newest first, in the same layout as the + latency tables. A run is identified by three columns: the **Run date**, the day and time it started (`summary.started_at`, + shown in the reader's own time zone, the UTC stamp on hover; a report written before it existed shows the date its file is + named for, without a time), and the **Run name**, the name the run was given, as given, so a run named `2026-09-28` reads + `2026-09-28` here although the charts style it as "Sep 28", and the **Model** it evaluated, its provider on hover. Then **Passed**, **Failed**, **Could not be graded** (an error left it without a verdict) and + **Skipped** (not run), then the **Pass rate**. The four are the values of the Result filter, and the pass rate is + the card's: passed out of the evaluated test cases, skipped ones left out, as in the console. The highest pass rate + is marked green with an up chevron and the lowest red with a down chevron, and the latest run is marked in lime. A + caution icon flags a run evaluated over a different number of test cases than the one before, because its pass + rate is then not a like-for-like change. The counts are read from the run's `summary` (`passed`, `failed`, + `errored`, `skipped`); a filtered view recounts them from the selected test cases, and a report written before + `summary.failed` existed shows what the other three leave. +- **Latency sections** — **Single-question tests · response time** first, then **Conversation tests**, which shows + both per response (each assistant reply, one gen-ai trace) and per conversation (start to finish, with the + simulated user and the judge). Each opens with a **line chart** of the median (P50), P70, P90 and P99 across the + runs, oldest on the left and the latest on the right, drawn from zero so line heights compare honestly; the lines + share one blue that darkens towards the tail. Hover or focus a run for its crosshair and every figure, in a tooltip + that says how many responses it rests on. A line needs two runs with timings, so with one run the chart is left + out. End labels name each line and give its latest value, and are dropped when two would touch. Under the chart a + table has one row per run, newest first, identified by the same **Run date**, **Run name** and **Model** columns as the outcomes table, with the same four figures. The quickest run in each column is marked + green and the slowest red, each with a chevron (down for least time, up for most) so colour is not the only + signal, and the latest run is marked in lime. A caution icon flags a run timed on a different number of samples + than the one before. Unfiltered they are read from `by_mode`; a filtered view recomputes them in the page by the + same rules. The fastest and slowest single response, the average and the trimmed average stay in the JSON (P99 + over a few dozen samples sits close to the slowest one, which is why `n` travels with it in the tooltip and + the cell hint). Seconds read with one decimal and no redundant ".0" (`3s`, `4.6s`). +- **A test case table**, newest first: the latest run's result, a **Since previous run** column, then the earlier runs + going back in time (click any result to open the drawer on that run). Each run's column is headed by its run date over + its run name, one to a line (hover the heading for the full run label); by model the columns are headed by the model. The change column reads *Regressed* (passed in + the previous run, not in the latest), *Fixed*, *Flaky* (flipped between pass and fail more than once), *New* + (in no earlier run) or *Removed* (in an earlier run, gone from the latest). A test case skipped in the latest run + has no label, since the change would describe earlier runs. With several runs the table opens on the regressions. Two time columns + keep the populations apart: **Response time** is the median of the test case's assistant responses, and **Time per + attempt** is the mean wall-clock of a whole attempt (the responses plus the judge and, for conversations, the + simulated user). With more than two runs shown they follow the latest run only. Hover a value to see every sample + behind it; the drawer labels its two latency chips the same way. A report written before per-trace timing has no + response figure and shows `avg_latency_s` as the attempt figure. +- **An expression filter**, folded under *Advanced: filter by a check expression* in the Test cases section, for + cross-cutting questions the fixed filters can't anticipate, e.g. `d.filter_ranking_score === false` or `d.expected_metric_uris.length > 1 && !d.metrics_correct`. Available variables: - `d` (the focused run's `detail`), `it` (its item), `i` (the row, `i.per[label]` for any - run), `q` (question), `kind`. -- **The conversation**, when the item ran the agentic multi-turn path — every turn in + `d` (the checks of the run being read, its `detail`), `it` (that run's result), `i` (the row, `i.per[label]` for any + run), `q` (question), `kind` (category id). +- **The conversation**, when the test case ran the agentic multi-turn path — every turn in order, with the simulated user marked apart from a real question, so you can see whether the agent got there or was handed the answer. -- **A per-item drawer** — checks as pass/fail chips, expected vs actual side by side, - full reasoning, conversation/response ids. +- **A per-test-case drawer** — checks as pass/fail chips, expected vs actual side by side, + the latency timeline, conversation/response ids. - **A latency timeline** from `detail.latency_breakdown`, in execution order, one bar per - step. Clicking a step expands its full record, joined by `index`: the paragraph a - reasoning step was summarised from, or a tool call's arguments and result from - `detail.tool_calls`. + step. Every step has a chevron that opens its full record in place, joined by `index`: the + paragraph a reasoning step was summarised from, or a tool call's arguments and result from + `detail.tool_calls`. A reasoning paragraph's markdown `**title**` is shown as bold text, + not as asterisks. Any number of steps can be open at once, and the chevron above the list + opens or closes all of them. The reasoning therefore lives on the timeline; a separate + Reasoning section appears only for paragraphs no step points at (or when a run recorded no + timeline). +- **A print stylesheet** that drops the filters and the drawer, so "Save as PDF" gives a clean page. + +A report that merges several files names each run after its file, and a file named for its date (`2026-09-28.json`) +reads as "Sep 28". A model is read from the run itself (`model` and the provider), never from the file name, so files +named for their model work as well as files named for their date. In the Date view the page treats the runs as one +model followed over time; when a report holds several models it adds the model to each run's name and points at +**Model** (see above) for the comparison. `--redact` additionally drops `transcript` and `tool_calls`: the exchange shows that the simulated user is primed with the expected output, and a tool result carries diff --git a/packages/gooddata-eval/src/gooddata_eval/cli/agentic_runner.py b/packages/gooddata-eval/src/gooddata_eval/cli/agentic_runner.py index 09d0dc267..79e2f4687 100644 --- a/packages/gooddata-eval/src/gooddata_eval/cli/agentic_runner.py +++ b/packages/gooddata-eval/src/gooddata_eval/cli/agentic_runner.py @@ -6,6 +6,7 @@ import sys import time from concurrent.futures import ThreadPoolExecutor, as_completed +from datetime import datetime, timezone from typing import Any, TypedDict from gooddata_eval.core.agentic._gate import DEFAULT_GATE, EvalGate, normalize_gate @@ -28,6 +29,7 @@ from gooddata_eval.core.evaluators.visualization import requires_execution_of from gooddata_eval.core.models import AgenticEvalOutcome, CreatedVisualization, DatasetItem from gooddata_eval.core.runner import EvalReport, ItemReport +from gooddata_eval.core.timing import TraceRecorder class _LfKw(TypedDict, total=False): @@ -375,6 +377,18 @@ def _apply_failed_runs(item_report: ItemReport, source: Any) -> None: item_report.failed_runs = list(failed_runs) +def _apply_run_latencies(item_report: ItemReport, source: Any) -> None: + """Copy the per-run wall-clock times off an outcome or a failure, if the kind timed them. + + Read from both like ``_apply_failed_runs``: a failing item reaches the report through the + exception. A kind that records none leaves the empty default, so the item adds no sample + to the latency distribution rather than a zero. + """ + run_latencies = getattr(source, "run_latencies_s", None) + if run_latencies: + item_report.run_latencies_s = list(run_latencies) + + def _apply_timings(item_report: ItemReport, timings: Any) -> None: """Copy an outcome's phase breakdown onto the item report, if the kind recorded one. @@ -429,6 +443,7 @@ def run_agentic_items( # latency. Drained below before this function returns, so every score is written # before the caller renders a report or decides an exit code. linker = BackgroundTraceLinker() + report.started_at = datetime.now(timezone.utc) _t0 = time.perf_counter() def _process_item(index: int, item: DatasetItem) -> ItemReport: @@ -447,6 +462,10 @@ def _process_item(index: int, item: DatasetItem) -> ItemReport: # None, not False, for the kinds _dispatch_agentic passes no gate to: ItemReport.passed # then falls back to pass_at_k and gate_passed keeps meaning "a gate ran". gated = item.test_kind not in UNGATED_AGENTIC_TEST_KINDS + # Started in this worker, where the item runs, so a concurrent item cannot write into it. + # Every kind reaches the chat client the same way, which is why the per-trace latencies are + # collected here once rather than handed out by each evaluator. + traces = TraceRecorder() t0 = time.perf_counter() try: outcome = _dispatch_agentic( @@ -482,6 +501,7 @@ def _process_item(index: int, item: DatasetItem) -> ItemReport: _apply_timings(item_report, getattr(outcome, "timings", None)) _apply_run_counts(item_report, outcome) _apply_failed_runs(item_report, outcome) + _apply_run_latencies(item_report, outcome) except AssertionError as exc: item_report.gate_passed = False if gated else None item_report.runs = k @@ -492,6 +512,7 @@ def _process_item(index: int, item: DatasetItem) -> ItemReport: _apply_timings(item_report, getattr(exc, "timings", None)) _apply_run_counts(item_report, exc) _apply_failed_runs(item_report, exc) + _apply_run_latencies(item_report, exc) # Read off the counts, not off the gate: pass^K fails items where runs did pass, # and reporting those as pass_at_k False would contradict the Langfuse score of # the same name. Kinds that report no count read as 0, i.e. a clean failure. @@ -512,6 +533,7 @@ def _process_item(index: int, item: DatasetItem) -> ItemReport: _apply_timings(item_report, getattr(exc, "timings", None)) _apply_run_counts(item_report, exc) _apply_failed_runs(item_report, exc) + _apply_run_latencies(item_report, exc) # Every run ungraded, by definition of this error -- said explicitly rather than # left to _apply_run_counts, whose source is detail["unscored_runs"] and which a # kind that attaches no diagnostics would leave at 0. @@ -525,8 +547,15 @@ def _process_item(index: int, item: DatasetItem) -> ItemReport: # judge broke should not also report the agent as costing 0s. Kinds that # attach no timings to the exception keep their 0.0 defaults. _apply_timings(item_report, getattr(exc, "timings", None)) + # Phase timings stay, but the per-turn response times do not: this item reports no + # runs (and so no run latencies), and keeping its turns would put them in the + # response population with no attempt beside them. An item that completed 2 of 3 + # runs and then raised would otherwise show up in the per-response table and not in + # the per-conversation one. + traces.discard() finally: item_report.latency_s = time.perf_counter() - t0 + item_report.trace_latencies_s = traces.stop() if on_item_done is not None: try: diff --git a/packages/gooddata-eval/src/gooddata_eval/cli/main.py b/packages/gooddata-eval/src/gooddata_eval/cli/main.py index 8d90b12ce..2ca25eadf 100644 --- a/packages/gooddata-eval/src/gooddata_eval/cli/main.py +++ b/packages/gooddata-eval/src/gooddata_eval/cli/main.py @@ -649,6 +649,10 @@ def on_langfuse_item_done( report.items.extend(agentic_report.items) report.items.extend(single_report.items) report.wall_clock_s = (agentic_report.wall_clock_s if agentic_report else 0.0) + single_report.wall_clock_s + report.started_at = min( + (r.started_at for r in (agentic_report, single_report) if r is not None and r.started_at is not None), + default=None, + ) skipped_kinds = sorted({i.test_kind for i in report.items if i.skipped}) if skipped_kinds: diff --git a/packages/gooddata-eval/src/gooddata_eval/core/agentic/alert_skill.py b/packages/gooddata-eval/src/gooddata_eval/core/agentic/alert_skill.py index b7b771297..191037db8 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/agentic/alert_skill.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/agentic/alert_skill.py @@ -6,6 +6,7 @@ import json import os import re +import time from dataclasses import dataclass, field from typing import Any @@ -587,6 +588,8 @@ class AlertRunResult: # also report operator/threshold/metric/recipients as False. exit_reason: LoopExit = LoopExit.BUDGET_EXHAUSTED turns_used: int = 0 + # This run's own wall time, from just before its chat call to the end of its scoring. + run_latency_s: float = 0.0 @dataclass @@ -802,6 +805,7 @@ def _run_once(conv_id: str) -> AlertRunResult: # that simply runs out of range() is correctly labelled without a trailing else. exit_reason = LoopExit.BUDGET_EXHAUSTED turns_used = 0 + run_started = time.monotonic() for _iteration in range(max_iterations): turns_used = _iteration + 1 try: @@ -903,6 +907,7 @@ def _run_once(conv_id: str) -> AlertRunResult: reasoning_step_events=all_reasoning_step_events, exit_reason=exit_reason, turns_used=turns_used, + run_latency_s=time.monotonic() - run_started, ) finally: if alert_id_to_delete: @@ -1122,6 +1127,7 @@ def _write_scores(ctx: RunTraceContext) -> None: exc.runs_passed = runs_passed exc.runs_effective = runs_effective exc.failed_runs = failed_runs + exc.run_latencies_s = [r.run_latency_s for r in summary.run_results] raise exc return AgenticEvalOutcome( runs_passed=runs_passed, @@ -1133,4 +1139,5 @@ def _write_scores(ctx: RunTraceContext) -> None: # Also on the success path: pass@K clears the gate with one passing run, so a # 1/3 item reports success while two of its runs failed for reasons worth reading. failed_runs=failed_runs, + run_latencies_s=[r.run_latency_s for r in summary.run_results], ) diff --git a/packages/gooddata-eval/src/gooddata_eval/core/agentic/anomaly_detection.py b/packages/gooddata-eval/src/gooddata_eval/core/agentic/anomaly_detection.py index b980b7067..1a4238983 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/agentic/anomaly_detection.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/agentic/anomaly_detection.py @@ -28,6 +28,7 @@ import logging import os import re +import time from dataclasses import dataclass, field from typing import Any @@ -284,6 +285,8 @@ class AnomalyRunResult: response_id: str | None = None tool_call_events: list[ToolCallEvent] = field(default_factory=list) reasoning_step_events: list[ReasoningStepEvent] = field(default_factory=list) + # This run's own wall time, from just before its chat call to the end of its scoring. + run_latency_s: float = 0.0 @dataclass @@ -393,6 +396,7 @@ def _accumulate(result: ChatResult) -> None: all_tool_call_events.extend(result.tool_call_events or []) all_reasoning_step_events.extend(result.reasoning_step_events or []) + run_started = time.monotonic() for iteration in range(max_iterations): try: chat_result = client.send_message(conv_id, current_question) @@ -440,6 +444,7 @@ def _accumulate(result: ChatResult) -> None: response_id=response_id, tool_call_events=all_tool_call_events, reasoning_step_events=all_reasoning_step_events, + run_latency_s=time.monotonic() - run_started, ) try: @@ -651,6 +656,7 @@ def _write_scores(ctx: RunTraceContext) -> None: exc.runs_passed = runs_passed exc.runs_effective = len(summary.run_results) exc.failed_runs = failed_runs + exc.run_latencies_s = [r.run_latency_s for r in summary.run_results] raise exc return AgenticEvalOutcome( @@ -661,4 +667,5 @@ def _write_scores(ctx: RunTraceContext) -> None: response_id=best.response_id, detail=detail, failed_runs=failed_runs, + run_latencies_s=[r.run_latency_s for r in summary.run_results], ) diff --git a/packages/gooddata-eval/src/gooddata_eval/core/agentic/conversation.py b/packages/gooddata-eval/src/gooddata_eval/core/agentic/conversation.py index e5f8aef36..3788598a5 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/agentic/conversation.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/agentic/conversation.py @@ -19,6 +19,7 @@ import json import os import re +import time from dataclasses import dataclass, field from datetime import date from typing import ClassVar, Literal @@ -612,6 +613,9 @@ class ConversationResult: stalled_turns: int = 0 mode: ConversationMode = "legacy" judge_model: str | None = None + # The whole conversation's wall time, from just before its first message to the end of its + # last turn's scoring; conversation create/delete is not part of it. + run_latency_s: float = 0.0 def _metric_creations(tool_call_events: list[ToolCallEvent]) -> list[tuple[str, bool]]: @@ -771,6 +775,7 @@ def run_agentic_conversation( tool_index_offset = 0 reasoning_index_offset = 0 current_context = user_context + run_latency_s = 0.0 try: if initial_conversation_id is not None: @@ -779,10 +784,14 @@ def run_agentic_conversation( conversation_id = client.create_conversation() owns_conversation = True + run_started = time.monotonic() + conversation_swap_s = 0.0 # fresh_conversation_per_turn's delete/create, which is not the run's work for turn_index, turn in enumerate(fixture.turns): if fresh_conversation_per_turn and turn_index > 0: + swap_started = time.monotonic() client.delete_conversation(conversation_id) conversation_id = client.create_conversation() + conversation_swap_s += time.monotonic() - swap_started transcript = [] active_skills = set() # Before the skip below: a turn whose expectation cannot resolve still changed what @@ -1006,6 +1015,8 @@ def run_agentic_conversation( ) ) + # Taken here, not after the finally: its cleanup is not part of the run. + run_latency_s = time.monotonic() - run_started - conversation_swap_s finally: if owns_conversation and conversation_id: client.delete_conversation(conversation_id) @@ -1039,6 +1050,7 @@ def run_agentic_conversation( stalled_turns=stalled, mode=resolved_mode, judge_model=judge.model_name if judged else None, + run_latency_s=run_latency_s, ) @@ -1246,6 +1258,7 @@ def _write_scores(ctx: RunTraceContext) -> None: # for. Saying so explicitly stops the report claiming K runs that never happened. exc.runs_passed = 0 exc.runs_effective = 1 + exc.run_latencies_s = [result.run_latency_s] raise exc return AgenticEvalOutcome( reasoning_steps=result.reasoning_steps, @@ -1254,4 +1267,5 @@ def _write_scores(ctx: RunTraceContext) -> None: detail=detail, runs_passed=1, runs_effective=1, + run_latencies_s=[result.run_latency_s], ) diff --git a/packages/gooddata-eval/src/gooddata_eval/core/agentic/dashboard_skill.py b/packages/gooddata-eval/src/gooddata_eval/core/agentic/dashboard_skill.py index 14acd8ba2..9bbe130db 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/agentic/dashboard_skill.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/agentic/dashboard_skill.py @@ -1167,6 +1167,8 @@ class DashboardRunResult: tool_call_events: list[ToolCallEvent] = field(default_factory=list) reasoning_step_events: list[ReasoningStepEvent] = field(default_factory=list) timings: PhaseTimings = field(default_factory=PhaseTimings) + # This run's own wall time, from just before its chat call to the end of its scoring. + run_latency_s: float = 0.0 @dataclass @@ -1399,6 +1401,7 @@ def _execute_single_dashboard_run( tool_index_offset = 0 reasoning_index_offset = 0 + run_started = time.monotonic() for iteration in range(max_iterations): turns += 1 agent_started = time.monotonic() @@ -1475,6 +1478,7 @@ def _execute_single_dashboard_run( tool_call_events=all_tool_call_events, reasoning_step_events=all_reasoning_step_events, timings=timings, + run_latency_s=time.monotonic() - run_started, ) @@ -1703,6 +1707,7 @@ def _write_scores(ctx: RunTraceContext) -> None: exc.runs_passed = runs_passed exc.runs_effective = runs_effective exc.failed_runs = failed_runs + exc.run_latencies_s = [r.run_latency_s for r in summary.run_results] raise exc return AgenticEvalOutcome( runs_passed=runs_passed, @@ -1713,4 +1718,5 @@ def _write_scores(ctx: RunTraceContext) -> None: detail=detail, timings=item_timings, failed_runs=failed_runs, + run_latencies_s=[r.run_latency_s for r in summary.run_results], ) diff --git a/packages/gooddata-eval/src/gooddata_eval/core/agentic/document_skill.py b/packages/gooddata-eval/src/gooddata_eval/core/agentic/document_skill.py index f3e8edeea..ba6332a4a 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/agentic/document_skill.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/agentic/document_skill.py @@ -638,6 +638,8 @@ class DocumentRunResult: tool_call_events: list[ToolCallEvent] = field(default_factory=list) reasoning_step_events: list[ReasoningStepEvent] = field(default_factory=list) timings: PhaseTimings = field(default_factory=PhaseTimings) + # This run's own wall time, from just before its chat call to the end of its scoring. + run_latency_s: float = 0.0 @property def diagnostics(self) -> dict[str, bool]: @@ -711,6 +713,7 @@ def _execute_single_document_run( reasoning_index_offset = 0 first_turn_asked = False + run_started = time.monotonic() for iteration in range(max_iterations): turns += 1 agent_started = time.monotonic() @@ -781,6 +784,7 @@ def _execute_single_document_run( tool_call_events=all_tool_call_events, reasoning_step_events=all_reasoning_step_events, timings=timings, + run_latency_s=time.monotonic() - run_started, ) @@ -980,6 +984,7 @@ def _write_scores(ctx: RunTraceContext) -> None: + " | ".join(unscored) ) exc_judge.timings = item_timings + exc_judge.run_latencies_s = [r.run_latency_s for r in summary.run_results] raise exc_judge runs_passed = sum(1 for r in summary.run_results if r.evaluation.strict_pass) @@ -1033,6 +1038,7 @@ def _run_detail(run: DocumentRunResult) -> dict[str, Any]: exc.runs_passed = runs_passed exc.runs_effective = runs_effective exc.failed_runs = failed_runs + exc.run_latencies_s = [r.run_latency_s for r in summary.run_results] raise exc return AgenticEvalOutcome( runs_passed=runs_passed, @@ -1043,4 +1049,5 @@ def _run_detail(run: DocumentRunResult) -> dict[str, Any]: detail=detail, timings=item_timings, failed_runs=failed_runs, + run_latencies_s=[r.run_latency_s for r in summary.run_results], ) diff --git a/packages/gooddata-eval/src/gooddata_eval/core/agentic/general_question.py b/packages/gooddata-eval/src/gooddata_eval/core/agentic/general_question.py index 3dfed436c..5de9512d5 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/agentic/general_question.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/agentic/general_question.py @@ -91,6 +91,8 @@ class GeneralQuestionResult: judge_error: str | None = None tool_call_events: list[ToolCallEvent] = field(default_factory=list) reasoning_step_events: list[ReasoningStepEvent] = field(default_factory=list) + # This run's own wall time, from just before its chat call to the end of its scoring. + run_latency_s: float = 0.0 @dataclass @@ -153,6 +155,9 @@ def _run_single_general_question( judge_error=verdict.error, tool_call_events=list(chat_result.tool_call_events or []), reasoning_step_events=list(chat_result.reasoning_step_events or []), + # item_started is taken just before the chat call and total_elapsed right after + # scoring, so this is the whole run without a second clock read. + run_latency_s=total_elapsed, ) @@ -224,6 +229,7 @@ def _attach_diagnostics( failed_runs: list[dict], runs_passed: int, runs_effective: int, + run_latencies_s: list[float], ) -> None: """Hang the report payload on a raised error, whichever error it is. @@ -238,6 +244,7 @@ def _attach_diagnostics( error.runs_passed = runs_passed error.runs_effective = runs_effective error.failed_runs = failed_runs + error.run_latencies_s = run_latencies_s def _run_detail(run: GeneralQuestionResult) -> dict: @@ -363,6 +370,7 @@ def _write_scores(ctx: RunTraceContext) -> None: # `runs_passed` is then 0, so nothing here needs a graded run to exist. runs_passed = sum(1 for r in summary.scored_run_results if r.passed) runs_effective = len(summary.run_results) + run_latencies_s = [r.run_latency_s for r in summary.run_results] best = summary.best detail = { @@ -389,7 +397,7 @@ def _write_scores(ctx: RunTraceContext) -> None: f"judge returned no readable verdict for any of the {len(summary.run_results)} run(s): " + " | ".join(unscored) ) - _attach_diagnostics(error, best, detail, failed_runs, runs_passed, runs_effective) + _attach_diagnostics(error, best, detail, failed_runs, runs_passed, runs_effective, run_latencies_s) error.timings = item_timings raise error @@ -398,7 +406,7 @@ def _write_scores(ctx: RunTraceContext) -> None: exc = GeneralQuestionAssertionError( f"General question assertion failed. {gate_note} passed={best.passed}. Reasoning: {best.reasoning}" ) - _attach_diagnostics(exc, best, detail, failed_runs, runs_passed, runs_effective) + _attach_diagnostics(exc, best, detail, failed_runs, runs_passed, runs_effective, run_latencies_s) exc.timings = item_timings raise exc return AgenticEvalOutcome( @@ -412,4 +420,5 @@ def _write_scores(ctx: RunTraceContext) -> None: # Also on the success path: pass@K clears the gate with one passing run, so a # 1/3 item reports success while two of its runs failed for reasons worth reading. failed_runs=failed_runs, + run_latencies_s=run_latencies_s, ) diff --git a/packages/gooddata-eval/src/gooddata_eval/core/agentic/guardrail.py b/packages/gooddata-eval/src/gooddata_eval/core/agentic/guardrail.py index b05d16d8c..81f9cb1ad 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/agentic/guardrail.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/agentic/guardrail.py @@ -3,6 +3,7 @@ from __future__ import annotations +import time from dataclasses import dataclass, field from gooddata_eval.core.agentic._failed_runs import build_failed_runs @@ -86,6 +87,8 @@ class GuardrailResult: # Set when the judge returned something unreadable for THIS run. Excluded from pass@K # and from Langfuse scoring rather than counted as a failure -- see score_run. judge_error: str | None = None + # This run's own wall time, from just before its chat call to the end of its scoring. + run_latency_s: float = 0.0 @dataclass @@ -120,6 +123,7 @@ def _run_single_guardrail( Extracted so the two call sites below (the first conversation, which may be supplied, and the remaining K-1) cannot drift -- they had already duplicated the whole body once. """ + run_started = time.monotonic() chat_result = client.send_message(conversation_id, question) actual_output = render_answer_text(chat_result) verdict = score_run(judge, input=question, expected_output=expected_output, actual_output=actual_output) @@ -134,6 +138,7 @@ def _run_single_guardrail( tool_call_events=list(chat_result.tool_call_events or []), reasoning_step_events=list(chat_result.reasoning_step_events or []), judge_error=verdict.error, + run_latency_s=time.monotonic() - run_started, ) @@ -205,6 +210,7 @@ def _attach_diagnostics( failed_runs: list[dict], runs_passed: int, runs_effective: int, + run_latencies_s: list[float], ) -> None: """Hang the report payload on a raised error, whichever error it is. @@ -219,6 +225,7 @@ def _attach_diagnostics( error.runs_passed = runs_passed error.runs_effective = runs_effective error.failed_runs = failed_runs + error.run_latencies_s = run_latencies_s def _run_detail(run: GuardrailResult) -> dict: @@ -344,6 +351,7 @@ def _write_scores(ctx: RunTraceContext) -> None: # `runs_passed` is then 0, so nothing here needs a graded run to exist. runs_passed = sum(1 for r in summary.scored_run_results if r.passed) runs_effective = len(summary.run_results) + run_latencies_s = [r.run_latency_s for r in summary.run_results] best = summary.best detail = { @@ -367,7 +375,7 @@ def _write_scores(ctx: RunTraceContext) -> None: f"judge returned no readable verdict for any of the {len(summary.run_results)} run(s): " + " | ".join(unscored) ) - _attach_diagnostics(error, best, detail, failed_runs, runs_passed, runs_effective) + _attach_diagnostics(error, best, detail, failed_runs, runs_passed, runs_effective, run_latencies_s) raise error if not gate_passed(gate, pass_at_k=summary.pass_at_k, pass_power_k=summary.pass_power_k): @@ -375,7 +383,7 @@ def _write_scores(ctx: RunTraceContext) -> None: exc = GuardrailAssertionError( f"Guardrail assertion failed. {gate_note} passed={best.passed}. Reasoning: {best.reasoning}" ) - _attach_diagnostics(exc, best, detail, failed_runs, runs_passed, runs_effective) + _attach_diagnostics(exc, best, detail, failed_runs, runs_passed, runs_effective, run_latencies_s) raise exc return AgenticEvalOutcome( runs_passed=runs_passed, @@ -387,4 +395,5 @@ def _write_scores(ctx: RunTraceContext) -> None: # Also on the success path: pass@K clears the gate with one passing run, so a # 1/3 item reports success while two of its runs failed for reasons worth reading. failed_runs=failed_runs, + run_latencies_s=run_latencies_s, ) diff --git a/packages/gooddata-eval/src/gooddata_eval/core/agentic/kda_skill.py b/packages/gooddata-eval/src/gooddata_eval/core/agentic/kda_skill.py index 7bf58fea6..7ab93c40a 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/agentic/kda_skill.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/agentic/kda_skill.py @@ -5,6 +5,7 @@ import logging import os +import time from dataclasses import dataclass, field import httpx @@ -200,6 +201,8 @@ class KdaRunResult: # separate a refusal from a run that hit max_iterations while still on track. exit_reason: LoopExit = LoopExit.BUDGET_EXHAUSTED turns_used: int = 0 + # This run's own wall time, from just before its chat call to the end of its scoring. + run_latency_s: float = 0.0 @dataclass @@ -300,6 +303,7 @@ def _accumulate(result: ChatResult) -> None: turns = 0 steps = 0 + run_started = time.monotonic() for iteration in range(max_iterations): turns_used = iteration + 1 try: @@ -375,6 +379,7 @@ def _accumulate(result: ChatResult) -> None: reasoning_step_events=all_reasoning_step_events, exit_reason=exit_reason, turns_used=turns_used, + run_latency_s=time.monotonic() - run_started, ) try: @@ -585,6 +590,7 @@ def _write_scores(ctx: RunTraceContext) -> None: exc.runs_passed = runs_passed exc.runs_effective = runs_effective exc.failed_runs = failed_runs + exc.run_latencies_s = [r.run_latency_s for r in summary.run_results] raise exc return AgenticEvalOutcome( runs_passed=runs_passed, @@ -596,4 +602,5 @@ def _write_scores(ctx: RunTraceContext) -> None: # Also on the success path: pass@K clears the gate with one passing run, so a # 1/3 item reports success while two of its runs failed for reasons worth reading. failed_runs=failed_runs, + run_latencies_s=[r.run_latency_s for r in summary.run_results], ) diff --git a/packages/gooddata-eval/src/gooddata_eval/core/agentic/metric_skill.py b/packages/gooddata-eval/src/gooddata_eval/core/agentic/metric_skill.py index ebeb8fa2b..e77832986 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/agentic/metric_skill.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/agentic/metric_skill.py @@ -181,6 +181,8 @@ class MetricRunResult: exit_reason: LoopExit = LoopExit.BUDGET_EXHAUSTED turns_used: int = 0 timings: PhaseTimings = field(default_factory=PhaseTimings) + # This run's own wall time, from just before its first chat call to the end of its scoring. + run_latency_s: float = 0.0 @dataclass @@ -326,6 +328,7 @@ def _execute_single_metric_run( # Defaults to BUDGET_EXHAUSTED: every other exit assigns explicitly, so a loop that # simply runs out of range() is labelled correctly with no trailing else. exit_reason = LoopExit.BUDGET_EXHAUSTED + run_started = time.monotonic() for _iteration in range(max_iterations): turns += 1 agent_started = time.monotonic() @@ -427,6 +430,7 @@ def _execute_single_metric_run( timings=timings, exit_reason=exit_reason, turns_used=turns, + run_latency_s=time.monotonic() - run_started, ) finally: for metric_id in created_metric_ids: @@ -605,6 +609,7 @@ def _write_scores(ctx: RunTraceContext) -> None: runs_passed = sum(1 for r in summary.run_results if r.metric_created and r.maql_correct) runs_effective = len(summary.run_results) + run_latencies_s = [r.run_latency_s for r in summary.run_results] best = summary.best expected_outputs_list: list[dict] = expected_output if isinstance(expected_output, list) else [expected_output] @@ -655,6 +660,7 @@ def _run_detail(run: MetricRunResult) -> dict: exc.runs_passed = runs_passed exc.runs_effective = runs_effective exc.failed_runs = failed_runs + exc.run_latencies_s = run_latencies_s raise exc return AgenticEvalOutcome( runs_passed=runs_passed, @@ -667,4 +673,5 @@ def _run_detail(run: MetricRunResult) -> dict: # Also on the success path: pass@K clears the gate with one passing run, so a # 1/3 item reports success while two of its runs failed for reasons worth reading. failed_runs=failed_runs, + run_latencies_s=run_latencies_s, ) diff --git a/packages/gooddata-eval/src/gooddata_eval/core/agentic/search_tool.py b/packages/gooddata-eval/src/gooddata_eval/core/agentic/search_tool.py index cdb7256cd..1d19c2e89 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/agentic/search_tool.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/agentic/search_tool.py @@ -3,6 +3,7 @@ from __future__ import annotations +import time from dataclasses import dataclass, field from gooddata_eval.core.agentic._failed_runs import build_failed_runs @@ -77,6 +78,8 @@ class SearchResult: response_id: str | None = None tool_call_events: list[ToolCallEvent] = field(default_factory=list) reasoning_step_events: list[ReasoningStepEvent] = field(default_factory=list) + # This run's own wall time, from just before its chat call to the end of its scoring. + run_latency_s: float = 0.0 @dataclass @@ -115,6 +118,7 @@ def run_agentic_search_tool( try: conv_id_0 = initial_conversation_id if initial_conversation_id is not None else client.create_conversation() try: + run_started = time.monotonic() chat_result = client.send_message(conv_id_0, question) tcs = chat_result.tool_call_events or [] selected = _tool_selection(tcs) @@ -129,6 +133,7 @@ def run_agentic_search_tool( response_id=chat_result.response_id, tool_call_events=list(chat_result.tool_call_events or []), reasoning_step_events=list(chat_result.reasoning_step_events or []), + run_latency_s=time.monotonic() - run_started, ) ) finally: @@ -138,6 +143,7 @@ def run_agentic_search_tool( for _ in range(1, k): conv_id = client.create_conversation() try: + run_started = time.monotonic() chat_result = client.send_message(conv_id, question) tcs = chat_result.tool_call_events or [] selected = _tool_selection(tcs) @@ -152,6 +158,7 @@ def run_agentic_search_tool( response_id=chat_result.response_id, tool_call_events=list(chat_result.tool_call_events or []), reasoning_step_events=list(chat_result.reasoning_step_events or []), + run_latency_s=time.monotonic() - run_started, ) ) finally: @@ -306,6 +313,7 @@ def _write_scores(ctx: RunTraceContext) -> None: exc.runs_passed = runs_passed exc.runs_effective = runs_effective exc.failed_runs = failed_runs + exc.run_latencies_s = [r.run_latency_s for r in summary.run_results] raise exc return AgenticEvalOutcome( runs_passed=runs_passed, @@ -317,4 +325,5 @@ def _write_scores(ctx: RunTraceContext) -> None: # Also on the success path: pass@K clears the gate with one passing run, so a # 1/3 item reports success while two of its runs failed for reasons worth reading. failed_runs=failed_runs, + run_latencies_s=[r.run_latency_s for r in summary.run_results], ) diff --git a/packages/gooddata-eval/src/gooddata_eval/core/agentic/visualization.py b/packages/gooddata-eval/src/gooddata_eval/core/agentic/visualization.py index 1285d1c86..0dd553353 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/agentic/visualization.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/agentic/visualization.py @@ -8,6 +8,7 @@ from __future__ import annotations import os +import time from dataclasses import dataclass, field from gooddata_eval.core.agentic._failed_runs import build_failed_runs @@ -73,6 +74,8 @@ class RunResult: # Why the simulated-user loop stopped. visualization_created=False alone cannot separate # a refusal from a run that hit max_iterations while still on track -- see LoopExit. exit_reason: LoopExit = LoopExit.BUDGET_EXHAUSTED + # This run's own wall time, from just before its first chat call to the end of its scoring. + run_latency_s: float = 0.0 @dataclass @@ -210,6 +213,7 @@ def _execute_single_run( # simply runs out of range() is labelled correctly with no trailing else. exit_reason = LoopExit.BUDGET_EXHAUSTED + run_started = time.monotonic() try: current_result = client.send_message(conversation_id, question) except ChatError as exc: @@ -298,6 +302,7 @@ def _execute_single_run( tool_call_events=all_tool_call_events, reasoning_step_events=all_reasoning_step_events, exit_reason=exit_reason, + run_latency_s=time.monotonic() - run_started, ) @@ -530,6 +535,7 @@ def _write_scores(ctx: RunTraceContext) -> None: runs_passed = sum(1 for r in summary.run_results if r.eval_result.strict_pass) runs_effective = len(summary.run_results) + run_latencies_s = [r.run_latency_s for r in summary.run_results] best = summary.best ev = best.eval_result @@ -592,6 +598,7 @@ def _write_scores(ctx: RunTraceContext) -> None: exc.runs_passed = runs_passed exc.runs_effective = runs_effective exc.failed_runs = failed_runs + exc.run_latencies_s = run_latencies_s raise exc return AgenticEvalOutcome( runs_passed=runs_passed, @@ -603,4 +610,5 @@ def _write_scores(ctx: RunTraceContext) -> None: # Also on the success path: pass@K clears the gate with one passing run, so a # 1/3 item reports success while two of its runs failed for reasons worth reading. failed_runs=failed_runs, + run_latencies_s=run_latencies_s, ) diff --git a/packages/gooddata-eval/src/gooddata_eval/core/agentic/what_if.py b/packages/gooddata-eval/src/gooddata_eval/core/agentic/what_if.py index f59954f90..baaeb201d 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/agentic/what_if.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/agentic/what_if.py @@ -22,6 +22,7 @@ import logging import os +import time from dataclasses import dataclass, field from typing import Any @@ -211,6 +212,8 @@ class WhatIfRunResult: response_id: str | None = None tool_call_events: list[ToolCallEvent] = field(default_factory=list) reasoning_step_events: list[ReasoningStepEvent] = field(default_factory=list) + # This run's own wall time, from just before its chat call to the end of its scoring. + run_latency_s: float = 0.0 @dataclass @@ -350,6 +353,7 @@ def _accumulate(result: ChatResult) -> None: all_tool_call_events.extend(result.tool_call_events or []) all_reasoning_step_events.extend(result.reasoning_step_events or []) + run_started = time.monotonic() for iteration in range(max_iterations): try: chat_result = client.send_message(conv_id, current_question) @@ -397,6 +401,7 @@ def _accumulate(result: ChatResult) -> None: response_id=response_id, tool_call_events=all_tool_call_events, reasoning_step_events=all_reasoning_step_events, + run_latency_s=time.monotonic() - run_started, ) try: @@ -616,6 +621,7 @@ def _write_scores(ctx: RunTraceContext) -> None: exc.runs_passed = runs_passed exc.runs_effective = len(summary.run_results) exc.failed_runs = failed_runs + exc.run_latencies_s = [r.run_latency_s for r in summary.run_results] raise exc return AgenticEvalOutcome( @@ -626,4 +632,5 @@ def _write_scores(ctx: RunTraceContext) -> None: response_id=best.response_id, detail=detail, failed_runs=failed_runs, + run_latencies_s=[r.run_latency_s for r in summary.run_results], ) diff --git a/packages/gooddata-eval/src/gooddata_eval/core/chat/sse_client.py b/packages/gooddata-eval/src/gooddata_eval/core/chat/sse_client.py index 404a1fc45..b3bd6e734 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/chat/sse_client.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/chat/sse_client.py @@ -28,6 +28,7 @@ from gooddata_eval.core.config import ReasoningEffort, normalize_reasoning_effort from gooddata_eval.core.langfuse.item_scope import JoinedRun, baggage_entries, current_scope, mark_joined, trace_ids_for from gooddata_eval.core.models import ChatResult, DatasetItem +from gooddata_eval.core.timing import note_trace_latency _log = logging.getLogger(__name__) @@ -606,7 +607,19 @@ def _do() -> ChatResult: except ChatError as exc: if joined is not None and exc.partial_result is not None: self._record_join(conversation_id, exc.partial_result.trace_id, joined) + # A turn that ended in a ChatError (a turn or item deadline, an error event, an + # incomplete turn) is still one gen-ai trace, and several evaluators score its + # partial result as a run. Recording it keeps the response population matching the + # runs that were scored: left out, the slowest turns -- the ones that hit a deadline -- + # would vanish and pull the tail down exactly when the agent is slowest. + if exc.partial_result is not None: + note_trace_latency(exc.partial_result.turn_wall_clock_sec) raise + # One turn is one gen-ai trace. Recorded here, from the figure the turn already carries, + # so every caller is covered and no extra clock is read. A turn that failed without a + # ChatError carries no partial result, so there is no response to time and it is not + # recorded. + note_trace_latency(result.turn_wall_clock_sec) if joined is not None: self._record_join(conversation_id, result.trace_id, joined) return result diff --git a/packages/gooddata-eval/src/gooddata_eval/core/evaluators/_llm_judge.py b/packages/gooddata-eval/src/gooddata_eval/core/evaluators/_llm_judge.py index 701898068..c32cb3f40 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/evaluators/_llm_judge.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/evaluators/_llm_judge.py @@ -61,6 +61,7 @@ class JudgeResponseError(RuntimeError): runs_passed: int runs_effective: int failed_runs: list[dict] + run_latencies_s: list[float] def _message_content(response: Any) -> str | None: diff --git a/packages/gooddata-eval/src/gooddata_eval/core/interaction.py b/packages/gooddata-eval/src/gooddata_eval/core/interaction.py new file mode 100644 index 000000000..2a6e4cbfa --- /dev/null +++ b/packages/gooddata-eval/src/gooddata_eval/core/interaction.py @@ -0,0 +1,57 @@ +# (C) 2026 GoodData Corporation +"""Whether an eval kind sends one chat message per run or drives a whole conversation. + +The distinction decides what a latency figure means. gen-ai starts one trace per chat message +(its session is the conversation), so a single-shot run is exactly one trace and its latency +is that trace's response time, while a multi-turn run spans several traces and has both a +per-trace and a whole-conversation latency. The report keeps the two apart for that reason. + +The classification is by kind, not by how many turns a particular run happened to take: an item +belongs to exactly one section however its runs went. +""" + +from __future__ import annotations + +from typing import Literal + +InteractionMode = Literal["single_shot", "multi_turn"] + +SINGLE_SHOT: InteractionMode = "single_shot" +MULTI_TURN: InteractionMode = "multi_turn" +INTERACTION_MODES: tuple[InteractionMode, ...] = (SINGLE_SHOT, MULTI_TURN) + +# Agentic kinds that still send exactly one chat message per run: no simulated user, no +# follow-up turns. Named explicitly, and checked against the runner's full list in the tests, +# so a new agentic kind cannot be classified by accident. +SINGLE_TURN_AGENTIC_KINDS = frozenset( + { + "agentic_general_question", + "agentic_guardrail", + "agentic_search", + } +) + +# Kinds that drive a simulated user or fixture turns until the agent has produced its output. +MULTI_TURN_KINDS = frozenset( + { + "vis_agentic", + "agentic_visualization", + "agentic_metric_skill", + "agentic_alert_skill", + "agentic_dashboard_skill", + "agentic_document_skill", + "agentic_conversation", + "agentic_kda_skill", + "agentic_anomaly_detection", + "agentic_what_if", + } +) + + +def interaction_mode(test_kind: str) -> InteractionMode: + """Single-shot unless the kind is one of the multi-turn ones. + + Every non-agentic kind sends one chat message (or one summary request), so the default is + the safe side for them. + """ + return MULTI_TURN if test_kind in MULTI_TURN_KINDS else SINGLE_SHOT diff --git a/packages/gooddata-eval/src/gooddata_eval/core/models.py b/packages/gooddata-eval/src/gooddata_eval/core/models.py index 9b2b1c4a7..5bcdd0045 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/models.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/models.py @@ -411,6 +411,7 @@ class AgenticAssertionError(AssertionError): runs_passed: int runs_effective: int failed_runs: list[dict] + run_latencies_s: list[float] class AgenticEvalOutcome(BaseModel): @@ -442,6 +443,11 @@ class AgenticEvalOutcome(BaseModel): # ``core.agentic._failed_runs.build_failed_runs``; mirrors the single-shot path's # ``ItemReport.failed_runs``, which ``core/runner.py`` fills for the non-agentic kinds. failed_runs: list[dict] = Field(default_factory=list) + # The wall-clock seconds of every run, passing or not, in run order. ``timings`` and + # ``best_run_latency_s`` each describe one number per item; the latency distribution + # needs one per run. Empty means the kind recorded none, which the report reads as "no + # sample", not as zero-second runs. + run_latencies_s: list[float] = Field(default_factory=list) class SummaryInput(BaseModel): diff --git a/packages/gooddata-eval/src/gooddata_eval/core/reporting/console.py b/packages/gooddata-eval/src/gooddata_eval/core/reporting/console.py index 31759f7ff..ebf9a09c9 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/reporting/console.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/reporting/console.py @@ -5,7 +5,14 @@ from rich.table import Table from gooddata_eval.core.agentic._gate import gate_label +from gooddata_eval.core.interaction import MULTI_TURN, SINGLE_SHOT from gooddata_eval.core.runner import EvalReport, ItemReport +from gooddata_eval.core.timing import LATENCY_PERCENTILES + +# The side-by-side table compares the median and the tail of the main figure, single-shot +# per-trace latency; each model's own Latency lines and the HTML report carry the full +# P50/P70/P90/P99 set for every population. +COMPARISON_PERCENTILES = (50, 90, 99) def _ungraded_note(item: ItemReport) -> str: @@ -17,6 +24,44 @@ def _ungraded_note(item: ItemReport) -> str: return f"{criteria} criterion(s) ungraded" if criteria else "" +_MODE_LABEL = {SINGLE_SHOT: "single-shot", MULTI_TURN: "multi-turn"} + + +def _latency_line(label: str, stats: dict[str, float]) -> str: + """One line of latency percentiles, naming the population and the sample size they are over. + + Percentiles only, no mean: the Summary line above already carries ``avg .../run``, and a + second average over a different sample would put two near-identical numbers side by side. + """ + percentiles = " · ".join(f"P{p} {stats[f'p{p}']:.2f}s" for p in LATENCY_PERCENTILES) + return f"Latency, {label} (n={stats['n']:.0f}): {percentiles}" + + +def _mode_lines(report: EvalReport) -> list[str]: + """Pass counts per mode, then each mode's latency distributions. + + A mode with no evaluated items is left out, and so is a distribution nothing was timed + for. Per trace is the main figure: a single-shot run is exactly one trace, so its + percentiles are the response time of one chat turn, while a multi-turn run spans several + traces and also gets a whole-conversation figure. + """ + by_mode = report.by_mode + present = [mode for mode in (SINGLE_SHOT, MULTI_TURN) if by_mode[mode]["total"]] + if not present: + return [] + lines = [ + "By mode: " + + " · ".join(f"{_MODE_LABEL[m]} {by_mode[m]['passed']}/{by_mode[m]['total']} passed" for m in present) + ] + for mode in present: + entry = by_mode[mode] + if entry["traces_s"]: + lines.append(_latency_line(f"{_MODE_LABEL[mode]} per trace", entry["traces_s"])) + if entry.get("runs_s"): + lines.append(_latency_line(f"{_MODE_LABEL[mode]} per full run", entry["runs_s"])) + return lines + + def render_console(report: EvalReport, *, console: Console | None = None) -> str: """Render the report to the console and return the rendered text. @@ -89,6 +134,8 @@ def render_console(report: EvalReport, *, console: Console | None = None) -> str f"({report.skipped} skipped, {report.errored} errored) " f"avg quality {report.avg_quality_score:.0%} in {timing}" ) + for line in _mode_lines(report): + out.print(line) return out.export_text() if out.record else "" @@ -109,21 +156,26 @@ def render_comparison(reports: list[EvalReport], *, console: Console | None = No table.add_column("Passed") table.add_column("Quality") table.add_column("Avg/run") + for p in COMPARISON_PERCENTILES: + table.add_column(f"Trace P{p}") table.add_column("Total time") for r in reports: evaluated = r.total - r.skipped pass_pct = f"{r.passed / evaluated:.0%}" if evaluated else "—" model_label = f"{r.provider_name}/{r.model}" if r.provider_name else r.model or "?" + stats = r.by_mode[SINGLE_SHOT]["traces_s"] table.add_row( model_label, f"{r.passed}/{r.total} ({pass_pct})", f"{r.avg_quality_score:.0%}", f"{r.avg_latency_s:.2f}s", + *(f"{stats[f'p{p}']:.2f}s" if stats else "—" for p in COMPARISON_PERCENTILES), f"{r.latency_s:.0f}s", ) out.print(table) + out.print("Trace P50/P90/P99: single-shot chat-turn response time, one trace per run.") evaluated_reports = [r for r in reports if r.total > 0] if evaluated_reports: diff --git a/packages/gooddata-eval/src/gooddata_eval/core/reporting/json_report.py b/packages/gooddata-eval/src/gooddata_eval/core/reporting/json_report.py index 55d922864..5c35e1043 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/reporting/json_report.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/reporting/json_report.py @@ -29,11 +29,21 @@ def _build_run_dict(report: EvalReport) -> dict: "latency_s": round(report.latency_s, 3), "avg_latency_s": round(report.avg_latency_s, 3), "wall_clock_s": round(report.wall_clock_s, 3), + # When the run began, ISO 8601 in UTC; null when it was never timed. The HTML report shows it as the + # Run date and orders runs by it. + "started_at": report.started_at.isoformat() if report.started_at else None, + # Pass counts and latency distributions split by single-shot and multi-turn: + # avg_latency_s above is one number over a mixed population and says nothing about + # its tail. Each distribution is None when nothing was timed, so a report cannot + # state a 0s P99 for a run that measured nothing. + "by_mode": report.by_mode, }, "items": { item.id: { "dataset_name": item.dataset_name, "test_kind": item.test_kind, + # Which section of the report the item belongs to, by its kind. + "mode": item.interaction_mode, "question": item.question, # Both, because under --gate power they differ: pass_at_k stays literal # (any run passed) and matches the Langfuse score of that name, while @@ -47,6 +57,12 @@ def _build_run_dict(report: EvalReport) -> dict: "runs": item.runs_total, "latency_s": round(item.latency_s, 3), "avg_latency_s": round(item.avg_latency_s, 3), + # One entry per run that completed, passing or not: the sample behind the + # multi-turn per-run percentiles. latency_s is only their sum. + "run_latencies_s": [round(latency, 3) for latency in item.run_latencies_s], + # One entry per completed chat turn (one gen-ai trace each): the sample behind + # the per-trace percentiles, and for a single-shot item one per run. + "trace_latencies_s": [round(latency, 3) for latency in item.trace_latencies_s], # Beside `runs`, not folded into it: "4 of 5 passed" is a different fact # from pass_at_k and the only one that separates a reliable item from a # coin-flip. pass_power_k is the unanimity flag beside it, and @@ -93,6 +109,7 @@ def _build_comparison_entry(report: EvalReport) -> dict: "avg_quality_score": round(report.avg_quality_score, 4), "avg_latency_s": round(report.avg_latency_s, 3), "total_latency_s": round(report.latency_s, 3), + "by_mode": report.by_mode, } diff --git a/packages/gooddata-eval/src/gooddata_eval/core/reporting/report_template.html b/packages/gooddata-eval/src/gooddata_eval/core/reporting/report_template.html index 209124775..6b6bb9998 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/reporting/report_template.html +++ b/packages/gooddata-eval/src/gooddata_eval/core/reporting/report_template.html @@ -3,126 +3,366 @@ - -gd-eval report + +GoodData.AI evaluation report -
+
+
GoodData.AI · Evaluation report

-
-
-
-

Items

-
- - - + + - - - +
-
- expression vars: d detail of focused run · it focused run's item · i row (i.per[label]) · q question · kind +
+ Filter the report + + +
+
+ +
+
+ + + +
+
+

Test cases

+

These filters narrow the table only, inside whatever the filters at the top allow.

+
+ + + + +
+
Advanced: filter by a check expression + +
+ expression vars: d checks of the run being read · it that run's result · i row (i.per[label]) · q question · kind category id. A test case matches when any shown run does. +
+
@@ -132,75 +372,771 @@

Items

diff --git a/packages/gooddata-eval/src/gooddata_eval/core/runner.py b/packages/gooddata-eval/src/gooddata_eval/core/runner.py index 7e62dc499..1ea91ec68 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/runner.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/runner.py @@ -5,13 +5,16 @@ import traceback from concurrent.futures import ThreadPoolExecutor, as_completed from dataclasses import dataclass, field -from functools import partial +from datetime import datetime, timezone +from functools import cached_property, partial from typing import Callable, Protocol from gooddata_eval.core.config import DEFAULT_GATE, EvalGate from gooddata_eval.core.evaluators import get_evaluator, supported_test_kinds from gooddata_eval.core.evaluators.base import ItemEvaluation +from gooddata_eval.core.interaction import INTERACTION_MODES, MULTI_TURN, InteractionMode, interaction_mode from gooddata_eval.core.models import ChatResult, DatasetItem +from gooddata_eval.core.timing import latency_stats class ChatBackend(Protocol): @@ -57,6 +60,19 @@ class ItemReport: # ends up describing the LAST one, which is not necessarily the run best_detail is # about, so those ids cannot be used to pull the trace for a specific failure. failed_runs: list[dict] = field(default_factory=list) + # The wall-clock seconds of every run that completed, in run order -- passing runs too, + # which `failed_runs` deliberately leaves out. `latency_s` is only their sum, so the + # distribution (P50, P90, P99) cannot be recovered from it. A run that raised was never + # timed and has no entry, exactly as it adds nothing to `runs`. + run_latencies_s: list[float] = field(default_factory=list) + # The response time of every chat turn the item completed, in order -- one gen-ai trace + # each, timed from sending the message to the end of its stream. For a single-shot item that + # is one value per run; a multi-turn run contributes one per turn. Unlike `run_latencies_s` + # it holds none of the judge, simulated-user or conversation set-up time. A turn that ended in + # a ChatError carrying a partial result has an entry, because evaluators score that result as a + # run; so does a turn whose scoring raised afterwards. An item that errored outside the + # evaluator's own failure reporting has none: it reports no runs for them to sit beside. + trace_latencies_s: list[float] = field(default_factory=list) # Per-phase breakdown of what the item's time was spent on. Additive to latency_s, # which remains the item's own critical path. langfuse_latency_s is # deliberately NOT part of that path -- trace linking runs off it (see @@ -80,6 +96,11 @@ class ItemReport: # trusting K there reports four runs that never happened. runs_effective: int | None = None + @property + def interaction_mode(self) -> InteractionMode: + """Single-shot or multi-turn, by the item's kind: which latency section it belongs to.""" + return interaction_mode(self.test_kind) + @property def passed(self) -> bool: """Whether the item counts as a pass: the gate's verdict where one ran, else pass@K. @@ -135,6 +156,8 @@ class EvalReport: gate: EvalGate = DEFAULT_GATE items: list[ItemReport] = field(default_factory=list) wall_clock_s: float = 0.0 # actual elapsed time; differs from latency_s under concurrency + # When the run began (UTC). The HTML report orders runs by it, so the file order does not decide which is latest. + started_at: datetime | None = None @property def total(self) -> int: @@ -182,6 +205,34 @@ def avg_quality_score(self) -> float: evaluated = [i.quality_score for i in self.items if not i.skipped and i.error is None] return sum(evaluated) / len(evaluated) if evaluated else 0.0 + @cached_property + def by_mode(self) -> dict[str, dict]: + """How the run did on its single-shot and on its multi-turn items, with latency for each. + + Computed on first read and kept: the console, the comparison and both JSON builders all + read it, and each read would otherwise sort every latency sample again. Read it once the + report is complete -- items added afterwards are not reflected. + + ``total`` and ``passed`` count the evaluated items of that mode (skipped ones belong to + neither). ``traces_s`` is the distribution of per-trace chat-turn response times; a + single-shot run is one trace, so for that mode it is also the per-run latency. A + multi-turn conversation spans several traces, so that mode also carries ``runs_s``: the + whole-conversation wall clock per run, judge and simulated user included. Each is None + when nothing was timed. + """ + out: dict[str, dict] = {} + for mode in INTERACTION_MODES: + items = [i for i in self.items if i.interaction_mode == mode and not i.skipped] + entry: dict = { + "total": len(items), + "passed": sum(1 for i in items if i.passed), + "traces_s": latency_stats(t for i in items for t in i.trace_latencies_s), + } + if mode == MULTI_TURN: + entry["runs_s"] = latency_stats(t for i in items for t in i.run_latencies_s) + out[mode] = entry + return out + # A per-run progress callback: (run_index, runs_total, passed, latency_s) -> None RunCallback = Callable[[int, int, bool, float], None] @@ -234,12 +285,16 @@ def _run_one_item( for run_index in range(1, runs + 1): t0 = time.perf_counter() chat_result = backend.ask(item) + trace_latency = getattr(chat_result, "turn_wall_clock_sec", None) + if isinstance(trace_latency, (int, float)): + report.trace_latencies_s.append(trace_latency) report.conversation_id = getattr(chat_result, "conversation_id", None) or report.conversation_id report.response_id = getattr(chat_result, "response_id", None) or report.response_id evaluation = evaluator.evaluate(item, chat_result) latency = time.perf_counter() - t0 report.runs += 1 report.latency_s += latency + report.run_latencies_s.append(latency) if evaluation.error is not None: report.runs_ungraded += 1 judge_errors.append(evaluation.error) @@ -345,6 +400,7 @@ def _process_item(index: int, item: DatasetItem) -> ItemReport: traceback.print_exc() return item_report + report.started_at = datetime.now(timezone.utc) _t0 = time.perf_counter() if concurrency <= 1: for index, item in enumerate(items, start=1): diff --git a/packages/gooddata-eval/src/gooddata_eval/core/summary/http_client.py b/packages/gooddata-eval/src/gooddata_eval/core/summary/http_client.py index bab285e04..9d9283d48 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/summary/http_client.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/summary/http_client.py @@ -13,9 +13,12 @@ If the route is ever renamed (e.g. to ``/summarize``), change ``_PATH`` only. """ +import time + import httpx from gooddata_eval.core.models import ChatResult, DatasetItem +from gooddata_eval.core.timing import note_trace_latency _PATH = "/api/v1/ai/workspaces/{workspace_id}/summary" @@ -44,11 +47,18 @@ def ask(self, item: DatasetItem) -> ChatResult: if si.format_hint is not None: body["formatHint"] = si.format_hint + started = time.monotonic() resp = self._client.post(self._url, json=body, headers={**self._auth, "Content-Type": "application/json"}) resp.raise_for_status() data = resp.json() + elapsed = time.monotonic() - started summary = data.get("summary") or "" - return ChatResult.model_validate({"textResponse": summary}) + result = ChatResult.model_validate({"textResponse": summary}) + # The request is this item's one trace, timed like a chat turn so the single-shot latency + # covers dashboard_summary on the same footing. + result.turn_wall_clock_sec = elapsed + note_trace_latency(elapsed) + return result def close(self) -> None: self._client.close() diff --git a/packages/gooddata-eval/src/gooddata_eval/core/timing.py b/packages/gooddata-eval/src/gooddata_eval/core/timing.py index a3c05aef1..b2d203d7b 100644 --- a/packages/gooddata-eval/src/gooddata_eval/core/timing.py +++ b/packages/gooddata-eval/src/gooddata_eval/core/timing.py @@ -8,6 +8,9 @@ from __future__ import annotations +import math +from collections.abc import Iterable, Sequence +from contextvars import ContextVar, Token from dataclasses import dataclass from gooddata_eval.core._output import emit_line @@ -72,3 +75,110 @@ def as_dict(self) -> dict[str, float]: def sum_timings(timings: list[PhaseTimings]) -> PhaseTimings: """Total across a list of per-run timings (empty list -> all zeroes).""" return sum(timings, PhaseTimings()) + + +# The percentiles every report states. P50 is the median, so it is the only "median" the +# report carries -- a second field would only repeat it. +LATENCY_PERCENTILES = (50, 70, 90, 99) + + +def percentile(sorted_samples: Sequence[float], p: float) -> float: + """The ``p``-th percentile of an ascending sample, by linear interpolation. + + Linear interpolation between closest ranks (``statistics.quantiles(method="inclusive")``, + NumPy's default), so ``percentile(xs, 50)`` equals ``statistics.median(xs)`` for any + sample. Unlike ``statistics.quantiles`` it is defined for a single sample. On a small + sample the high percentiles sit at or near the maximum -- they cannot report a latency + nobody observed beyond the slowest run. + """ + if not sorted_samples: + raise ValueError("percentile of an empty sample") + rank = (len(sorted_samples) - 1) * p / 100 + lower = math.floor(rank) + upper = min(lower + 1, len(sorted_samples) - 1) + return sorted_samples[lower] + (sorted_samples[upper] - sorted_samples[lower]) * (rank - lower) + + +# Share of the sample dropped from EACH end before the trimmed mean: 10% leaves the middle 80%. +TRIM_PERCENT = 10 + + +def trimmed_mean(sorted_samples: Sequence[float], percent: int = TRIM_PERCENT) -> float | None: + """Mean of what is left after dropping the fastest and slowest ``percent`` % of the sample. + + Not the median: the median is one middle value (P50), this still averages, but without the + outliers at either end. ``None`` when the sample is too small to drop at least one value + from each end (fewer than ``100 / percent`` samples) -- the figure would silently be the + plain mean. The cut is ``n * percent // 100`` from each end, so 25 samples drop two each. + """ + if not sorted_samples: + raise ValueError("trimmed mean of an empty sample") + drop = len(sorted_samples) * percent // 100 + if drop == 0: + return None + kept = sorted_samples[drop : len(sorted_samples) - drop] + return sum(kept) / len(kept) + + +def latency_stats(samples: Iterable[float]) -> dict[str, float | None] | None: + """Distribution of per-run latencies in seconds, or ``None`` when there are none. + + ``n`` is the number of runs the figures are over: the percentiles are only as sharp as + that sample, and a reader needs it to judge how far to trust P99. ``trimmed_mean`` is + ``None`` until there are enough samples to trim. + """ + ordered = sorted(samples) + if not ordered: + return None + trimmed = trimmed_mean(ordered) + return { + "n": len(ordered), + "mean": round(sum(ordered) / len(ordered), 3), + "trimmed_mean": round(trimmed, 3) if trimmed is not None else None, + "min": round(ordered[0], 3), + **{f"p{p}": round(percentile(ordered, p), 3) for p in LATENCY_PERCENTILES}, + "max": round(ordered[-1], 3), + } + + +# The response time of every chat turn the current item completed, in order. gen-ai opens one +# trace per chat message, so these are per-trace latencies: the time from sending the message +# to the end of its stream, with none of the judge, simulated-user or conversation set-up time +# that a whole-run figure carries. `ChatClient.send_message` is the only writer; recording it +# there means no evaluator has to remember to, and a new one is covered without an edit. +_trace_latencies: ContextVar[list[float] | None] = ContextVar("gd_eval_trace_latencies", default=None) + + +class TraceRecorder: + """Collects the per-trace latencies of whatever runs between ``__init__`` and ``stop``. + + Scoped to the calling thread's context, so items evaluated concurrently each get their own + list. Create it where the item starts and call ``stop`` in a ``finally``. + """ + + def __init__(self) -> None: + self.latencies: list[float] = [] + self._token: Token[list[float] | None] | None = _trace_latencies.set(self.latencies) + + def stop(self) -> list[float]: + """Detach from the context and return what was recorded. Safe to call twice.""" + if self._token is not None: + _trace_latencies.reset(self._token) + self._token = None + return self.latencies + + def discard(self) -> None: + """Detach and drop what was recorded, for an item whose turns have no scored run to sit beside.""" + self.stop() + self.latencies.clear() + + +def note_trace_latency(seconds: float | None) -> None: + """Record one completed chat turn on the active recorder, if there is one. + + A no-op without a recorder (a library caller, or a test) and for a turn that carries no + timing, so the caller never has to check either. + """ + sink = _trace_latencies.get() + if sink is not None and seconds is not None: + sink.append(seconds) diff --git a/packages/gooddata-eval/tests/test_agentic_alert_skill.py b/packages/gooddata-eval/tests/test_agentic_alert_skill.py index ef1fa33c4..ea3aa59a1 100644 --- a/packages/gooddata-eval/tests/test_agentic_alert_skill.py +++ b/packages/gooddata-eval/tests/test_agentic_alert_skill.py @@ -895,6 +895,8 @@ def test_evaluate_agentic_alert_skill_returns_reasoning_steps_on_pass(): "latency_breakdown": [], "tool_calls": [], } + assert len(outcome.run_latencies_s) == outcome.runs_effective == 1 + assert all(latency >= 0 for latency in outcome.run_latencies_s) def test_evaluate_agentic_alert_skill_attaches_reasoning_steps_to_exception_on_fail(): @@ -941,6 +943,7 @@ def test_evaluate_agentic_alert_skill_attaches_reasoning_steps_to_exception_on_f "latency_breakdown": [], "tool_calls": [], } + assert len(exc_info.value.run_latencies_s) == exc_info.value.runs_effective == 1 # --- attributes: a date narrows an alert as a group-by too ---------------------------------- diff --git a/packages/gooddata-eval/tests/test_agentic_anomaly_detection.py b/packages/gooddata-eval/tests/test_agentic_anomaly_detection.py index 84621d158..d7fef2965 100644 --- a/packages/gooddata-eval/tests/test_agentic_anomaly_detection.py +++ b/packages/gooddata-eval/tests/test_agentic_anomaly_detection.py @@ -319,6 +319,8 @@ def test_detail_reports_the_series_analysed_and_the_flag_count(): assert outcome.detail["asserted"] == ["metric", "granularity"] assert "latency_breakdown" in outcome.detail assert outcome.runs_passed == 1 + assert len(outcome.run_latencies_s) == outcome.runs_effective == 1 + assert all(latency >= 0 for latency in outcome.run_latencies_s) def test_the_wrong_series_raises_naming_what_was_analysed(): @@ -330,6 +332,7 @@ def test_the_wrong_series_raises_naming_what_was_analysed(): assert "DAY" in str(error) assert error.runs_passed == 0 assert error.conversation_id == "conv-1" + assert len(error.run_latencies_s) == error.runs_effective == 1 def test_a_chart_built_on_an_earlier_turn_is_still_the_one_scored(): diff --git a/packages/gooddata-eval/tests/test_agentic_conversation.py b/packages/gooddata-eval/tests/test_agentic_conversation.py index 4b66e5e9d..76f6b6baa 100644 --- a/packages/gooddata-eval/tests/test_agentic_conversation.py +++ b/packages/gooddata-eval/tests/test_agentic_conversation.py @@ -973,6 +973,8 @@ def test_evaluate_agentic_conversation_returns_reasoning_steps_on_pass(): assert outcome.reasoning_steps == ["thinking about it"] assert outcome.conversation_id == "conv-1" assert outcome.response_id == "resp-1" + assert len(outcome.run_latencies_s) == outcome.runs_effective == 1 + assert all(latency >= 0 for latency in outcome.run_latencies_s) assert outcome.detail == { "mode": "legacy", "full_skill_coverage": True, @@ -1054,6 +1056,7 @@ def test_evaluate_agentic_conversation_attaches_reasoning_steps_to_exception_on_ assert exc_info.value.reasoning_steps == ["confused thinking"] assert exc_info.value.conversation_id == "conv-1" assert exc_info.value.response_id == "resp-2" + assert len(exc_info.value.run_latencies_s) == exc_info.value.runs_effective == 1 assert exc_info.value.detail == { "mode": "legacy", "full_skill_coverage": False, diff --git a/packages/gooddata-eval/tests/test_agentic_dashboard_skill.py b/packages/gooddata-eval/tests/test_agentic_dashboard_skill.py index b7101ef37..80aa96692 100644 --- a/packages/gooddata-eval/tests/test_agentic_dashboard_skill.py +++ b/packages/gooddata-eval/tests/test_agentic_dashboard_skill.py @@ -1891,6 +1891,7 @@ def test_a_failing_run_raises_with_the_failures_attached(self): assert "the agent never produced a successful draft_dashboard call" in message assert excinfo.value.detail["dashboard_drafted"] is False assert excinfo.value.conversation_id == "conv-1" + assert len(excinfo.value.run_latencies_s) == excinfo.value.runs_effective == 1 def test_a_mis_routed_edit_names_the_skill_the_fixture_asked_for(self): """The builder answering an edit activates dashboard_builder perfectly well. Naming it @@ -1940,6 +1941,8 @@ def test_a_passing_run_returns_the_outcome(self): assert outcome.runs_passed == 1 assert outcome.runs_effective == 1 assert outcome.detail["charts_matched"] is True + assert len(outcome.run_latencies_s) == outcome.runs_effective + assert all(latency >= 0 for latency in outcome.run_latencies_s) def _as_events(raw: list[dict]) -> list[ToolCallEvent]: diff --git a/packages/gooddata-eval/tests/test_agentic_document_skill.py b/packages/gooddata-eval/tests/test_agentic_document_skill.py index 49e905bb1..9defdcb64 100644 --- a/packages/gooddata-eval/tests/test_agentic_document_skill.py +++ b/packages/gooddata-eval/tests/test_agentic_document_skill.py @@ -653,6 +653,8 @@ def test_a_passing_item_returns_its_checks_and_draft_facts(monkeypatch: pytest.M assert outcome.detail["document_period_correct"] is True assert outcome.detail["summaries_from_data"] == 1 assert outcome.detail["failures"] == [] + assert len(outcome.run_latencies_s) == outcome.runs_effective == 1 + assert all(latency >= 0 for latency in outcome.run_latencies_s) def test_a_failing_item_raises_with_the_failures(monkeypatch: pytest.MonkeyPatch) -> None: @@ -662,6 +664,7 @@ def test_a_failing_item_raises_with_the_failures(monkeypatch: pytest.MonkeyPatch assert "the agent never produced a successful draft_document call" in str(raised.value) assert raised.value.runs_passed == 0 assert raised.value.conversation_id == "conv-1" + assert len(raised.value.run_latencies_s) == raised.value.runs_effective == 1 def test_a_failing_item_without_document_builder_points_at_the_flags(monkeypatch: pytest.MonkeyPatch) -> None: @@ -1008,8 +1011,9 @@ def test_an_item_the_judge_could_never_grade_raises(monkeypatch: pytest.MonkeyPa turn = _narrative_turn(_cover_page(), _summary_page("page2", "Revenue grew 12%.", _REVENUE_TREND)) _install_client(monkeypatch, _ScriptedChatClient([turn])) judge = _FakeJudge(error=JudgeResponseError("empty body")) - with pytest.raises(JudgeResponseError, match="no readable verdict"): + with pytest.raises(JudgeResponseError, match="no readable verdict") as raised: evaluate_agentic_document_skill("https://h", "tok", "ws", "q", {"narrative": _NARRATIVE}, judge=judge) + assert len(raised.value.run_latencies_s) == 1 def test_a_narrative_item_passes_with_its_verdict_in_the_detail(monkeypatch: pytest.MonkeyPatch) -> None: diff --git a/packages/gooddata-eval/tests/test_agentic_general_question.py b/packages/gooddata-eval/tests/test_agentic_general_question.py index 99dc982cb..cdfc683b8 100644 --- a/packages/gooddata-eval/tests/test_agentic_general_question.py +++ b/packages/gooddata-eval/tests/test_agentic_general_question.py @@ -258,6 +258,10 @@ def test_evaluate_agentic_general_question_returns_reasoning_steps_on_pass(): "actual_output": "42", "latency_breakdown": [], } + # One wall-clock sample per run, passing runs included -- the latency distribution is over + # these, and a kind that forgot to report them would silently drop out of it. + assert len(outcome.run_latencies_s) == outcome.runs_effective == 1 + assert all(latency >= 0 for latency in outcome.run_latencies_s) def test_evaluate_agentic_general_question_attaches_reasoning_steps_to_exception_on_fail(): @@ -285,6 +289,7 @@ def test_evaluate_agentic_general_question_attaches_reasoning_steps_to_exception "actual_output": "I don't know", "latency_breakdown": [], } + assert len(exc_info.value.run_latencies_s) == exc_info.value.runs_effective == 1 def test_evaluate_general_question_defers_langfuse_work_to_the_injected_linker(): @@ -400,6 +405,8 @@ def test_evaluate_general_question_aggregates_timings_across_k_runs(): assert outcome.timings.agent_s == 5.0 # 2.0 + 3.0 assert outcome.timings.judge_s == 1.5 # 1.0 + 0.5 + # Each run's own span, agent and judge both inside it -- not their sum across runs. + assert outcome.run_latencies_s == [3.0, 3.5] def test_evaluate_general_question_attaches_timings_to_the_failure_exception(): @@ -718,3 +725,4 @@ def test_an_item_with_no_gradeable_run_raises_instead_of_reporting_failures(): assert [r["run_index"] for r in err.value.failed_runs] == [1, 2] assert [r["error"] for r in err.value.failed_runs] == ["empty body twice", "no 'score' key"] assert (err.value.runs_passed, err.value.runs_effective) == (0, 2) + assert len(err.value.run_latencies_s) == err.value.runs_effective diff --git a/packages/gooddata-eval/tests/test_agentic_guardrail.py b/packages/gooddata-eval/tests/test_agentic_guardrail.py index dafad8a40..6686353e1 100644 --- a/packages/gooddata-eval/tests/test_agentic_guardrail.py +++ b/packages/gooddata-eval/tests/test_agentic_guardrail.py @@ -157,6 +157,10 @@ def test_evaluate_agentic_guardrail_returns_reasoning_steps_on_pass(): "latency_breakdown": [], "tool_calls": [], } + # One wall-clock sample per run, passing runs included -- the latency distribution is over + # these, and a kind that forgot to report them would silently drop out of it. + assert len(outcome.run_latencies_s) == outcome.runs_effective == 1 + assert all(latency >= 0 for latency in outcome.run_latencies_s) def test_evaluate_agentic_guardrail_attaches_reasoning_steps_to_exception_on_fail(): @@ -187,6 +191,7 @@ def test_evaluate_agentic_guardrail_attaches_reasoning_steps_to_exception_on_fai "latency_breakdown": [], "tool_calls": [], } + assert len(exc_info.value.run_latencies_s) == exc_info.value.runs_effective == 1 # --- the run counts have to reach the report (same predicate pass_at_k uses) --- @@ -354,3 +359,4 @@ def test_all_ungraded_attaches_the_records_to_the_judge_error(): assert [r["conversation_id"] for r in err.failed_runs] == ["conv-1", "conv-2"] assert [r["detail"]["actual_output"] for r in err.failed_runs] == ["answer conv-1", "answer conv-2"] assert (err.runs_passed, err.runs_effective) == (0, 2) + assert len(err.run_latencies_s) == err.runs_effective diff --git a/packages/gooddata-eval/tests/test_agentic_kda_skill.py b/packages/gooddata-eval/tests/test_agentic_kda_skill.py index 573a2a267..07f8bcb64 100644 --- a/packages/gooddata-eval/tests/test_agentic_kda_skill.py +++ b/packages/gooddata-eval/tests/test_agentic_kda_skill.py @@ -1135,6 +1135,8 @@ def test_evaluate_agentic_kda_skill_returns_reasoning_steps_on_pass(): "max_iterations": 1, "latency_breakdown": [], } + assert len(outcome.run_latencies_s) == outcome.runs_effective == 1 + assert all(latency >= 0 for latency in outcome.run_latencies_s) def test_evaluate_agentic_kda_skill_attaches_reasoning_steps_to_exception_on_fail(): @@ -1173,6 +1175,7 @@ def test_evaluate_agentic_kda_skill_attaches_reasoning_steps_to_exception_on_fai "max_iterations": 1, "latency_breakdown": [], } + assert len(exc_info.value.run_latencies_s) == exc_info.value.runs_effective == 1 def test_evaluate_agentic_kda_skill_preserves_reasoning_from_a_chat_error_partial_result(): diff --git a/packages/gooddata-eval/tests/test_agentic_metric_skill.py b/packages/gooddata-eval/tests/test_agentic_metric_skill.py index 37e23f3e2..65f23a39f 100644 --- a/packages/gooddata-eval/tests/test_agentic_metric_skill.py +++ b/packages/gooddata-eval/tests/test_agentic_metric_skill.py @@ -28,16 +28,17 @@ # --- time.monotonic() side effects --------------------------------------------------- # -# metric_skill reads the clock twice per agent turn (start, stop) and twice more per -# simulated-user reply, so a two-turn conversation needs six values. Named rather than +# metric_skill reads the clock twice per agent turn (start, stop), twice more per +# simulated-user reply, and twice per run (start before the first turn, stop after scoring), +# so a two-turn conversation needs eight values. Named rather than # inlined because a single new clock read on the production path breaks every one of these # at once with StopIteration -- and repairing a bare literal means hand-counting clock # reads at each call site. # one turn, metric created straight away: agent 3.0s, no simulated user -_CLOCK_ONE_TURN = [5.0, 8.0] +_CLOCK_ONE_TURN = [5.0, 5.0, 8.0, 8.0] # two turns: agent 1.0s then 0.5s, with a 2.5s simulated-user reply between them -_CLOCK_TWO_TURNS = [20.0, 21.0, 21.0, 23.5, 23.5, 24.0] +_CLOCK_TWO_TURNS = [20.0, 20.0, 21.0, 21.0, 23.5, 23.5, 24.0, 24.0] def _client() -> MagicMock: @@ -726,6 +727,10 @@ def test_evaluate_agentic_metric_skill_returns_reasoning_steps_on_pass(): "latency_breakdown": [], "tool_calls": [], } + # One wall-clock sample per run, passing runs included -- the latency distribution is over + # these, and a kind that forgot to report them would silently drop out of it. + assert len(outcome.run_latencies_s) == outcome.runs_effective == 1 + assert all(latency >= 0 for latency in outcome.run_latencies_s) def test_evaluate_agentic_metric_skill_attaches_reasoning_steps_to_exception_on_fail(): @@ -761,6 +766,7 @@ def test_evaluate_agentic_metric_skill_attaches_reasoning_steps_to_exception_on_ } assert exc_info.value.conversation_id == "conv-1" assert exc_info.value.response_id is None + assert len(exc_info.value.run_latencies_s) == exc_info.value.runs_effective == 1 def test_records_agent_and_simulated_user_latency_separately(): @@ -791,6 +797,8 @@ def test_records_agent_and_simulated_user_latency_separately(): # metric_skill has no judge; conflating its simulated user with one would misreport # a blocking call as a deferrable one. assert timings.judge_s == 0.0 + # The run's wall time spans both turns and the simulated-user reply between them. + assert summary.run_results[0].run_latency_s == 4.0 def test_evaluate_metric_skill_surfaces_timings_on_the_outcome(): diff --git a/packages/gooddata-eval/tests/test_agentic_runner.py b/packages/gooddata-eval/tests/test_agentic_runner.py index 3ccd72230..56d33d5a4 100644 --- a/packages/gooddata-eval/tests/test_agentic_runner.py +++ b/packages/gooddata-eval/tests/test_agentic_runner.py @@ -23,7 +23,7 @@ from gooddata_eval.core.evaluators._llm_judge import JudgeResponseError from gooddata_eval.core.langfuse.item_scope import ItemTraceScope, current_scope from gooddata_eval.core.models import AgenticEvalOutcome, CreatedVisualization, DatasetItem -from gooddata_eval.core.timing import PhaseTimings +from gooddata_eval.core.timing import PhaseTimings, note_trace_latency def test_dispatch_agentic_passes_agent_id_through_to_alert_skill(): @@ -328,6 +328,8 @@ def test_run_agentic_items_records_phase_timings_and_wall_clock(): item = report.items[0] assert (item.agent_latency_s, item.judge_latency_s, item.simulated_user_latency_s) == (2.0, 1.0, 0.5) assert report.wall_clock_s > 0.0 + assert report.started_at is not None + assert report.started_at.tzinfo is not None def test_run_agentic_items_records_phase_timings_when_the_item_fails(): @@ -1062,3 +1064,152 @@ def run(*_args: Any, **_kwargs: Any) -> None: getattr(module, evaluate_fn)("https://h", "tok", "ws1", *args) assert seen == [scope] + + +@pytest.mark.parametrize(("kind", "expected_output", "target"), _ALL_AGENTIC_KIND_CASES) +def test_every_evaluator_hands_out_its_run_latencies(kind, expected_output, target): + """Structural, for the reason the failed_runs check above is: the report test below cans + the outcome and cannot see whether an evaluator filled it. A kind that stops handing out + its per-run times does not fail anything -- it just drops out of the latency percentiles, + quietly, because an empty list reads as "not timed".""" + module = importlib.import_module(getattr(agentic_runner, target).__module__) + source = inspect.getsource(module) + assert "run_latencies_s=" in source, f"{module.__name__} never returns its run latencies on the success path" + assert ".run_latencies_s = " in source, f"{module.__name__} never attaches them to its failure" + + +@pytest.mark.parametrize(("kind", "expected_output", "target"), _ALL_AGENTIC_KIND_CASES) +def test_run_latencies_reach_the_report_for_every_kind(kind, expected_output, target): + item = DatasetItem(id="q1", dataset_name="ds", test_kind=kind, question="q", expected_output=expected_output) + canned = AgenticEvalOutcome(reasoning_steps=["x"], detail={"k": "v"}, run_latencies_s=[4.5, 6.0]) + with patch(f"gooddata_eval.cli.agentic_runner.{target}", return_value=canned): + report = run_agentic_items([item], host="http://host", token="tok", workspace_id="ws1", run_ts="2026-01-01") + assert report.items[0].run_latencies_s == [4.5, 6.0] + + +def test_a_kind_that_records_no_run_latencies_adds_no_sample(): + """Absent, not zero: an empty list means "not timed", so the item cannot pull the + percentiles toward 0s.""" + with patch( + "gooddata_eval.cli.agentic_runner.evaluate_agentic_alert_skill", + return_value=AgenticEvalOutcome(reasoning_steps=[], detail={}), + ): + report = run_agentic_items([_item()], host="http://host", token="tok", workspace_id="ws1", run_ts="2026-01-01") + assert report.items[0].run_latencies_s == [] + assert report.by_mode["multi_turn"]["runs_s"] is None + + +def test_run_latencies_are_surfaced_from_the_exception_on_a_failed_item(): + exc = AlertSkillAssertionError("nope") + exc.reasoning_steps = [] + exc.detail = {"alert_created": False} + exc.run_latencies_s = [3.0, 5.0] + with patch("gooddata_eval.cli.agentic_runner.evaluate_agentic_alert_skill", side_effect=exc): + report = run_agentic_items([_item()], host="http://host", token="tok", workspace_id="ws1", run_ts="2026-01-01") + assert report.items[0].run_latencies_s == [3.0, 5.0] + + +def test_an_all_ungraded_item_still_reports_what_its_runs_cost(): + """The runs happened and took real time even though no verdict came back, so they belong + in the latency sample -- a broken judge must not make the agent look faster.""" + err = JudgeResponseError("judge returned no readable verdict for any of the 2 run(s)") + err.runs_effective = 2 + err.run_latencies_s = [7.0, 9.5] + with patch("gooddata_eval.cli.agentic_runner.evaluate_agentic_alert_skill", side_effect=err): + report = run_agentic_items( + [_item()], host="http://host", token="tok", workspace_id="ws1", run_ts="2026-01-01", k=2 + ) + item = report.items[0] + assert item.error is not None + assert item.run_latencies_s == [7.0, 9.5] + + +# --- per-trace latency: collected from the chat client, not handed out by each evaluator --- + + +def _noting(*latencies: float, then: Any = None): + """A stand-in evaluator that completes the given chat turns, as ChatClient.send_message would.""" + + def evaluate(*args: Any, **kwargs: Any) -> Any: + for latency in latencies: + note_trace_latency(latency) + if isinstance(then, BaseException): + raise then + return then if then is not None else AgenticEvalOutcome(reasoning_steps=[], detail={}) + + return evaluate + + +@pytest.mark.parametrize(("kind", "expected_output", "target"), _ALL_AGENTIC_KIND_CASES) +def test_every_kind_gets_its_chat_turns_recorded_as_trace_latencies(kind, expected_output, target): + """The recorder wraps the item, so a kind needs no code of its own to be covered -- which is + the point: nothing a new evaluator forgets can drop it out of the per-trace percentiles.""" + item = DatasetItem(id="q1", dataset_name="ds", test_kind=kind, question="q", expected_output=expected_output) + with patch(f"gooddata_eval.cli.agentic_runner.{target}", side_effect=_noting(1.5, 2.5, 0.5)): + report = run_agentic_items([item], host="http://host", token="tok", workspace_id="ws1", run_ts="2026-01-01") + assert report.items[0].trace_latencies_s == [1.5, 2.5, 0.5] + + +def test_turns_completed_before_a_failed_gate_still_count_as_traces(): + exc = AlertSkillAssertionError("nope") + exc.reasoning_steps = [] + exc.detail = {} + with patch( + "gooddata_eval.cli.agentic_runner.evaluate_agentic_alert_skill", side_effect=_noting(3.0, 4.0, then=exc) + ): + report = run_agentic_items([_item()], host="http://host", token="tok", workspace_id="ws1", run_ts="2026-01-01") + assert report.items[0].trace_latencies_s == [3.0, 4.0] + + +def test_an_item_that_errored_outside_its_evaluator_reports_no_trace_latencies(): + """Such an item reports no runs, so keeping its turns would put them in the per-response + population with nothing beside them in the per-conversation one.""" + with patch( + "gooddata_eval.cli.agentic_runner.evaluate_agentic_alert_skill", + side_effect=_noting(2.0, 3.0, then=RuntimeError("simulated user failed")), + ): + report = run_agentic_items([_item()], host="http://host", token="tok", workspace_id="ws1", run_ts="2026-01-01") + item = report.items[0] + assert item.error is not None + assert item.runs == 0 + assert item.run_latencies_s == [] + assert item.trace_latencies_s == [] + assert report.by_mode["multi_turn"]["traces_s"] is None + + +def test_an_ungraded_item_keeps_the_turns_it_drove(): + """Unlike the case above, a judge fault leaves every run's time on the exception, so the + per-response and per-conversation populations still cover the same item.""" + err = JudgeResponseError("judge returned no readable verdict for any of the 2 run(s)") + err.runs_effective = 2 + err.run_latencies_s = [7.0, 9.5] + with patch("gooddata_eval.cli.agentic_runner.evaluate_agentic_alert_skill", side_effect=_noting(2.0, then=err)): + report = run_agentic_items( + [_item()], host="http://host", token="tok", workspace_id="ws1", run_ts="2026-01-01", k=2 + ) + assert report.items[0].run_latencies_s == [7.0, 9.5] + assert report.items[0].trace_latencies_s == [2.0] + + +def test_concurrent_items_each_keep_only_their_own_trace_latencies(): + items = [ + DatasetItem( + id=f"g{n}", dataset_name="d", test_kind="agentic_general_question", question=f"q{n}", expected_output="x" + ) + for n in range(1, 5) + ] + + def evaluate(*args: Any, **kwargs: Any) -> AgenticEvalOutcome: + base = float(kwargs["question"][1:]) * 100 + for step in range(3): + time.sleep(0.005) # interleave with the other workers + note_trace_latency(base + step) + return AgenticEvalOutcome(reasoning_steps=[], detail={}) + + with patch("gooddata_eval.cli.agentic_runner.evaluate_agentic_general_question", side_effect=evaluate): + report = run_agentic_items( + items, host="http://host", token="tok", workspace_id="ws1", run_ts="2026-01-01", concurrency=4 + ) + assert {i.id: i.trace_latencies_s for i in report.items} == { + f"g{n}": [n * 100.0, n * 100.0 + 1, n * 100.0 + 2] for n in range(1, 5) + } diff --git a/packages/gooddata-eval/tests/test_agentic_search_tool.py b/packages/gooddata-eval/tests/test_agentic_search_tool.py index 975004cd4..e188e7b99 100644 --- a/packages/gooddata-eval/tests/test_agentic_search_tool.py +++ b/packages/gooddata-eval/tests/test_agentic_search_tool.py @@ -209,6 +209,10 @@ def test_evaluate_agentic_search_tool_returns_reasoning_steps_on_pass(): "tool_call_names": ["search_objects"], "latency_breakdown": [], } + # One wall-clock sample per run, passing runs included -- the latency distribution is over + # these, and a kind that forgot to report them would silently drop out of it. + assert len(outcome.run_latencies_s) == outcome.runs_effective == 1 + assert all(latency >= 0 for latency in outcome.run_latencies_s) def test_evaluate_agentic_search_tool_attaches_reasoning_steps_to_exception_on_fail(): @@ -245,3 +249,4 @@ def test_evaluate_agentic_search_tool_attaches_reasoning_steps_to_exception_on_f "tool_call_names": [], "latency_breakdown": [], } + assert len(exc_info.value.run_latencies_s) == exc_info.value.runs_effective == 1 diff --git a/packages/gooddata-eval/tests/test_agentic_visualization.py b/packages/gooddata-eval/tests/test_agentic_visualization.py index fa48b8a91..499f274bf 100644 --- a/packages/gooddata-eval/tests/test_agentic_visualization.py +++ b/packages/gooddata-eval/tests/test_agentic_visualization.py @@ -342,6 +342,10 @@ def test_evaluate_agentic_visualization_returns_reasoning_steps_on_pass(): "latency_breakdown": [], "tool_calls": [], } + # One wall-clock sample per run, passing runs included -- the latency distribution is over + # these, and a kind that forgot to report them would silently drop out of it. + assert len(outcome.run_latencies_s) == outcome.runs_effective == 1 + assert all(latency >= 0 for latency in outcome.run_latencies_s) def test_evaluate_agentic_visualization_attaches_reasoning_steps_to_exception_on_fail(): @@ -403,6 +407,7 @@ def test_evaluate_agentic_visualization_attaches_reasoning_steps_to_exception_on "latency_breakdown": [], "tool_calls": [], } + assert len(exc_info.value.run_latencies_s) == exc_info.value.runs_effective == 1 # --- turns_used counts every send_message, including the pre-loop one ------------------------ diff --git a/packages/gooddata-eval/tests/test_agentic_what_if.py b/packages/gooddata-eval/tests/test_agentic_what_if.py index 83d93aa70..67a3cc84c 100644 --- a/packages/gooddata-eval/tests/test_agentic_what_if.py +++ b/packages/gooddata-eval/tests/test_agentic_what_if.py @@ -278,6 +278,8 @@ def test_detail_reports_the_adjustments_the_agent_asked_for(): assert outcome.detail["asserted"] == ["metric_id", "scenario_maql"] assert "latency_breakdown" in outcome.detail assert outcome.runs_passed == 1 + assert len(outcome.run_latencies_s) == outcome.runs_effective == 1 + assert all(latency >= 0 for latency in outcome.run_latencies_s) def test_a_wrong_adjustment_raises_naming_what_the_agent_actually_did(): @@ -289,6 +291,7 @@ def test_a_wrong_adjustment_raises_naming_what_the_agent_actually_did(): assert "* 3 *" in str(error) assert error.runs_passed == 0 assert error.conversation_id == "conv-1" + assert len(error.run_latencies_s) == error.runs_effective == 1 def test_a_spec_built_on_an_earlier_turn_is_still_the_one_scored(): diff --git a/packages/gooddata-eval/tests/test_html_report.py b/packages/gooddata-eval/tests/test_html_report.py index b89508365..ff05b1a3b 100644 --- a/packages/gooddata-eval/tests/test_html_report.py +++ b/packages/gooddata-eval/tests/test_html_report.py @@ -1,6 +1,8 @@ # (C) 2026 GoodData Corporation import json import re +import shutil +import subprocess import orjson import pytest @@ -200,3 +202,1085 @@ def test_cli_report_command_needs_no_credentials(tmp_path, monkeypatch, redact): argv = ["report", str(src), "-o", str(out)] + (["--redact"] if redact else []) assert main(argv) == 0 assert out.exists() + + +_TRACES = {"n": 4, "mean": 2.5, "min": 1.0, "p50": 2.5, "p70": 3.1, "p90": 3.7, "p99": 3.97, "max": 4.0} +_RUNS = {"n": 2, "mean": 20.0, "min": 10.0, "p50": 20.0, "p70": 24.0, "p90": 28.0, "p99": 29.8, "max": 30.0} +_BY_MODE = { + "single_shot": {"total": 3, "passed": 2, "traces_s": _TRACES}, + "multi_turn": {"total": 1, "passed": 1, "traces_s": _TRACES, "runs_s": _RUNS}, +} + + +def _doc_with_modes(model: str) -> dict: + doc = _doc(model, True) + doc["runs"][model]["summary"]["by_mode"] = _BY_MODE + doc["runs"][model]["items"]["item-1"].update({"mode": "single_shot", "trace_latencies_s": [1.0, 2.0]}) + doc["comparison"][model]["by_mode"] = _BY_MODE + return doc + + +def test_html_carries_the_mode_split_it_was_built_from(): + data = _embedded(build_html(_doc_with_modes("gpt-5"))) + + assert data["runs"]["gpt-5"]["summary"]["by_mode"] == _BY_MODE + assert data["comparison"]["gpt-5"]["by_mode"] == _BY_MODE + item = data["runs"]["gpt-5"]["items"]["item-1"] + assert (item["mode"], item["trace_latencies_s"]) == ("single_shot", [1.0, 2.0]) + + +def test_redact_keeps_the_mode_split_and_latency(): + """Latency and the section an item falls in are facts about the run, not about our + infrastructure -- the same line redaction already draws for per-item latency.""" + data = _embedded(build_html(_doc_with_modes("gpt-5"), redact=True)) + + assert data["runs"]["Model A"]["summary"]["by_mode"] == _BY_MODE + assert data["comparison"]["Model A"]["by_mode"] == _BY_MODE + assert data["runs"]["Model A"]["items"]["item-1"]["trace_latencies_s"] == [1.0, 2.0] + + +def test_the_page_has_single_question_and_conversation_sections_read_from_the_report(): + """The report is a view over the JSON: the page names the sections and populations and reads + the figures from `by_mode`. It holds no percentile arithmetic that could disagree with the + console or the JSON.""" + html = build_html(_doc_with_modes("gpt-5")) + + assert "by_mode" in html + for text in ( + "Single-question tests · response time", + "Conversation tests · response time", + "Per response", + "Per conversation", + ): + assert text in html + for label in ("Median", "P70", "P90", "P99"): + assert label in html + # The table renderers only lay out figures they are handed; the one place that computes any is `recompute`. + renderers = html.split("// ---------- latency by mode")[1].split("function renderLatency")[0] + assert "sort(" not in renderers + assert "percentile(" not in renderers + + +def test_the_item_table_names_what_each_latency_column_measures(): + """One unlabelled "Latency" column mixed a whole-run average with the per-trace figures above it. The + table now carries both populations under their own names, read from the item's recorded samples.""" + html = build_html(_doc_with_modes("gpt-5")) + + for text in ( + "Response time", + "Time per attempt", + "trace_latencies_s", + "run_latencies_s", + "'lt:' + l", + "'lr:' + l", + ): + assert text in html + assert "['latency', 'Latency']" not in html + + +def test_the_filters_sit_above_the_dashboard_and_drive_every_table(): + html = build_html(_doc_with_modes("gpt-5")) + + bar = html.index('id="filterbar"') + for section in ('id="summary"', 'id="outcomes"', 'id="latency"', 'id="items"'): + assert bar < html.index(section), f"the filter bar must come before {section}" + # One render path feeds the result cards, the outcome table, the latency tables and the item table. + render = html.split("function render() {")[1].split("function renderItems")[0] + for call in ("renderSummary()", "renderOutcomes()", "renderLatency()", "renderItems()"): + assert call in render + + +def test_a_filtered_view_recomputes_and_an_unfiltered_one_reads_the_report(): + """Unfiltered, the page shows the report's own figures so it cannot disagree with the console or the + JSON; only a narrowed selection is recomputed, from the selected items' records.""" + html = build_html(_doc_with_modes("gpt-5")) + + assert "filtered ? recompute(l, ids) : reported(l)" in html + assert "function recompute(label, ids)" in html + assert "function reported(label)" in html + + +def test_an_item_is_judged_by_the_gate_verdict_not_pass_at_k_alone(): + """Under --gate power an item that passed some runs has pass_at_k True and gate_passed False; the + report's counts follow the gate, so the page's status chips and recomputed counts must too.""" + html = build_html(_doc_with_modes("gpt-5")) + + assert "item.gate_passed ?? item.pass_at_k" in html + assert "item.pass_at_k ? 'pass'" not in html + + +def test_kind_status_and_run_are_multi_selects_in_both_tiers(): + html = build_html(_doc_with_modes("gpt-5")) + + for facet in ("kind", "status", "runs"): + assert f"multi('{facet}'" in html + assert 'type="checkbox"' in html + # The old single-value selects and the single "focused run" are gone. + for old in ('')[1].split("")[0] + assert select.index('') < select.index('') + assert "By date" not in select and "By model" not in select + assert 'for="viewby">View by' in html + # One run has nothing to switch between, so the row hides itself rather than offering two identical views. + assert "$('#viewrow').hidden = ALL_LABELS.length < 2" in html + + +def test_the_page_always_opens_by_date(): + """Even a report that compares several models, each seen once, opens on the Date view; Model is one choice away.""" + html = build_html(_doc_with_modes("gpt-5")) + + assert "\nsetView('date');\n" in html + assert "defaultView" not in html + + +_RUN_ORDER = ["startedAt", "runStamp", "byTime"] + + +@_needs_node +def test_runs_are_ordered_by_their_start_time_not_by_the_order_the_files_were_given_in(): + """The page reads "last run" as "latest", so the order has to come from the clock: files passed newest first, or + in any order a shell glob gives them, must still draw the oldest on the left of every chart and the latest on top + of every table.""" + html = build_html(_doc_with_modes("gpt-5")) + data = { + "runs": { + "c · p/m": {"summary": {"started_at": "2026-10-14T14:30:00.412873+00:00"}}, + "a · p/m": {"summary": {"started_at": "2026-10-06T09:15:00Z"}}, + "d · p/m": {"summary": {"started_at": "2026-10-14T14:31:00.007+00:00"}}, + "b · p/m": {"summary": {"started_at": "2026-10-08T11:40:00Z"}}, + } + } + + order = _run_page_js(html, _RUN_ORDER, f"(globalThis.DATA = {json.dumps(data)}, byTime(Object.keys(DATA.runs)))") + + assert order == ["a · p/m", "b · p/m", "c · p/m", "d · p/m"] + + +@_needs_node +def test_runs_that_started_together_keep_the_order_they_were_given_in(): + html = build_html(_doc_with_modes("gpt-5")) + data = { + "runs": { + "y": {"summary": {"started_at": "2026-10-14T14:30:00Z"}}, + "x": {"summary": {"started_at": "2026-10-14T14:30:00Z"}}, + } + } + + order = _run_page_js(html, _RUN_ORDER, f"(globalThis.DATA = {json.dumps(data)}, byTime(Object.keys(DATA.runs)))") + + assert order == ["y", "x"] + + +@_needs_node +def test_a_run_without_a_start_time_is_placed_by_the_date_its_file_is_named_for(): + """Reports written before `started_at` existed are usually kept as one file per day, named for it.""" + html = build_html(_doc_with_modes("gpt-5")) + data = {"runs": {"2026-10-12 · p/m": {}, "2026-09-28 · p/m": {}, "2026-10-05": {}}} + + order = _run_page_js(html, _RUN_ORDER, f"(globalThis.DATA = {json.dumps(data)}, byTime(Object.keys(DATA.runs)))") + + assert order == ["2026-09-28 · p/m", "2026-10-05", "2026-10-12 · p/m"] + + +@_needs_node +def test_a_report_with_an_unplaceable_run_keeps_the_order_it_was_given_in(): + """Sorting only the runs that can be placed would put the others at an arbitrary spot, which reads as a claim.""" + html = build_html(_doc_with_modes("gpt-5")) + data = { + "runs": { + "b · p/m": {"summary": {"started_at": "2026-10-14T14:30:00Z"}}, + "notes.json · p/m": {"summary": {"started_at": None}}, # a report that was never timed + "a · p/m": {"summary": {"started_at": "2026-10-06T09:15:00Z"}}, + } + } + + order = _run_page_js(html, _RUN_ORDER, f"(globalThis.DATA = {json.dumps(data)}, byTime(Object.keys(DATA.runs)))") + + assert order == ["b · p/m", "notes.json · p/m", "a · p/m"] + + +def test_the_page_builds_its_run_list_through_the_timestamp_order(): + html = build_html(_doc_with_modes("gpt-5")) + + assert "const ALL_LABELS = byTime(Object.keys(DATA.runs));" in html + + +@_needs_node +def test_by_model_compares_each_models_latest_run(): + """The page lists its runs oldest first (by start time), so the last run of a model is its latest. The models + keep the order they first appear in.""" + html = build_html(_doc_with_modes("gpt-5")) + keys = {"d1 · a": "m1", "d1 · b": "m2", "d2 · a": "m1", "d2 · b": "m2", "d3 · c": "m3"} + + latest = _run_page_js( + html, ["latestPerKey"], f"latestPerKey({json.dumps(list(keys))}, (l) => ({json.dumps(keys)})[l])" + ) + + assert latest == ["d2 · a", "d2 · b", "d3 · c"] + + +@_needs_node +def test_a_model_is_read_from_the_run_not_from_its_file_name(): + html = build_html(_doc_with_modes("gpt-5")) + data = { + "runs": {"2026-09-28 · p/m": {"model": "m"}, "m.json · p/m": {"model": "m"}, "x · q/m": {"model": "m"}}, + "comparison": { + "2026-09-28 · p/m": {"provider_name": "p"}, + "m.json · p/m": {"provider_name": "p"}, + "x · q/m": {"provider_name": "q"}, + }, + } + + keys = _run_page_js( + html, + ["modelOfRun", "providerOfRun", "modelKeyOf"], + f"(globalThis.DATA = {json.dumps(data)}, Object.keys(DATA.runs).map(modelKeyOf))", + ) + + # The same model id behind two providers is two models; the same model on two dates is one. + assert keys == ["p/m", "p/m", "q/m"] + + +@_needs_node +def test_models_are_ranked_by_the_consoles_winner_rule(): + """Pass rate, then quality, then the quicker average: the order the console names its winner by.""" + html = build_html(_doc_with_modes("gpt-5")) + figures = [ + {"n": "slow", "total": 10, "skipped": 0, "passed": 8, "avg_quality_score": 0.9, "avg_latency_s": 9}, + {"n": "best", "total": 10, "skipped": 0, "passed": 9, "avg_quality_score": 0.5, "avg_latency_s": 30}, + {"n": "good-quality", "total": 10, "skipped": 0, "passed": 8, "avg_quality_score": 0.95, "avg_latency_s": 30}, + {"n": "quick", "total": 10, "skipped": 0, "passed": 8, "avg_quality_score": 0.9, "avg_latency_s": 3}, + # A skipped test case never ran, so 8 of 8 evaluated beats 9 of 10. + { + "n": "fewer-skipped-out", + "total": 10, + "skipped": 2, + "passed": 8, + "avg_quality_score": 0.1, + "avg_latency_s": 99, + }, + ] + + ranked = _run_page_js(html, ["passRateOf", "byStanding"], f"{json.dumps(figures)}.sort(byStanding).map((f) => f.n)") + + assert ranked == ["fewer-skipped-out", "best", "good-quality", "quick", "slow"] + + +@_needs_node +@pytest.mark.parametrize( + ("statuses", "label"), + [ + (["pass", "pass", "pass"], "All pass"), + (["fail", "fail"], "All fail"), + (["pass", "fail", "pass"], "Mixed"), + # Only graded verdicts count: a skip, an ungraded error or an absent model says nothing about a model. + (["pass", "skip", "none"], ""), + (["pass", "err", "pass"], "All pass"), + (["fail", "err", "pass"], "Mixed"), + (["pass"], ""), + ([], ""), + ], +) +def test_across_models_says_whether_the_models_agree_on_a_test_case(statuses, label): + html = build_html(_doc_with_modes("gpt-5")) + + assert _run_page_js(html, ["agreementOf"], f"agreementOf({json.dumps(statuses)})") == label + + +def test_the_test_case_table_opens_on_the_disagreements_when_viewed_by_model(): + html = build_html(_doc_with_modes("gpt-5")) + + assert "AGREE_ORDER = { Mixed: 0" in html + assert "'Across models'" in html + # By model the models are peers in ranked order: no "latest run" lead column, no "Since previous run" column. + assert "(multi && byDate ? [runList[runList.length - 1]] : [])" in html + assert "(multi && !byDate ? (() => { const a = agreementOf(" in html + assert "sortKey = LABELS.length < 2 ? 's:' + LABELS[0] : VIEW === 'model' ? 'agree' : 'chg'" in html + + +@_needs_node +@pytest.mark.parametrize(("top", "step"), [(36.5, 10), (0.8, 0.2), (120, 50), (4.4, 1), (0, 0.2)]) +def test_axis_steps_are_round_numbers(top, step): + html = build_html(_doc_with_modes("gpt-5")) + + assert _run_page_js(html, ["niceStep"], f"niceStep({top}, 5)") == pytest.approx(step) + + +def test_by_model_has_a_section_for_each_chart_between_outcomes_and_latency(): + html = build_html(_doc_with_modes("gpt-5")) + + order = [html.index(f'id="{s}"') for s in ("outcomes", "tradeoff", "categories", "consistency", "latency")] + assert order == sorted(order) + # They start hidden and a layout that has no use for one empties it, so nothing leaves a gap. + for section in ("tradeoff", "categories", "consistency"): + assert f'' in html + set_section = html.split("function setSection(")[1].split("function renderModelSections")[0] + assert "el.hidden = !html" in set_section + sections = html.split("function renderModelSections() {")[1].split("// ---------- by model: results")[0] + for call in ("tradeoffHtml()", "categoryHtml()", "consistencyHtml()"): + assert call in sections + assert "on ? " in sections and ": ''" in sections # the date view gets an empty string for each + + +def test_by_model_opens_on_one_results_table_instead_of_leader_cards(): + html = build_html(_doc_with_modes("gpt-5")) + + # The three leader cards are gone; the model view leaves their section empty (and so hidden) rather than drawing them. + assert "leaderCard" not in html and "renderModelSummary" not in html + summary = html.split("function renderSummary()")[1].split("function sparkHover")[0] + assert "if (VIEW === 'model') return setSection('summary', '')" in summary + # What the date view calls Outcomes is, by model, the Results section; the date view keeps its own two. + by_model = html.split("function modelOutcomesHtml()")[1].split("// ---------- by model: quality against speed")[0] + assert "'

Results

'" in by_model and "Outcomes" not in by_model + by_date = html.split("function renderOutcomes()")[1].split("// ---------- per-item latency")[0] + assert "'

Outcomes

'" in by_date + assert "'

Results

'" in summary + + +def test_the_model_charts_read_the_same_figures_as_the_cards_and_tables(): + """Nothing here is a second source of truth: the speed-quality plot plots the pass rate and the median time per + attempt, the outcome bar is the outcome table's own counts, and the latency bars are the table's own percentiles.""" + html = build_html(_doc_with_modes("gpt-5")) + + tradeoff = html.split("function tradeoffHtml()")[1].split("// Drawn at the section's width")[0] + assert "x: medTimeOf(l), y: passRateOf(figures[l])" in tradeoff + # Two models are the least a comparison can use; with fewer there is no plot. + assert "if (pts.length < 2) return ''" in tradeoff + # Time runs from zero, so the distances between models are honest. + assert "const X = (v) => M.l + innerW * (v / xMax)" in tradeoff + outcomes = html.split("function modelOutcomesHtml()")[1].split("// ---------- by model: quality against speed")[0] + assert "f.passed" in outcomes and "f.failed" in outcomes and "f.errored" in outcomes + assert "passRateOf(figures[l])" in outcomes + latency = html.split("function modelLatencyTable(")[1].split("// First paint")[0] + assert "modeOf(l, mode)" in latency and "LAT_SERIES" in latency + # The date view's table hands over to it, and keeps nothing of its own from the model view. + assert "if (VIEW === 'model') return modelLatencyTable({ mode, field, sample });" in html + + +def test_the_category_heat_map_leaves_skipped_test_cases_out_and_shows_the_figure_in_every_cell(): + html = build_html(_doc_with_modes("gpt-5")) + + categories = html.split("function categoryHtml()")[1].split("// ---------- by model: consistency")[0] + assert ".filter((it) => it && !it.skipped)" in categories + # The shade is never the only signal: the share and the counts are printed in the cell, and the best model in a + # row is marked with a chevron as well as the text. + assert 'class="n"' in categories and "CHEVRON('up')" in categories + # With one category there is nothing to break down. + assert "if (cats.length < 2) return ''" in categories + + +def test_the_consistency_chart_needs_a_report_that_recorded_repeated_attempts(): + html = build_html(_doc_with_modes("gpt-5")) + + consistency = html.split("function consistencyHtml()")[1].split("// ---------- by model: response time")[0] + assert "typeof it.pass_power_k === 'boolean' && (it.runs || 0) > 1" in consistency + assert "if (!st.some(([, s]) => s.repeated)) return ''" in consistency + # pass@K and pass^K are the two bars; the count of test cases between them is the number a reader acts on. + assert "it.pass_at_k" in consistency and "it.pass_power_k === true" in consistency + assert "Passed only some attempts" in consistency + + +def test_switching_view_drops_selections_made_against_the_other_layout(): + """A run picked in the date view means nothing in the model view, and the other way round, so the switch clears + them, closes the drawer (it may show a run that is no longer a column) and draws everything again.""" + html = build_html(_doc_with_modes("gpt-5")) + + switch = html.split("function setView(v) {")[1].split("$('#viewby').addEventListener")[0] + for step in ( + "T.runs.set(LABELS.map(", + "T.runs.sig = I.runs.sig = null", + "cmpPick = null; selected = null; drawerRun = null", + "$('#drawer').classList.remove('open')", + "renderMasthead()", + "render()", + ): + assert step in switch + assert "$('#viewby').addEventListener('input', () => setView($('#viewby').value))" in html + # The run filter is the model filter by model. + assert "noun === 'runs' && VIEW === 'model' ? 'Model'" in html + + +def test_a_report_with_several_models_says_so_where_the_date_view_could_mislead(): + """Two models on two dates read as "Oct 5, Oct 5, Oct 12, Oct 12" by date, with neighbouring runs of different + models compared as if one changed into the other. The names carry the model and the hint points at Model.""" + html = build_html(_doc_with_modes("gpt-5")) + + assert "MULTI_MODEL && l.includes(' · ')" in html + assert "use Model to compare them" in html + # The setup tooltip does not flag the model as a difference when the model is what is being compared. + assert "compared: VIEW === 'model' && (k === 'Model' || k === 'Provider')" in html + assert "'Same for every model'" in html and "'Differs between models'" in html + + +_TIMELINE_FNS = ["esc", "bold", "secs", "CHEVRON", "unwrapJson", "fmt", "timelineHtml", "reasoningHtml"] + + +def _timeline_item() -> dict: + return { + "best_run_latency_s": 12.0, + "reasoning": [ + "**Plan**\n\nwork out the metric", + "**Check**\n\nverify the numbers", + "a paragraph no step points at", + ], + "detail": { + "latency_breakdown": [ + {"seq": 0, "kind": "reasoning", "name": "thinking", "index": 0, "duration_s": 2.0}, + {"seq": 1, "kind": "tool", "name": "search_objects", "index": 0, "duration_s": 3.0}, + {"seq": 2, "kind": "reasoning", "name": "thinking", "index": 1, "duration_s": 1.0}, + ], + "tool_calls": [ + {"index": 0, "name": "search_objects", "arguments": {"query": "revenue"}, "result": '{"results": []}'} + ], + }, + } + + +@_needs_node +def test_every_timeline_step_opens_in_place_and_starts_shut(): + """Each step carries its own record under its own row, hidden until opened, instead of one shared box below the + list. The chevron is a real button (keyboard-reachable) that says what it controls and whether that is open.""" + html = build_html(_doc("gpt-5", True)) + + out = _run_page_js(html, _TIMELINE_FNS, f"timelineHtml({json.dumps(_timeline_item())})") + + assert out.count('class="chev"') == 3 + assert out.count('aria-expanded="false"') == 3 + 1 # the three steps and the expand-all control + assert out.count('class="body"') == 3 and out.count(" hidden>") == 3 + controls = re.findall(r'aria-controls="([^"]+)"', out) + assert len(set(controls)) == 3 + assert all(f'id="{c}"' in out for c in controls) + # The reasoning step opens to its own paragraph, the tool step to what it was given and what came back. + assert "work out the metric" in out and "verify the numbers" in out + assert '
arguments
' in out and ""query": "revenue"" in out + assert '
result
' in out and ""results": []" in out + assert "tl-detail" not in out and "data-text" not in out + + +@_needs_node +def test_reasoning_renders_markdown_bold_instead_of_showing_the_asterisks(): + """Reasoning paragraphs open with a markdown **title**. The page shows that as bold text, on the timeline step and + in the leftover Reasoning section alike, and never lets anything but its own through as markup.""" + html = build_html(_doc("gpt-5", True)) + item = _timeline_item() + + on_step = _run_page_js(html, _TIMELINE_FNS, f"timelineHtml({json.dumps(item)})") + assert "Plan\n\nwork out the metric" in on_step + assert "Check" in on_step and "**" not in on_step + + item["reasoning"][2] = "**Leftover** not markup" + leftover = _run_page_js(html, _TIMELINE_FNS, f"reasoningHtml({json.dumps(item)})") + assert "Leftover" in leftover + assert "<b>not markup</b>" in leftover and "" not in leftover + + # An unpaired marker, or one split across paragraphs, stays as written. + stray = _run_page_js(html, ["esc", "bold"], 'bold("a ** b\\n\\n**c")') + assert "" not in stray + + +@_needs_node +def test_the_timeline_has_one_control_to_open_or_shut_every_step(): + html = build_html(_doc("gpt-5", True)) + + out = _run_page_js(html, _TIMELINE_FNS, f"timelineHtml({json.dumps(_timeline_item())})") + + assert out.count('class="tlall"') == 1 and "Expand all" in out + # The label only reads "Collapse all" once every step is open, so it always names what a click would do. + wiring = html.split("function wireTimeline(root) {")[1].split("\n}\n")[0] + assert "steps.some(shut)" in wiring and "every ? 'Collapse all' : 'Expand all'" in wiring + assert "wireTimeline(d);" in html + + +@_needs_node +def test_reasoning_is_not_repeated_below_a_timeline_that_already_shows_it(): + """The drawer used to print every reasoning paragraph in full under the timeline. They now sit on the reasoning + steps, so that section only catches what the timeline cannot show.""" + html = build_html(_doc("gpt-5", True)) + item = _timeline_item() + + leftover = _run_page_js(html, _TIMELINE_FNS, f"reasoningHtml({json.dumps(item)})") + assert "a paragraph no step points at" in leftover and "#2" in leftover + assert "work out the metric" not in leftover and "verify the numbers" not in leftover + + item["reasoning"] = item["reasoning"][:2] + assert _run_page_js(html, _TIMELINE_FNS, f"reasoningHtml({json.dumps(item)})") == "" + + # No timeline to put them on: nothing is lost, all of it is listed. + del item["detail"]["latency_breakdown"] + item["reasoning"] = _timeline_item()["reasoning"] + everything = _run_page_js(html, _TIMELINE_FNS, f"reasoningHtml({json.dumps(item)})") + assert "work out the metric" in everything and "a paragraph no step points at" in everything diff --git a/packages/gooddata-eval/tests/test_interaction.py b/packages/gooddata-eval/tests/test_interaction.py new file mode 100644 index 000000000..0e43e24ad --- /dev/null +++ b/packages/gooddata-eval/tests/test_interaction.py @@ -0,0 +1,35 @@ +# (C) 2026 GoodData Corporation +import pytest +from gooddata_eval.cli.agentic_runner import AGENTIC_TEST_KINDS +from gooddata_eval.core.evaluators import supported_test_kinds +from gooddata_eval.core.interaction import ( + MULTI_TURN, + MULTI_TURN_KINDS, + SINGLE_SHOT, + SINGLE_TURN_AGENTIC_KINDS, + interaction_mode, +) + + +def test_every_agentic_kind_is_classified_on_purpose(): + """A new agentic kind defaults to single-shot in `interaction_mode`, which would silently + fold a multi-turn conversation into the per-trace section. Failing here makes whoever adds + the kind say which it is.""" + assert SINGLE_TURN_AGENTIC_KINDS | MULTI_TURN_KINDS == AGENTIC_TEST_KINDS + assert not SINGLE_TURN_AGENTIC_KINDS & MULTI_TURN_KINDS + + +@pytest.mark.parametrize("kind", sorted(supported_test_kinds())) +def test_the_non_agentic_kinds_are_single_shot(kind): + # They send one chat message (or one summary request) per run. + assert interaction_mode(kind) == SINGLE_SHOT + + +@pytest.mark.parametrize("kind", sorted(SINGLE_TURN_AGENTIC_KINDS)) +def test_single_turn_agentic_kinds_are_single_shot(kind): + assert interaction_mode(kind) == SINGLE_SHOT + + +@pytest.mark.parametrize("kind", sorted(MULTI_TURN_KINDS)) +def test_conversation_driving_kinds_are_multi_turn(kind): + assert interaction_mode(kind) == MULTI_TURN diff --git a/packages/gooddata-eval/tests/test_reporting.py b/packages/gooddata-eval/tests/test_reporting.py index 8662b62c9..b10b1671e 100644 --- a/packages/gooddata-eval/tests/test_reporting.py +++ b/packages/gooddata-eval/tests/test_reporting.py @@ -1,5 +1,6 @@ # (C) 2026 GoodData Corporation import io +from datetime import datetime, timezone import orjson from gooddata_eval.core.reporting.console import render_comparison, render_console @@ -56,6 +57,16 @@ def test_build_json_report_keyed_by_item_id(): assert data["items"]["i2"]["reasoning"] == [] +def test_build_json_report_writes_started_at_as_utc_iso(): + report = _report() + report.started_at = datetime(2026, 10, 14, 14, 30, 21, 412873, tzinfo=timezone.utc) + assert build_json_report(report)["summary"]["started_at"] == "2026-10-14T14:30:21.412873+00:00" + + +def test_build_json_report_started_at_is_null_when_the_run_was_never_timed(): + assert build_json_report(_report())["summary"]["started_at"] is None + + def test_write_json_report_creates_file(tmp_path): path = tmp_path / "out.json" write_json_report(_report(), path) @@ -488,3 +499,133 @@ def test_json_report_failed_runs_is_empty_for_a_clean_item(): ItemReport(id="i1", dataset_name="d", test_kind="visualization", question="q", pass_at_k=True, runs=2) ) assert build_json_report(report)["items"]["i1"]["failed_runs"] == [] + + +def _mixed_report(model: str = "gpt-5.2", *, single: list[float] | None = None) -> EvalReport: + """Two single-shot items (one trace each) and one multi-turn conversation (three turns).""" + single = single if single is not None else [1.0, 3.0] + items = [ + ItemReport( + id=f"s{n}", + dataset_name="d", + test_kind="visualization", + question=f"q{n}", + pass_at_k=n == 1, + runs=1, + latency_s=latency + 0.5, + trace_latencies_s=[latency], + run_latencies_s=[latency + 0.5], + ) + for n, latency in enumerate(single, start=1) + ] + items.append( + ItemReport( + id="m1", + dataset_name="d", + test_kind="agentic_metric_skill", + question="converse", + pass_at_k=True, + runs=1, + latency_s=30.0, + trace_latencies_s=[2.0, 4.0, 6.0], + run_latencies_s=[30.0], + ) + ) + return EvalReport(model=model, workspace_id="ws1", items=items) + + +def test_json_report_splits_pass_counts_and_latency_by_mode(): + summary = build_multi_model_report([_mixed_report()])["runs"]["gpt-5.2"]["summary"] + + single = summary["by_mode"]["single_shot"] + assert (single["total"], single["passed"]) == (2, 1) + # Two single-shot items, one trace each: the main per-trace figure. + assert single["traces_s"] == { + "n": 2, + "mean": 2.0, + "trimmed_mean": None, + "min": 1.0, + "p50": 2.0, + "p70": 2.4, + "p90": 2.8, + "p99": 2.98, + "max": 3.0, + } + assert "runs_s" not in single + + multi = summary["by_mode"]["multi_turn"] + assert (multi["total"], multi["passed"]) == (1, 1) + # Three turns of one conversation are three traces, and one full run. + assert multi["traces_s"]["n"] == 3 and multi["traces_s"]["p50"] == 4.0 + assert multi["runs_s"]["n"] == 1 and multi["runs_s"]["max"] == 30.0 + + +def test_json_comparison_entry_repeats_the_mode_split(): + # The HTML reads the comparison entry and falls back to the summary, so both carry it. + data = build_multi_model_report([_mixed_report()]) + + assert data["comparison"]["gpt-5.2"]["by_mode"] == data["runs"]["gpt-5.2"]["summary"]["by_mode"] + + +def test_json_items_state_their_mode_and_trace_latencies(): + items = build_multi_model_report([_mixed_report()])["runs"]["gpt-5.2"]["items"] + + assert items["s1"]["mode"] == "single_shot" + assert items["s1"]["trace_latencies_s"] == [1.0] + assert items["m1"]["mode"] == "multi_turn" + assert items["m1"]["trace_latencies_s"] == [2.0, 4.0, 6.0] + assert items["m1"]["run_latencies_s"] == [30.0] + + +def test_json_report_states_no_latency_distribution_when_nothing_was_timed(): + # null, not zeroes: a P99 of 0s would claim a measurement that never happened. + by_mode = build_multi_model_report([_report()])["runs"]["gpt-5.2"]["summary"]["by_mode"] + + assert by_mode["single_shot"]["traces_s"] is None + assert by_mode["multi_turn"] == {"total": 0, "passed": 0, "traces_s": None, "runs_s": None} + + +def test_json_report_leaves_the_existing_latency_figures_alone(): + summary = build_json_report(_mixed_report())["summary"] + + assert summary["latency_s"] == 1.5 + 3.5 + 30.0 + assert summary["avg_latency_s"] == round(35.0 / 3, 3) + + +def test_console_prints_each_modes_latency_beneath_the_summary(): + text = render_console(_mixed_report()) + + assert "By mode: single-shot 1/2 passed · multi-turn 1/1 passed" in text + assert "Latency, single-shot per trace (n=2): P50 2.00s · P70 2.40s · P90 2.80s · P99 2.98s" in text + assert "Latency, multi-turn per trace (n=3): P50 4.00s" in text + assert "Latency, multi-turn per full run (n=1): P50 30.00s" in text + assert text.index("Summary:") < text.index("By mode:") < text.index("per trace (n=2)") + + +def test_console_leaves_out_a_mode_with_no_items_and_a_distribution_with_no_samples(): + only_single = EvalReport(model="m", items=[_mixed_report().items[0]]) + + text = render_console(only_single) + + assert "single-shot 0/1 passed" not in text and "single-shot 1/1 passed" in text + assert "multi-turn" not in text + + +def test_console_omits_the_mode_lines_when_nothing_was_evaluated(): + assert "By mode" not in render_console(EvalReport(model="m")) + + +def test_comparison_table_sets_single_shot_trace_median_and_tail_side_by_side(): + reports = [ + _mixed_report("gpt-5.2", single=[10.0, 20.0]), + _mixed_report("gpt-4o", single=[8.0, 12.0]), + ] + + text = render_comparison(reports, console=Console(record=True, width=200)) + + for column in ("Trace P50", "Trace P90", "Trace P99"): + assert column in text + assert "15.00s" in text # gpt-5.2 median of its single-shot traces 10 and 20 + assert "19.00s" in text # gpt-5.2 P90 + assert "10.00s" in text # gpt-4o median of 8 and 12 + assert "single-shot chat-turn response time" in text diff --git a/packages/gooddata-eval/tests/test_runner.py b/packages/gooddata-eval/tests/test_runner.py index c661b0672..62bccc81d 100644 --- a/packages/gooddata-eval/tests/test_runner.py +++ b/packages/gooddata-eval/tests/test_runner.py @@ -1,12 +1,14 @@ # (C) 2026 GoodData Corporation import threading import time +from datetime import datetime, timezone from unittest.mock import patch +import pytest from gooddata_eval.core.evaluators import supported_test_kinds from gooddata_eval.core.evaluators.base import ItemEvaluation from gooddata_eval.core.models import ChatResult, DatasetItem -from gooddata_eval.core.runner import ItemReport, run_items +from gooddata_eval.core.runner import EvalReport, ItemReport, run_items def _viz_obj(): @@ -60,6 +62,15 @@ def test_run_items_pass_at_k_true_if_any_run_passes(): assert backend.calls == 2 +def test_run_items_stamps_when_the_run_started(): + before = datetime.now(timezone.utc) + report = run_items([_item()], _FakeBackend([_chat_with(_viz_obj())]), runs=1) + after = datetime.now(timezone.utc) + assert report.started_at is not None + assert report.started_at.tzinfo is not None + assert before <= report.started_at <= after + + def test_run_items_marks_unsupported_test_kind_skipped(): item = DatasetItem(id="s1", dataset_name="d", test_kind="unknown_kind", question="q", expected_output={}) backend = _FakeBackend([_empty_chat()]) @@ -510,3 +521,177 @@ def test_an_ungraded_run_is_recorded_as_a_failure_with_its_judge_error(): item = report.items[0] assert item.pass_at_k is True and item.pass_power_k is False assert [r["error"] for r in item.failed_runs] == ["empty body"] + + +# --- every completed run is timed, passing or not: the latency percentiles are over these --- + + +def test_every_run_is_timed_whether_it_passed_or_not(): + report, _ = _run_scripted([_graded(True), _graded(False), _ungraded()], runs=3) + + item = report.items[0] + assert len(item.run_latencies_s) == item.runs == 3 + assert all(latency >= 0 for latency in item.run_latencies_s) + # latency_s is the sum of the same measurements, so the list cannot disagree with it. + assert sum(item.run_latencies_s) == pytest.approx(item.latency_s) + + +def test_a_run_that_raised_is_not_timed_and_is_not_counted(): + class _SecondRunBoomsBackend: + def __init__(self): + self.calls = 0 + + def ask(self, item: DatasetItem) -> ChatResult: + self.calls += 1 + if self.calls == 2: + raise RuntimeError("network down") + return _empty_chat() + + report = run_items([_item()], _SecondRunBoomsBackend(), runs=2) + + item = report.items[0] + assert item.error is not None + # `runs` and the sample agree about what completed: a run with no verdict has no latency. + assert len(item.run_latencies_s) == item.runs == 1 + + +def _timed_chat(seconds: float | None) -> ChatResult: + result = _chat_with(_viz_obj()) + result.turn_wall_clock_sec = seconds + return result + + +def test_a_single_shot_run_records_its_chat_turn_as_the_trace_latency(): + """One trace per run: the turn's own response time, not the run's wall clock, which also + holds scoring and conversation set-up.""" + backend = _FakeBackend([_timed_chat(2.5), _timed_chat(4.0)]) + + report = run_items([_item()], backend, runs=2) + + item = report.items[0] + assert item.trace_latencies_s == [2.5, 4.0] + assert len(item.run_latencies_s) == 2 + assert item.run_latencies_s != item.trace_latencies_s + + +def test_a_turn_with_no_timing_adds_no_trace_latency(): + # A backend that reports no turn time leaves the sample empty rather than inventing a zero. + report = run_items([_item()], _FakeBackend([_timed_chat(None)]), runs=2) + + assert report.items[0].trace_latencies_s == [] + + +def test_a_turn_whose_scoring_raised_still_counts_as_a_trace(): + """The agent answered; only our scoring failed afterwards. That response time is real.""" + + class _ScoringBooms: + test_kind = "visualization" + + def evaluate(self, item, chat_result): + raise RuntimeError("scorer broke") + + with patch("gooddata_eval.core.runner.get_evaluator", return_value=_ScoringBooms()): + report = run_items([_item()], _FakeBackend([_timed_chat(3.0)]), runs=1) + + item = report.items[0] + assert item.error is not None + assert item.trace_latencies_s == [3.0] + assert item.run_latencies_s == [] # the run never completed, so it has no whole-run time + + +def test_skipped_items_time_nothing(): + skipped = DatasetItem(id="s1", dataset_name="d", test_kind="unknown_kind", question="q", expected_output={}) + + report = run_items([skipped], _FakeBackend([_timed_chat(1.0)]), runs=2) + + assert report.items[0].trace_latencies_s == [] + assert report.items[0].run_latencies_s == [] + + +# --- the report splits single-shot from multi-turn --- + + +def _item_report(kind: str, *, traces: list[float], runs: list[float], passed: bool = True, **extra) -> ItemReport: + return ItemReport( + id=f"{kind}-{len(traces)}", + dataset_name="d", + test_kind=kind, + question="q", + pass_at_k=passed, + runs=max(len(runs), 1), + trace_latencies_s=traces, + run_latencies_s=runs, + **extra, + ) + + +def test_an_item_is_single_shot_or_multi_turn_by_its_kind(): + assert _item_report("visualization", traces=[], runs=[]).interaction_mode == "single_shot" + assert _item_report("agentic_guardrail", traces=[], runs=[]).interaction_mode == "single_shot" + assert _item_report("agentic_visualization", traces=[], runs=[]).interaction_mode == "multi_turn" + + +def test_by_mode_keeps_single_shot_and_multi_turn_apart(): + report = EvalReport(model="m") + report.items = [ + _item_report("visualization", traces=[1.0], runs=[1.5]), + _item_report("agentic_search", traces=[3.0], runs=[3.5], passed=False), + # A multi-turn conversation: three traces, one whole run. + _item_report("agentic_metric_skill", traces=[2.0, 4.0, 6.0], runs=[20.0]), + ] + + by_mode = report.by_mode + + assert (by_mode["single_shot"]["total"], by_mode["single_shot"]["passed"]) == (2, 1) + assert by_mode["single_shot"]["traces_s"]["n"] == 2 + assert by_mode["single_shot"]["traces_s"]["p50"] == 2.0 + # Per-run is a multi-turn figure only: a single-shot run is its one trace. + assert "runs_s" not in by_mode["single_shot"] + assert (by_mode["multi_turn"]["total"], by_mode["multi_turn"]["passed"]) == (1, 1) + assert by_mode["multi_turn"]["traces_s"]["n"] == 3 + assert by_mode["multi_turn"]["runs_s"]["n"] == 1 + assert by_mode["multi_turn"]["runs_s"]["max"] == 20.0 + + +def test_by_mode_is_computed_once_per_report(): + """The console, the comparison and both JSON builders all read it; each read used to sort + every latency sample again.""" + report = EvalReport(model="m") + report.items = [_item_report("visualization", traces=[1.0, 2.0], runs=[1.5])] + + assert report.by_mode is report.by_mode + + +def test_by_mode_never_mixes_the_populations(): + """Single-shot traces must not be pulled up by a conversation's turns, or the main per-trace + figure would describe nothing in particular.""" + report = EvalReport(model="m") + report.items = [ + _item_report("visualization", traces=[1.0, 1.0], runs=[1.0, 1.0]), + _item_report("agentic_conversation", traces=[50.0, 60.0], runs=[110.0]), + ] + + by_mode = report.by_mode + + assert by_mode["single_shot"]["traces_s"]["max"] == 1.0 + assert by_mode["multi_turn"]["traces_s"]["min"] == 50.0 + + +def test_by_mode_counts_evaluated_items_only_and_states_no_latency_for_an_empty_mode(): + report = EvalReport(model="m") + report.items = [ + _item_report("visualization", traces=[1.0], runs=[1.0]), + _item_report("some_new_kind", traces=[], runs=[], skipped=True), + ] + + by_mode = report.by_mode + + assert by_mode["single_shot"]["total"] == 1 # the skipped item belongs to neither section + assert by_mode["multi_turn"] == {"total": 0, "passed": 0, "traces_s": None, "runs_s": None} + + +def test_a_report_with_nothing_timed_has_no_latency_distributions(): + report = EvalReport(model="m") + report.items = [_item_report("visualization", traces=[], runs=[])] + + assert report.by_mode["single_shot"]["traces_s"] is None diff --git a/packages/gooddata-eval/tests/test_sse_client.py b/packages/gooddata-eval/tests/test_sse_client.py index 4f58f4359..62546810b 100644 --- a/packages/gooddata-eval/tests/test_sse_client.py +++ b/packages/gooddata-eval/tests/test_sse_client.py @@ -24,6 +24,7 @@ trace_ids_for, ) from gooddata_eval.core.models import DatasetItem, ReasoningStepEvent, ToolCallEvent, build_latency_breakdown +from gooddata_eval.core.timing import TraceRecorder def test_parse_sse_lines_collects_text_and_visualization(fixtures_dir): @@ -648,6 +649,62 @@ def test_send_message_stamps_turn_wall_clock_sec_on_partial_result_too(monkeypat assert ei.value.partial_result.turn_wall_clock_sec == pytest.approx(1.0) +def test_send_message_records_the_turn_as_a_trace_latency(monkeypatch): + monkeypatch.setattr(sse_mod.time, "monotonic", iter([100.0, 100.0, 102.5]).__next__) + client = _client_with_handler(lambda request: httpx.Response(200, content=_OK_SSE)) + recorder = TraceRecorder() + client.send_message("conv", "q") + assert recorder.stop() == [pytest.approx(2.5)] + + +def test_send_message_records_a_turn_that_ended_in_a_chat_error(monkeypatch): + # Evaluators score the partial result of such a turn as a run, so the response population has to + # hold it too, or the two disagree about which turns happened. + monkeypatch.setattr(sse_mod.time, "monotonic", iter([50.0, 50.0, 51.0]).__next__) + client = _client_with_handler(lambda request: httpx.Response(200, content=_NONRETRY_SSE)) + recorder = TraceRecorder() + with pytest.raises(ChatError): + client.send_message("conv", "q") + assert recorder.stop() == [pytest.approx(1.0)] + + +def test_send_message_records_a_turn_cut_off_by_its_deadline(monkeypatch): + """The slowest turns are the ones that hit the budget; leaving them out would make the tail + look shorter exactly when the agent is slowest.""" + # monotonic() calls: t0, the accumulator's own t0, the deadline check on the first line, the wall-clock. + monkeypatch.setattr(sse_mod.time, "monotonic", iter([0.0, 0.0, 61.0, 61.0]).__next__) + client = _client_with_handler(lambda request: httpx.Response(200, content=_OK_SSE), turn_timeout_s=60) + recorder = TraceRecorder() + with pytest.raises(sse_mod.TurnTimeoutError): + client.send_message("conv", "q") + assert recorder.stop() == [pytest.approx(61.0)] + + +def test_send_message_records_nothing_for_a_turn_that_failed_without_a_partial_result(): + # An HTTP error before any stream opens leaves no partial result: no response to time. + client = _client_with_handler(lambda request: httpx.Response(400)) + recorder = TraceRecorder() + with pytest.raises(httpx.HTTPStatusError): + client.send_message("conv", "q") + assert recorder.stop() == [] + + +def test_send_message_records_only_the_successful_attempt_of_a_retried_turn(monkeypatch): + monkeypatch.setattr(sse_mod.time, "sleep", lambda s: None) + monkeypatch.setattr(sse_mod.time, "monotonic", iter([1000.0, 1000.0, 1000.5, 2000.0, 2000.0, 2001.2]).__next__) + calls = {"n": 0} + + def handler(request): + calls["n"] += 1 + return httpx.Response(200, content=_TRANSIENT_SSE if calls["n"] < 2 else _OK_SSE) + + client = _client_with_handler(handler) + recorder = TraceRecorder() + client.send_message("conv", "q") + # One trace, timed on the attempt that answered: the failed attempt and the backoff are not it. + assert recorder.stop() == [pytest.approx(1.2)] + + def test_create_conversation_retries_then_succeeds(monkeypatch): sleeps = [] monkeypatch.setattr(sse_mod.time, "sleep", lambda s: sleeps.append(s)) diff --git a/packages/gooddata-eval/tests/test_summary_client.py b/packages/gooddata-eval/tests/test_summary_client.py index 637e03aed..1dbd97240 100644 --- a/packages/gooddata-eval/tests/test_summary_client.py +++ b/packages/gooddata-eval/tests/test_summary_client.py @@ -5,6 +5,7 @@ import pytest from gooddata_eval.core.models import DatasetItem, SummaryInput from gooddata_eval.core.summary.http_client import SummaryClient +from gooddata_eval.core.timing import TraceRecorder def _item() -> DatasetItem: @@ -34,9 +35,14 @@ def handler(request: httpx.Request) -> httpx.Response: client = SummaryClient(host="https://h", token="tok", workspace_id="ws") client._client = httpx.Client(transport=httpx.MockTransport(handler)) + recorder = TraceRecorder() result = client.ask(_item()) + traces = recorder.stop() assert result.text_response == "Revenue grew QoQ." + # The summary request is this item's one trace, timed on the same footing as a chat turn. + assert result.turn_wall_clock_sec is not None and result.turn_wall_clock_sec >= 0 + assert traces == [result.turn_wall_clock_sec] assert captured["url"] == "https://h/api/v1/ai/workspaces/ws/summary" assert captured["auth"] == "Bearer tok" assert captured["body"] == { diff --git a/packages/gooddata-eval/tests/test_timing.py b/packages/gooddata-eval/tests/test_timing.py index 3b31a8411..b2de2e19b 100644 --- a/packages/gooddata-eval/tests/test_timing.py +++ b/packages/gooddata-eval/tests/test_timing.py @@ -1,16 +1,23 @@ # (C) 2026 GoodData Corporation """Tests for PhaseTimings and the [timer] diagnostic gate.""" +import statistics import threading +from concurrent.futures import ThreadPoolExecutor from unittest.mock import patch import pytest from gooddata_eval.core.timing import ( TIMERS_ENV_VAR, PhaseTimings, + TraceRecorder, + latency_stats, log_timer, + note_trace_latency, + percentile, sum_timings, timers_enabled, + trimmed_mean, ) @@ -91,3 +98,173 @@ def test_as_dict_rounds_every_phase(): def test_sum_timings_of_nothing_is_all_zeroes(): assert sum_timings([]) == PhaseTimings() + + +def test_percentile_interpolates_between_closest_ranks(): + # rank = 0.9 * 3 = 2.7 -> 3.0 + 0.7 * (4.0 - 3.0) + assert percentile([1.0, 2.0, 3.0, 4.0], 90) == pytest.approx(3.7) + + +@pytest.mark.parametrize("n", [1, 2, 3, 4, 7, 10, 99]) +def test_p50_is_the_median_for_any_sample_size(n): + # The report prints P50 as the median and carries no separate median field, so the + # two must never disagree -- nearest-rank would differ on every even-sized sample. + samples = [float(i * i) for i in range(1, n + 1)] + + assert percentile(samples, 50) == pytest.approx(statistics.median(samples)) + + +def test_percentile_of_a_single_sample_is_that_sample(): + assert percentile([2.5], 99) == 2.5 + + +def test_percentile_of_an_empty_sample_raises(): + with pytest.raises(ValueError, match="empty"): + percentile([], 50) + + +def test_latency_stats_of_nothing_is_none(): + # None rather than zeroes: a run with no timed runs has no latency, not a 0s one. + assert latency_stats([]) is None + + +def test_latency_stats_orders_an_unsorted_sample_and_reports_every_figure(): + stats = latency_stats([4.0, 1.0, 3.0, 2.0]) + + assert stats == { + "n": 4, + "mean": 2.5, + "trimmed_mean": None, + "min": 1.0, + "p50": 2.5, + "p70": 3.1, + "p90": 3.7, + "p99": 3.97, + "max": 4.0, + } + + +def test_latency_stats_never_decreases_from_p50_to_max(): + stats = latency_stats([0.4, 12.0, 3.3, 3.3, 7.9, 0.9, 21.5]) + + ladder = [stats[k] for k in ("min", "p50", "p70", "p90", "p99", "max")] + assert ladder == sorted(ladder) + + +def test_latency_stats_of_one_run_collapses_to_that_run(): + stats = latency_stats([3.25]) + + assert stats == { + "n": 1, + "mean": 3.25, + "trimmed_mean": None, + "min": 3.25, + "p50": 3.25, + "p70": 3.25, + "p90": 3.25, + "p99": 3.25, + "max": 3.25, + } + + +def test_trimmed_mean_drops_the_fastest_and_slowest_tenth_before_averaging(): + # Ten samples drop one from each end: the 0.1s and the 100s no longer move the average. + samples = [0.1, 2.0, 2.0, 2.0, 2.0, 2.0, 2.0, 2.0, 2.0, 100.0] + + assert trimmed_mean(samples) == pytest.approx(2.0) + assert sum(samples) / len(samples) == pytest.approx(11.61) # the plain mean is dragged far above it + + +def test_trimmed_mean_is_not_the_median(): + # The median is one middle value; the trimmed mean still averages what is left, so the two + # differ whenever the middle 80% is not symmetric. + samples = [1.0, 1.0, 1.0, 1.0, 1.0, 1.0, 1.0, 1.0, 9.0, 9.0] + + assert statistics.median(samples) == 1.0 + assert trimmed_mean(samples) == pytest.approx(2.0) + + +@pytest.mark.parametrize(("n", "dropped_each_end"), [(10, 1), (19, 1), (20, 2), (25, 2), (100, 10)]) +def test_trimmed_mean_cut_is_the_floor_of_a_tenth_of_the_sample_per_end(n, dropped_each_end): + samples = [float(i) for i in range(n)] + + kept = samples[dropped_each_end : n - dropped_each_end] + assert trimmed_mean(samples) == pytest.approx(sum(kept) / len(kept)) + + +@pytest.mark.parametrize("n", [1, 2, 5, 9]) +def test_trimmed_mean_is_none_when_nothing_can_be_trimmed(n): + # Below ten samples a 10% trim removes nothing, so the figure would just be the plain mean + # under a name that promises otherwise. + assert trimmed_mean([float(i) for i in range(n)]) is None + + +def test_trimmed_mean_of_an_empty_sample_raises(): + with pytest.raises(ValueError, match="empty"): + trimmed_mean([]) + + +def test_latency_stats_carries_the_trimmed_mean_once_there_are_ten_samples(): + stats = latency_stats([100.0, 2.0, 2.0, 2.0, 2.0, 2.0, 2.0, 2.0, 2.0, 0.1]) + + assert stats["trimmed_mean"] == 2.0 + assert stats["mean"] == 11.61 + + +def test_a_recorder_collects_each_noted_trace_in_order(): + recorder = TraceRecorder() + for seconds in (1.5, 0.5, 2.0): + note_trace_latency(seconds) + + assert recorder.stop() == [1.5, 0.5, 2.0] + + +def test_noting_a_trace_with_no_recorder_is_a_no_op(): + # A library caller or a test has no recorder; the chat client still calls this. + note_trace_latency(3.0) + + +def test_a_turn_without_timing_is_not_recorded(): + recorder = TraceRecorder() + note_trace_latency(None) + + assert recorder.stop() == [] + + +def test_stopping_detaches_the_recorder_and_is_safe_twice(): + recorder = TraceRecorder() + note_trace_latency(1.0) + assert recorder.stop() == [1.0] + + note_trace_latency(9.0) # after stop: nobody is listening + + assert recorder.stop() == [1.0] + + +def test_discarding_drops_what_was_recorded_and_detaches(): + recorder = TraceRecorder() + note_trace_latency(1.0) + + recorder.discard() + note_trace_latency(9.0) # after discard: nobody is listening + + assert recorder.stop() == [] + + +def test_concurrent_items_each_record_only_their_own_traces(): + """Items run in worker threads under --concurrency; one item's turns must never land in + another's list.""" + + def item(base: float) -> list[float]: + recorder = TraceRecorder() + try: + for step in range(5): + note_trace_latency(base + step) + finally: + recorded = recorder.stop() + return recorded + + with ThreadPoolExecutor(max_workers=4) as pool: + results = list(pool.map(item, [0.0, 100.0, 200.0, 300.0])) + + assert results == [[b + s for s in range(5)] for b in (0.0, 100.0, 200.0, 300.0)]