feat(agents/invoke): display server response timing after successful invoke#8625
feat(agents/invoke): display server response timing after successful invoke#8625VBhadauria wants to merge 1 commit into
Conversation
b2e1f1e to
3581f23
Compare
|
@VBhadauria please read the following Contributor License Agreement(CLA). If you agree with the CLA, please reply with the following information.
Contributor License AgreementContribution License AgreementThis Contribution License Agreement (“Agreement”) is agreed to by the party signing below (“You”),
|
3581f23 to
58faa31
Compare
…invoke Show a green timing line after every successful azd ai agent invoke: ⏱ Server responded in 6.667s (first byte: 1.111s) Implementation: - Records time.Now() before HTTP request - Captures TTFB when response headers arrive - Captures total duration after full response body is consumed - Prints green timing via fatih/color (already used in extension) - Success-only: failures show error, no timing noise - Suppressed in --output raw mode (machine-consumable output) Covered paths: - responsesRemote (SSE streaming) - responsesLocal (JSON) - invocationsRemote (sync/SSE/LRO) - invocationsLocal (sync/SSE) Tests: - Unit: printInvokeTiming, formatDuration - Integration: responses local (success, failure, plain text, raw) - Integration: invocations local (sync JSON, SSE, failure, raw) - Timing sanity: non-zero values with simulated delay Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
58faa31 to
be06a46
Compare
There was a problem hiding this comment.
Pull request overview
Adds post-invoke latency visibility to the Azure AI Agents extension by printing a timing summary (total duration + TTFB) after successful azd ai agent invoke executions, while keeping --output raw clean.
Changes:
- Added
printInvokeTiming+formatDurationhelpers and wired timing instrumentation into all four invoke paths (responses/invocations × local/remote). - Captured TTFB immediately after
client.Do()returns and total duration after the full response body/stream is consumed. - Introduced new table-driven tests covering duration formatting, timing output formatting, and timing suppression on failures/raw mode.
Reviewed changes
Copilot reviewed 2 out of 2 changed files in this pull request and generated 4 comments.
| File | Description |
|---|---|
cli/azd/extensions/azure.ai.agents/internal/cmd/invoke.go |
Adds timing helpers and measures/prints TTFB + total duration on successful invoke flows (suppressed in raw mode). |
cli/azd/extensions/azure.ai.agents/internal/cmd/invoke_timing_test.go |
Adds unit/integration-style tests for timing formatting and for timing behavior across local invoke paths. |
| func withCapturedStdout(t *testing.T, fn func()) string { | ||
| t.Helper() | ||
| r, w, _ := os.Pipe() | ||
| orig := os.Stdout | ||
| os.Stdout = w | ||
| fn() | ||
| _ = w.Close() | ||
| os.Stdout = orig | ||
| out, _ := io.ReadAll(r) | ||
| _ = r.Close() | ||
| return string(out) | ||
| } |
| ) | ||
|
|
||
| func TestFormatDuration(t *testing.T) { | ||
| t.Parallel() |
|
|
||
| for _, tc := range cases { | ||
| t.Run(tc.want, func(t *testing.T) { | ||
| t.Parallel() |
| } | ||
|
|
||
| func TestPrintInvokeTiming(t *testing.T) { | ||
| t.Parallel() |
Summary
Display server response timing after every successful
azd ai agent invoke:Changes
invoke.goprintInvokeTiming(w, total, ttfb)— green timing line viafatih/color(already used in extension)formatDuration(d)— always formats as seconds with 3 decimal places (0.943s,6.667s)responsesRemote,responsesLocal,invocationsRemote,invocationsLocalclient.Do()returns (headers received)--output raw— machine-consumable output stays cleaninvoke_timing_test.goTable-driven tests covering:
formatDurationunit tests (0ms → 14.7s)printInvokeTimingoutput formatMotivation
Users have no visibility into agent latency during the quickstart. This surfaces:
Examples
⏱ Server responded in 6.775s (first byte: 1.101s)⏱ Server responded in 20.476s (first byte: 14.727s)⏱ Server responded in 0.943s (first byte: 0.943s)--output rawDependencies
github.com/fatih/color— already in use (eval.go,banner.go).