Add JSON summary output for inspect profile

[JamesbbBriz]

Fixes #33701

Summary

• Adds --format human|json and --output/-o to vespa inspect profile.
• Adds a compact tracedoctor.ProfileSummary model with schemaVersion: 1.
• Exposes the stable timing values already extracted by tracedoctor: top-level query timing, per-search backend time, per-node task timing, and top first/second phase profiled components.

This intentionally does not expose the full dynamic profile/trace tree as a stable API.

Tests

• go test ./internal/cli/cmd ./internal/vespa/tracedoctor
• go test ./...

[chatgpt-codex-connector]

💡 Codex Review

Here are some automated review suggestions for this pull request.

Reviewed commit: 02dcf6dc4c

ℹ️ About Codex in GitHub

Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you

• Open a pull request for review
• Mark a draft as ready
• Comment "@codex review".

If Codex has suggestions, it will comment; otherwise it will react with 👍.

Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".

[chatgpt-codex-connector]

Validate the format before truncating output files

When --output is combined with an invalid --format, this opens the destination with os.Create before the format switch rejects the command, so a typo such as --format jsn --output summary.json silently truncates an existing file and then returns an error without writing anything. Check opts.format before creating the file to avoid data loss on invalid invocations.

Useful? React with 👍 / 👎.

[JamesbbBriz]

This is a first narrow pass for #33701.

I kept the JSON output to a schemaVersioned summary instead of exposing the full trace tree, since the issue discussion called out that the trace/profile structure is dynamic. The summary currently includes top-level timing, per-search/backend timing, per-node task timings, and top first/second phase components.

I also addressed the automated review comment in 318d38a by validating --format before creating --output, with a regression test covering invalid formats not truncating an existing output file.

If this scope looks reasonable, I can adjust the JSON shape or keep this behind the hidden inspect profile command.

[bratseth]

We're not really ready to make this a public API, and when it is not it isn't clear that this is worth the maintenance cost. Do you need it for anything?

[JamesbbBriz]

Hi bratseth, thank you for the review. Let me try to answer the "do you need it for anything?" question concretely, as that's the heart of it.

My motivation: vespa inspect profile is the natural entry point for diagnosing slow queries, but today it only produces human-readable text. Whenever someone wants to automate that — a CI performance gate, a regression check after a Vespa upgrade or rank profile change, spotting outlier nodes on a large cluster, attaching structured data to a support ticket — they have to parse free-form tables or re-parse the raw trace themselves. A machine-readable summary would make inspect programmable rather than just readable.

Here's an illustrative example of the output (slow query over 6 content nodes):

{
  "schemaVersion": 1,
  "timing": { "totalMs": 210.4, "queryMs": 185.2, "summaryMs": 8.9, "otherMs": 16.3 },
  "searches": [
    {
      "id": 1, "documentType": "news", "nodes": 6, "backendTimeMs": 173.1,
      "nodeSummaries": [
        {
          "name": "content/news/0/0", "durationMs": 173.1,
          "tasks": { "globalFilterMs": 12.4, "annSetupMs": 8.2, "matchingMs": 61.7,
                     "firstPhaseMs": 9.8, "secondPhaseMs": 42.3 },
          "topFirstPhaseComponents": [ { "name": "bm25(news_body)", "count": 1, "selfTimeMs": 5.1 } ],
          "topSecondPhaseComponents": [ { "name": "rankingExpression(quality_model)", "count": 1, "selfTimeMs": 38.7 } ]
        }
      ]
    }
  ],
  "warnings": []
}

With this, a few lines of jq can answer questions that today require reading one table per query — e.g. comparing .timing.totalMs against a stored baseline in CI, or sorting .searches[].nodeSummaries by durationMs to surface outlier nodes.

This format is the programmatic counterpart of --make-prompt: --make-prompt renders the profile as a one-shot text report for a language model, while the JSON summary serves the same analyzed data to scripts and agents that consume it repeatedly — CI gates, cross-run comparisons, or a performance-tuning loop where component-level selfTimeMs names the exact ranking expression to change, followed by a re-run against the baseline. Both paths are needed; this is the structured one.

To be concrete about how I'd use it: this is already part of my workflow — I dump traces from my benchmark queries, convert each to a summary, and diff against a stored baseline when iterating on rank profiles. The natural extension is a tuning loop: the summary shows which phase and which ranking expression the time goes to, I adjust, re-run, and compare. The structured format is what keeps that loop scriptable (and potentially agent-assisted) instead of a manual read of one report per query.

On maintenance, I completely understand the concern about public API commitments, and I'd be glad to make this as cheap as possible — for example dropping schemaVersion and marking the flag experimental or hidden, if that's more acceptable. The parsing adds no new analysis: Summary() simply reuses the existing extractTiming, findProtonTraces, groupProtonTraces, extractSummary, selectSlowestThread and topN used by the human-readable output, so the change is essentially a struct plus serialization. And since this is a workflow I actually use, I'm happy to help maintain it as it evolves — addressing issues and keeping it in sync with upstream changes.

Since you know Vespa much better than I do, I'd also genuinely appreciate your guidance: if there is already a better approach for this (existing tooling for machine-readable profiling, or a different place this belongs), I'd be happy to follow it.

[bratseth]

To help me understand the purpose of this, it would be useful if you, the human running this, could explain if you personally have a specific non-hypothetical use of it.

[JamesbbBriz]

To help me understand the purpose of this, it would be useful if you, the human running this, could explain if you personally have a specific non-hypothetical use of it.

Yes. I’m currently building an evaluation and retrieval-tuning loop for a legal search product, and this JSON output is the performance input I’m using for it.

Right now I run a fixed set of Vespa queries, save the profile traces, and use this branch to produce compact JSON summaries so I can compare runs directly. I'm also wiring those summaries into an Optuna loop that tunes a small set of bounded parameters like totalTargetHits and totalRerankCount.

The loop is designed so that every trial runs the same evaluation. Trials that fall below my preregistered Recall@200 floor, or trip an existing quality-regression gate, are rejected. Among the ones that pass, Optuna minimizes latency.

The quality side and immutable run records were already in place. The missing piece was a compact, machine-readable performance summary — the CLI didn't expose one yet. Optuna picks the parameters; the JSON provides the measured performance data for each profiled query, which my evaluation harness aggregates for the trial.

--make-prompt is useful for LLM analysis, but Optuna and automated gates need exact numeric fields.

I added this for my own workflow first, then opened the PR because the same narrow output seemed useful for other repeatable profiling and regression workflows. Later, I may also feed it into an agent-assisted layer for structural changes that Optuna's parameter space cannot express.

[bratseth]

Thanks for the explanation. What information do you need from the trace for automatic tuning, I would think that the timing information - which is part of the API and much cheaper to obtain - would be enough?

[JamesbbBriz]

Thanks for the explanation. What information do you need from the trace for automatic tuning, I would think that the timing information - which is part of the API and much cheaper to obtain - would be enough?

Thanks, that makes sense. presentation.timing is enough if I only need the scalar objective for Optuna, and I do use it for that.

The reason I still want the profile data is that this is an offline tuning loop, not the serving path. For each change, I want to see not only whether it got faster or slower, but where the cost moved: across content nodes, matching, ANN setup, ranking phases, and individual profiled ranking components.

That makes the feedback much more useful. A change can improve total latency while making one stage worse, or shift cost from one part of the ranking pipeline to another. Seeing that breakdown lets me verify that an optimization affected the component I intended, and gives me a much better basis for making trade-off decisions than optimizing one top-level number in isolation.

I have a real case on file from a paired 600-query comparison where average latency went from 194.6 to 265.4 ms. The timing result told me clearly that it was slower, but not which phase or ranking component accounted for the extra time. That's exactly the kind of regression I want this output to make diagnosable on subsequent runs.

Profiling is more expensive, of course, but this is controlled eval and tuning work. presentation.timing is the cheap top-level metric Optuna optimizes; the profile JSON is the deeper feedback I can use when I need attribution and trade-off analysis. Later, the same signal could also feed an agent-assisted tuning layer.

[bratseth]

So, there are two needs:

• automated tuning, which uses the existing timing info in the result API.
• deeper manual analysis, by a human and/or LLM, which can use the existing text format, possibly with --make-prompt

It seems nothing is missing then?

[JamesbbBriz]

You're right about the Optuna part. I mixed up the number used for tuning with the data used to investigate a regression.

presentation.timing is enough for the latency objective. I would keep using that for every trial. The profile is only needed after a run gets slower and I want to find out where the time moved.

flowchart LR
    A["Fixed evaluation set"] --> B["presentation.timing"]
    B --> C["Quality gate + Optuna"]
    C -->|"Regression found"| D["Profile affected queries"]
    D --> E["TraceDoctor"]
    E --> F["Human report"]
    E --> G["--make-prompt"]
    E --> H["JSON summary"]
    H --> I["Compare runs"]
    H --> J["Calculate phase and component deltas"]
    H --> K["Save a diagnostic artifact"]

Loading

--make-prompt is useful when I want an LLM to read one profile. My case is a little different. I need to compare many profiles, calculate exact deltas, and decide which part needs investigation before calling an LLM.

For example, the timing result can tell me that a 600-query run went from 194.6 ms to 265.4 ms. It cannot tell my tooling whether the increase came from ANN setup, matching, first phase, second phase, one content node, or a particular ranking expression.

With structured output, a small program can make that decision first:

flowchart TD
    A["Baseline and candidate summaries"] --> B{"Which measurement changed?"}

    B -->|"totalMs or queryMs"| C["Timing + run settings"]
    B -->|"node duration skew"| D["Slowest and median nodes"]
    B -->|"globalFilterMs or annSetupMs"| E["ANN + filter settings"]
    B -->|"matchingMs"| F["YQL + query tree"]
    B -->|"firstPhaseMs"| G["First phase + top components"]
    B -->|"secondPhaseMs"| H["Second phase + top components"]
    B -->|"unexplained time"| I["Relevant timeline"]

    C --> J["Small context pack"]
    D --> J
    E --> J
    F --> J
    G --> J
    H --> J
    I --> J

    J --> K["Add rank-profile diff<br/>quality result<br/>run parameters"]
    K --> L["LLM explains the evidence"]
    L --> M["Propose one bounded experiment"]
    M --> N["Run the same evaluation"]
    N --> O{"Quality still passes<br/>and latency improves?"}
    O -->|"Yes"| P["Accept"]
    O -->|"No"| Q["Reject"]

Loading

This is the difference for me:

flowchart LR
    A["--make-prompt"] --> B["Give one rendered report to an LLM"]
    C["JSON summary"] --> D["Code selects the relevant evidence first"]
    D --> E["Give the LLM a smaller context pack"]

Loading

I could parse the text tables, but that would create an external parser for information TraceDoctor has already extracted. I could give every full report to an LLM, but that would cost more and the evidence selection would vary between runs.

That is the gap this PR fills. It makes TraceDoctor's analysis usable by tools that compare runs, locate where the cost moved, and assemble the right evidence for a closer look. The text output and --make-prompt remain useful for reading one report; the JSON output supports repeatable analysis across many of them.

[bratseth]

Thanks for the explanation - this makes sense.

[JamesbbBriz]

@bratseth, I rebased this onto current master and the focused Go tests pass locally; could you take another look and approve the blocked Buildkite run when you have a chance?