From 9326f4b747758c1abc6d2c1a352396ffc8214fbc Mon Sep 17 00:00:00 2001 From: Max Date: Tue, 28 Apr 2026 10:37:04 +0800 Subject: [PATCH] feat(logging): enhance logger output control and add trace diagnostics - Updated logger methods to respect the new `config.Silent` flag, allowing suppression of console output in development mode. - Refactored `buildTurnResponse` to utilize a shared `buildTrace` function for improved tool call association. - Introduced JSON output capabilities in `OutputWriter` for detailed trace and duration reporting. - Enhanced reporting mechanisms to include trace details in JSON and Markdown formats for better diagnostics. - Added support for a new `Trace` structure to capture detailed execution information, including tool calls and completion data. --- agent/robot/logger/logger.go | 12 ++-- agent/test/dynamic_runner.go | 43 +++---------- agent/test/dynamic_types.go | 16 +---- agent/test/output.go | 63 +++++++++++++++++++ agent/test/reporter.go | 60 +++++++++++++++++- agent/test/resolver.go | 15 +++++ agent/test/runner.go | 118 +++++++++++++++++++++++++++++++++-- agent/test/script.go | 88 ++++++++++++++++++++------ agent/test/script_types.go | 3 + agent/test/types.go | 37 +++++++++++ cmd/agent/test.go | 118 +++++++++++++++++++++++++++++++++-- cmd/run.go | 63 ++++++++++++------- config/config.go | 4 ++ 13 files changed, 533 insertions(+), 107 deletions(-) diff --git a/agent/robot/logger/logger.go b/agent/robot/logger/logger.go index 1df9313a..f2b6a176 100644 --- a/agent/robot/logger/logger.go +++ b/agent/robot/logger/logger.go @@ -47,7 +47,7 @@ func (l *Logger) prefix() string { func (l *Logger) Trace(format string, args ...interface{}) { msg := fmt.Sprintf(format, args...) - if config.IsDevelopment() { + if config.IsDevelopment() && !config.Silent { fmt.Printf("%s → %s %s%s\n", gray, l.prefix(), msg, reset) } kunlog.Trace("%s %s", l.prefix(), msg) @@ -55,7 +55,7 @@ func (l *Logger) Trace(format string, args ...interface{}) { func (l *Logger) Debug(format string, args ...interface{}) { msg := fmt.Sprintf(format, args...) - if config.IsDevelopment() { + if config.IsDevelopment() && !config.Silent { fmt.Printf("%s • %s %s%s\n", gray, l.prefix(), msg, reset) } kunlog.Debug("%s %s", l.prefix(), msg) @@ -63,7 +63,7 @@ func (l *Logger) Debug(format string, args ...interface{}) { func (l *Logger) Info(format string, args ...interface{}) { msg := fmt.Sprintf(format, args...) - if config.IsDevelopment() { + if config.IsDevelopment() && !config.Silent { fmt.Printf("%s ℹ %s %s%s\n", cyan, l.prefix(), msg, reset) } kunlog.Info("%s %s", l.prefix(), msg) @@ -71,7 +71,7 @@ func (l *Logger) Info(format string, args ...interface{}) { func (l *Logger) Warn(format string, args ...interface{}) { msg := fmt.Sprintf(format, args...) - if config.IsDevelopment() { + if config.IsDevelopment() && !config.Silent { fmt.Printf("%s ⚠ %s %s%s\n", yellow, l.prefix(), msg, reset) } kunlog.Warn("%s %s", l.prefix(), msg) @@ -79,7 +79,7 @@ func (l *Logger) Warn(format string, args ...interface{}) { func (l *Logger) Error(format string, args ...interface{}) { msg := fmt.Sprintf(format, args...) - if config.IsDevelopment() { + if config.IsDevelopment() && !config.Silent { fmt.Printf("%s ✗ %s %s%s\n", red, l.prefix(), msg, reset) } kunlog.Error("%s %s", l.prefix(), msg) @@ -94,7 +94,7 @@ func IsDev() bool { // Use for rich multi-line output (box-style logs, tables, etc.) // that should bypass the standard single-line prefix format. func Raw(s string) { - if config.IsDevelopment() { + if config.IsDevelopment() && !config.Silent { fmt.Print(s) } } diff --git a/agent/test/dynamic_runner.go b/agent/test/dynamic_runner.go index 2f52266c..41e84533 100644 --- a/agent/test/dynamic_runner.go +++ b/agent/test/dynamic_runner.go @@ -572,7 +572,8 @@ func (r *DynamicRunner) allRequiredCheckpointsReached(result *DynamicResult) boo return true } -// buildTurnResponse builds a TurnResponse from the agent response +// buildTurnResponse builds a TurnResponse from the agent response. +// Reuses the same merge logic as buildTrace to correctly associate parallel MCP calls. func buildTurnResponse(response *context.Response) *TurnResponse { if response == nil { return nil @@ -580,44 +581,16 @@ func buildTurnResponse(response *context.Response) *TurnResponse { tr := &TurnResponse{} - // Extract completion content if response.Completion != nil { tr.Content = response.Completion.Content - - // Extract tool calls from completion - if len(response.Completion.ToolCalls) > 0 { - for _, tc := range response.Completion.ToolCalls { - tr.ToolCalls = append(tr.ToolCalls, ToolCallInfo{ - Tool: tc.Function.Name, - Arguments: tc.Function.Arguments, - }) - } - } } - // Add tool results - if len(response.Tools) > 0 { - // If we already have tool calls from completion, match results - if len(tr.ToolCalls) > 0 { - for i, toolResult := range response.Tools { - if i < len(tr.ToolCalls) { - tr.ToolCalls[i].Result = toolResult.Result - } - } - } else { - // Create tool call entries from results - for _, toolResult := range response.Tools { - tr.ToolCalls = append(tr.ToolCalls, ToolCallInfo{ - Tool: toolResult.Tool, - Arguments: toolResult.Arguments, - Result: toolResult.Result, - }) - } - } - } - - // Extract Next hook data - if response.Next != nil && !isEmptyValue(response.Next) { + // Build tool call list with full details via the shared buildTrace helper + trace := buildTrace(response) + if trace != nil { + tr.ToolCalls = trace.ToolCalls + tr.Next = trace.Next + } else if response.Next != nil && !isEmptyValue(response.Next) { tr.Next = response.Next } diff --git a/agent/test/dynamic_types.go b/agent/test/dynamic_types.go index ea215779..79f2f4b2 100644 --- a/agent/test/dynamic_types.go +++ b/agent/test/dynamic_types.go @@ -55,25 +55,13 @@ type TurnResponse struct { // Content is the text content from LLM completion Content interface{} `json:"content,omitempty"` - // ToolCalls contains the tool calls made by the agent - ToolCalls []ToolCallInfo `json:"tool_calls,omitempty"` + // ToolCalls contains the tool calls made by the agent (uses TraceToolCall for full details) + ToolCalls []TraceToolCall `json:"tool_calls,omitempty"` // Next is the data returned from Next hook Next interface{} `json:"next,omitempty"` } -// ToolCallInfo contains information about a tool call -type ToolCallInfo struct { - // Tool is the tool name - Tool string `json:"tool"` - - // Arguments are the tool call arguments - Arguments interface{} `json:"arguments,omitempty"` - - // Result is the tool execution result - Result interface{} `json:"result,omitempty"` -} - // CheckpointResult represents the result of a checkpoint validation type CheckpointResult struct { // ID is the checkpoint identifier diff --git a/agent/test/output.go b/agent/test/output.go index aaedcf04..70a9611e 100644 --- a/agent/test/output.go +++ b/agent/test/output.go @@ -257,6 +257,69 @@ func (w *OutputWriter) DirectOutput(output interface{}) { } } +// DirectOutputJSON outputs a complete JSON object with output, trace and duration. +// Designed for AI/script consumption via --json flag. +func (w *OutputWriter) DirectOutputJSON(output interface{}, trace *Trace, duration time.Duration) { + payload := map[string]interface{}{ + "output": output, + "duration_ms": duration.Milliseconds(), + } + if trace != nil { + payload["trace"] = trace + } + jsonBytes, err := jsoniter.MarshalIndent(payload, "", " ") + if err != nil { + fmt.Printf("%v\n", output) + return + } + fmt.Println(string(jsonBytes)) +} + +// DirectTrace prints a human-readable summary of tool calls from a Trace. +// Only prints when there are tool calls; skipped when trace is nil or empty. +func (w *OutputWriter) DirectTrace(trace *Trace) { + if trace == nil || len(trace.ToolCalls) == 0 { + return + } + + fmt.Println() + color.New(color.FgHiBlack).Println("--- Tool Calls ---") + for _, tc := range trace.ToolCalls { + prefix := tc.Tool + if tc.Server != "" { + prefix = tc.Server + "/" + tc.Tool + } + + status := "OK" + if tc.Error != "" { + status = "ERR: " + truncateString(tc.Error, 60) + } + + argsStr := "" + if tc.Arguments != nil { + if b, err := jsoniter.Marshal(tc.Arguments); err == nil { + argsStr = truncateString(string(b), 80) + } + } + + if argsStr != "" { + color.New(color.FgHiBlack).Printf(" %s → %s (args: %s)\n", prefix, status, argsStr) + } else { + color.New(color.FgHiBlack).Printf(" %s → %s\n", prefix, status) + } + } +} + +// ScriptOutputJSON outputs the complete script test report as JSON. +func (w *OutputWriter) ScriptOutputJSON(report *ScriptTestReport) { + jsonBytes, err := jsoniter.MarshalIndent(report, "", " ") + if err != nil { + fmt.Printf("{\"error\": %q}\n", err.Error()) + return + } + fmt.Println(string(jsonBytes)) +} + // ScriptTestSummary prints the script test summary func (w *OutputWriter) ScriptTestSummary(summary *ScriptTestSummary, duration time.Duration) { w.SubHeader("Summary") diff --git a/agent/test/reporter.go b/agent/test/reporter.go index d1a16dfe..cb47fe19 100644 --- a/agent/test/reporter.go +++ b/agent/test/reporter.go @@ -57,6 +57,9 @@ func (r *JSONLReporter) Write(report *Report, w io.Writer) error { if result.Error != "" { resultEvent["error"] = result.Error } + if result.Trace != nil { + resultEvent["trace"] = result.Trace + } if err := writeJSONLineToWriter(writer, resultEvent); err != nil { return err } @@ -220,6 +223,11 @@ func (r *MarkdownReporter) Write(report *Report, w io.Writer) error { if result.Error != "" { sb.WriteString(fmt.Sprintf("**Error:** %s\n\n", result.Error)) } + + // Expand Trace for non-passed cases + if result.Status != StatusPassed && result.Trace != nil { + writeMarkdownTrace(&sb, result.Trace) + } } } @@ -252,6 +260,43 @@ func (r *MarkdownReporter) Write(report *Report, w io.Writer) error { return err } +// writeMarkdownTrace writes a Trace section in Markdown format. +func writeMarkdownTrace(sb *strings.Builder, trace *Trace) { + if trace.Completion != nil { + sb.WriteString("**Completion**\n\n") + if trace.Completion.Model != "" { + sb.WriteString(fmt.Sprintf("- Model: `%s`\n", trace.Completion.Model)) + } + if trace.Completion.Refusal != "" { + sb.WriteString(fmt.Sprintf("- Refusal: %s\n", trace.Completion.Refusal)) + } + if trace.Completion.ReasoningContent != "" { + sb.WriteString(fmt.Sprintf("- Reasoning: %s\n", truncateString(trace.Completion.ReasoningContent, 200))) + } + sb.WriteString("\n") + } + + if len(trace.ToolCalls) > 0 { + sb.WriteString("**Tool Calls**\n\n") + sb.WriteString("| Server | Tool | Status | Arguments |\n") + sb.WriteString("| ------ | ---- | ------ | --------- |\n") + for _, tc := range trace.ToolCalls { + status := "OK" + if tc.Error != "" { + status = "ERR: " + truncateString(tc.Error, 40) + } + argsStr := "" + if tc.Arguments != nil { + if b, err := jsoniter.Marshal(tc.Arguments); err == nil { + argsStr = truncateString(string(b), 60) + } + } + sb.WriteString(fmt.Sprintf("| %s | %s | %s | `%s` |\n", tc.Server, tc.Tool, status, argsStr)) + } + sb.WriteString("\n") + } +} + // HTMLReporter generates HTML format reports type HTMLReporter struct{} @@ -267,7 +312,19 @@ func (r *HTMLReporter) Generate(report *Report) error { // Write writes the report in HTML format func (r *HTMLReporter) Write(report *Report, w io.Writer) error { - tmpl, err := template.New("report").Parse(htmlTemplate) + funcMap := template.FuncMap{ + "traceJSON": func(trace *Trace) string { + if trace == nil { + return "" + } + b, err := jsoniter.MarshalIndent(trace, "", " ") + if err != nil { + return err.Error() + } + return string(b) + }, + } + tmpl, err := template.New("report").Funcs(funcMap).Parse(htmlTemplate) if err != nil { return fmt.Errorf("failed to parse HTML template: %w", err) } @@ -489,6 +546,7 @@ const htmlTemplate = ` {{.DurationMs}}ms {{if .Error}}
{{.Error}}
{{end}} + {{if and (ne (printf "%s" .Status) "passed") .Trace}}
Trace
{{traceJSON .Trace}}
{{end}} {{end}} diff --git a/agent/test/resolver.go b/agent/test/resolver.go index 7104d3a1..32d837ee 100644 --- a/agent/test/resolver.go +++ b/agent/test/resolver.go @@ -323,6 +323,21 @@ func MergeOptions(opts *Options, defaults *Options) *Options { if opts.FailFast { result.FailFast = opts.FailFast } + if opts.BeforeAll != "" { + result.BeforeAll = opts.BeforeAll + } + if opts.AfterAll != "" { + result.AfterAll = opts.AfterAll + } + if opts.DryRun { + result.DryRun = opts.DryRun + } + if opts.Simulator != "" { + result.Simulator = opts.Simulator + } + if opts.JSONOutput { + result.JSONOutput = opts.JSONOutput + } return &result } diff --git a/agent/test/runner.go b/agent/test/runner.go index 5fc9b242..f34410df 100644 --- a/agent/test/runner.go +++ b/agent/test/runner.go @@ -63,6 +63,10 @@ func (r *Executor) RunScriptTests() (*Report, error) { // Convert to standard report for unified output handling report := scriptReport.ToReport() + if r.opts.JSONOutput { + r.output.ScriptOutputJSON(scriptReport) + } + // Write output if specified if r.opts.OutputFile != "" { err = r.writeOutput(report) @@ -73,8 +77,9 @@ func (r *Executor) RunScriptTests() (*Report, error) { } } - // Print final result - r.output.FinalResult(!report.HasFailures()) + if !r.opts.JSONOutput { + r.output.FinalResult(!report.HasFailures()) + } return report, nil } @@ -119,6 +124,7 @@ func (r *Executor) RunDirect() (*Report, error) { } // Run the agent + start := time.Now() response, err := ast.Stream(ctx, messages, opts) // Check for timeout @@ -131,9 +137,17 @@ func (r *Executor) RunDirect() (*Report, error) { return nil, err } - // Extract and print output directly + // Extract output and build trace output := extractOutput(response) - r.output.DirectOutput(output) + trace := buildTrace(response) + duration := time.Since(start) + + if r.opts.JSONOutput { + r.output.DirectOutputJSON(output, trace, duration) + } else { + r.output.DirectOutput(output) + r.output.DirectTrace(trace) + } // Determine connector: user-specified > agent default connector := r.opts.Connector @@ -499,8 +513,9 @@ func (r *Executor) runSingleTest(ast *assistant.Assistant, tc *Case, agentID str return result } - // Extract output + // Extract output and build trace for diagnostics result.Output = extractOutput(response) + result.Trace = buildTrace(response) // Validate result using asserter (with response for tool_called assertions) asserter := NewAsserter().WithResponse(response) @@ -857,6 +872,99 @@ func isEmptyValue(v interface{}) bool { return false } +// buildTrace builds a Trace from the full agent response. +// It merges Completion.ToolCalls (request-side: ID, name, arguments) with +// response.Tools (result-side: server, result, error) by matching ToolCallID, +// so parallel MCP calls are correctly associated. +func buildTrace(response *context.Response) *Trace { + if response == nil { + return nil + } + + trace := &Trace{} + + if response.Completion != nil { + trace.Completion = &CompletionTrace{ + Model: response.Completion.Model, + Role: response.Completion.Role, + Content: response.Completion.Content, + ReasoningContent: response.Completion.ReasoningContent, + Refusal: response.Completion.Refusal, + } + } + + // Build tool call index from results keyed by ToolCallID + resultByID := make(map[string]*context.ToolCallResponse, len(response.Tools)) + for i := range response.Tools { + if response.Tools[i].ToolCallID != "" { + resultByID[response.Tools[i].ToolCallID] = &response.Tools[i] + } + } + + // Merge request-side (Completion.ToolCalls) with result-side (response.Tools) + if response.Completion != nil && len(response.Completion.ToolCalls) > 0 { + for i, tc := range response.Completion.ToolCalls { + var args interface{} + if tc.Function.Arguments != "" { + if err := jsoniter.UnmarshalFromString(tc.Function.Arguments, &args); err != nil { + args = tc.Function.Arguments + } + } + entry := TraceToolCall{ + ID: tc.ID, + Tool: tc.Function.Name, + Arguments: args, + } + if r, ok := resultByID[tc.ID]; ok { + entry.Server = r.Server + entry.Result = r.Result + entry.Error = r.Error + } else if i < len(response.Tools) { + entry.Server = response.Tools[i].Server + entry.Result = response.Tools[i].Result + entry.Error = response.Tools[i].Error + } + entry.Tool = stripServerPrefix(entry.Tool, entry.Server) + trace.ToolCalls = append(trace.ToolCalls, entry) + } + } else if len(response.Tools) > 0 { + for _, t := range response.Tools { + trace.ToolCalls = append(trace.ToolCalls, TraceToolCall{ + ID: t.ToolCallID, + Server: t.Server, + Tool: stripServerPrefix(t.Tool, t.Server), + Arguments: t.Arguments, + Result: t.Result, + Error: t.Error, + }) + } + } + + if response.Next != nil && !isEmptyValue(response.Next) { + trace.Next = response.Next + } + + if trace.Completion == nil && len(trace.ToolCalls) == 0 && trace.Next == nil { + return nil + } + + return trace +} + +// stripServerPrefix removes the "{server}__" prefix from an encoded tool name. +// MCP tools are internally encoded as "server__tool" (e.g. "echo__ping"), +// but for trace output we display the original tool name since server is a separate field. +func stripServerPrefix(tool, server string) string { + if server == "" { + return tool + } + prefix := server + "__" + if strings.HasPrefix(tool, prefix) { + return tool[len(prefix):] + } + return tool +} + // validateOutput validates the actual output against expected func validateOutput(actual, expected interface{}) bool { // Simple JSON comparison diff --git a/agent/test/script.go b/agent/test/script.go index 4e4bec99..038fc303 100644 --- a/agent/test/script.go +++ b/agent/test/script.go @@ -207,9 +207,12 @@ func (r *ScriptRunner) Run() (*ScriptTestReport, error) { return nil, err } - // Print header - r.output.Header("Script Test") - r.output.Info("Script: %s", scriptInfo.TestPath) + quiet := r.opts.JSONOutput + + if !quiet { + r.output.Header("Script Test") + r.output.Info("Script: %s", scriptInfo.TestPath) + } // Discover tests tests, err := DiscoverTests(scriptInfo.TestPath) @@ -223,12 +226,14 @@ func (r *ScriptRunner) Run() (*ScriptTestReport, error) { if err != nil { return nil, fmt.Errorf("invalid -run pattern: %w", err) } - r.output.Info("Tests: %d functions (filtered by: %s)", len(tests), r.opts.Run) - } else { + if !quiet { + r.output.Info("Tests: %d functions (filtered by: %s)", len(tests), r.opts.Run) + } + } else if !quiet { r.output.Info("Tests: %d functions", len(tests)) } - if len(tests) == 0 { + if len(tests) == 0 && !quiet { r.output.Warning("No tests to run") } @@ -240,7 +245,9 @@ func (r *ScriptRunner) Run() (*ScriptTestReport, error) { if err != nil { return nil, fmt.Errorf("failed to load context file: %w", err) } - r.output.Info("Context: %s", r.opts.ContextFile) + if !quiet { + r.output.Info("Context: %s", r.opts.ContextFile) + } } // Create environment with optional context config @@ -250,8 +257,10 @@ func (r *ScriptRunner) Run() (*ScriptTestReport, error) { } else { env = NewEnvironment(r.opts.UserID, r.opts.TeamID) } - r.output.Info("User: %s", env.UserID) - r.output.Info("Team: %s", env.TeamID) + if !quiet { + r.output.Info("User: %s", env.UserID) + r.output.Info("Team: %s", env.TeamID) + } // Load all scripts from src directory (including the test file) // This ensures imports can be resolved properly @@ -260,7 +269,9 @@ func (r *ScriptRunner) Run() (*ScriptTestReport, error) { if err != nil { return nil, fmt.Errorf("failed to load scripts: %w", err) } - r.output.Info("Loaded: %d scripts", loadedCount) + if !quiet { + r.output.Info("Loaded: %d scripts", loadedCount) + } // Create report report := &ScriptTestReport{ @@ -276,7 +287,9 @@ func (r *ScriptRunner) Run() (*ScriptTestReport, error) { } // Run tests - r.output.SubHeader("Running Tests") + if !quiet { + r.output.SubHeader("Running Tests") + } for _, tc := range tests { result := r.runScriptTest(tc, scriptInfo, env) @@ -304,15 +317,20 @@ func (r *ScriptRunner) Run() (*ScriptTestReport, error) { report.Summary.DurationMs = time.Since(startTime).Milliseconds() report.Metadata.CompletedAt = time.Now() - // Print summary - r.output.ScriptTestSummary(report.Summary, time.Since(startTime)) + // Print summary (skip in JSON mode, handled by caller) + if !r.opts.JSONOutput { + r.output.ScriptTestSummary(report.Summary, time.Since(startTime)) + } return report, nil } // runScriptTest runs a single script test function func (r *ScriptRunner) runScriptTest(tc *ScriptTestCase, scriptInfo *ScriptInfo, env *Environment) *ScriptTestResult { - r.output.TestStart(tc.Name, "", 1) + quiet := r.opts.JSONOutput + if !quiet { + r.output.TestStart(tc.Name, "", 1) + } startTime := time.Now() result := &ScriptTestResult{ @@ -338,14 +356,24 @@ func (r *ScriptRunner) runScriptTest(tc *ScriptTestCase, scriptInfo *ScriptInfo, if err != nil { result.Status = StatusError result.Error = err.Error() - r.output.TestResult(result.Status, duration) - r.output.TestError(result.Error) + if jse, ok := err.(*jsErrorWithTrace); ok { + result.StackTrace = jse.stackTrace + } + if !quiet { + r.output.TestResult(result.Status, duration) + r.output.TestError(result.Error) + if result.StackTrace != "" { + r.output.TestError(result.StackTrace) + } + } return result } if testingT.Skipped() { result.Status = StatusSkipped - r.output.TestResult(result.Status, duration) + if !quiet { + r.output.TestResult(result.Status, duration) + } return result } @@ -356,12 +384,16 @@ func (r *ScriptRunner) runScriptTest(tc *ScriptTestCase, scriptInfo *ScriptInfo, result.Error = errors[0] } result.Assertion = testingT.AssertionInfo() - r.output.TestResult(result.Status, duration) - r.output.TestError(result.Error) + if !quiet { + r.output.TestResult(result.Status, duration) + r.output.TestError(result.Error) + } return result } - r.output.TestResult(result.Status, duration) + if !quiet { + r.output.TestResult(result.Status, duration) + } return result } @@ -516,6 +548,12 @@ func (r *ScriptRunner) executeTestFunction(tc *ScriptTestCase, scriptInfo *Scrip // Assertion failure - already recorded return nil } + if jserr, ok := err.(*v8go.JSError); ok { + return &jsErrorWithTrace{ + message: jserr.Message, + stackTrace: v8.StackTrace(jserr, nil), + } + } return fmt.Errorf("test function error: %w", err) } @@ -542,6 +580,16 @@ func RegisterTestingGlobals() { v8.RegisterFunction("__testing_log", testingLogEmbed) } +// jsErrorWithTrace wraps a V8 JS error with source-mapped stack trace +type jsErrorWithTrace struct { + message string + stackTrace string +} + +func (e *jsErrorWithTrace) Error() string { + return e.message +} + // testingLogEmbed provides a console.log-like function for tests func testingLogEmbed(iso *v8go.Isolate) *v8go.FunctionTemplate { return v8go.NewFunctionTemplate(iso, func(info *v8go.FunctionCallbackInfo) *v8go.Value { diff --git a/agent/test/script_types.go b/agent/test/script_types.go index 27531ebc..abc85114 100644 --- a/agent/test/script_types.go +++ b/agent/test/script_types.go @@ -43,6 +43,9 @@ type ScriptTestResult struct { // Error contains the error message if the test failed Error string `json:"error,omitempty"` + // StackTrace contains the source-mapped stack trace for runtime errors + StackTrace string `json:"stack_trace,omitempty"` + // Assertion contains assertion failure details Assertion *ScriptAssertionInfo `json:"assertion,omitempty"` diff --git a/agent/test/types.go b/agent/test/types.go index 1f5c25bb..dc773f25 100644 --- a/agent/test/types.go +++ b/agent/test/types.go @@ -160,6 +160,9 @@ type Options struct { // Simulator is the default simulator agent ID for dynamic mode // Can be overridden per test case in JSONL Simulator string `json:"simulator,omitempty"` + + // JSONOutput outputs results in JSON format for AI/script consumption + JSONOutput bool `json:"json_output,omitempty"` } // ContextConfig represents custom context configuration from JSON file @@ -642,6 +645,10 @@ type Result struct { // Error contains the error message if status is failed/error/timeout Error string `json:"error,omitempty"` + // Trace contains full execution details for AI-driven failure diagnosis. + // Includes LLM completion info, all tool/MCP calls with arguments and results, and Next hook data. + Trace *Trace `json:"trace,omitempty"` + // Options contains the context options used for this test case Options *CaseOptions `json:"options,omitempty"` @@ -649,6 +656,36 @@ type Result struct { Metadata map[string]interface{} `json:"metadata,omitempty"` } +// Trace contains full execution details for AI-driven failure diagnosis. +// It captures the complete chain: LLM completion -> tool/MCP calls -> Next hook, +// enabling AI to understand exactly what happened during test execution. +type Trace struct { + Completion *CompletionTrace `json:"completion,omitempty"` + ToolCalls []TraceToolCall `json:"tool_calls,omitempty"` + Next interface{} `json:"next,omitempty"` +} + +// CompletionTrace captures LLM completion details. +type CompletionTrace struct { + Model string `json:"model,omitempty"` + Role string `json:"role,omitempty"` + Content interface{} `json:"content,omitempty"` + ReasoningContent string `json:"reasoning_content,omitempty"` + Refusal string `json:"refusal,omitempty"` +} + +// TraceToolCall contains the complete lifecycle of a single tool/MCP call: +// request (ID, arguments) matched with response (server, result, error). +// MCP tool calls may execute in parallel; the ID field links request to response. +type TraceToolCall struct { + ID string `json:"id,omitempty"` + Server string `json:"server,omitempty"` + Tool string `json:"tool"` + Arguments interface{} `json:"arguments,omitempty"` + Result interface{} `json:"result,omitempty"` + Error string `json:"error,omitempty"` +} + // RunDetail represents the result of a single run in stability testing type RunDetail struct { // Run is the run number (1-based) diff --git a/cmd/agent/test.go b/cmd/agent/test.go index ebe543d1..7485e048 100644 --- a/cmd/agent/test.go +++ b/cmd/agent/test.go @@ -37,20 +37,128 @@ var ( testAfter string // --after flag for global AfterAll hook testDryRun bool // --dry-run flag for generating tests without running testSimulator string // --simulator flag for default simulator agent in dynamic mode + testJSON bool // --json flag for machine-readable JSON output + testScripts string // --scripts flag for script unit test module ) // TestCmd is the agent test command var TestCmd = &cobra.Command{ Use: "test", Short: L("Test an agent with input cases"), - Long: L("Test an agent with input cases from JSONL file or direct message"), + Long: L(`Test an agent with input cases from JSONL file or direct message. + +IMPORTANT: Run this command from the Yao application root directory (where app.yao is located). + Always use -n to specify the agent explicitly, to avoid ambiguity. + +Modes: + Direct message (-n -i 'message'): + Send a single message to the agent and print the response. + The -n flag specifies the agent ID (e.g. myagent, folder.subagent). + + File mode (-n -i file.jsonl): + Run test cases from a JSONL file with assertions and reporting. + + Script test (-n --scripts ): + Run unit tests defined in the agent's src/*_test.ts files. + -n specifies the agent, --scripts specifies the module name. + This discovers and executes all Test* functions in the corresponding _test.ts file. + Each test function receives (t: testing.T, ctx: agent.Context). + Use --run to filter which Test* functions to run. + + Examples: + -n myagent --scripts tools -> assistants/myagent/src/tools_test.ts + -n myagent.sub --scripts seed -> assistants/myagent/sub/src/seed_test.ts + + Legacy syntax (also supported): + -i scripts.myagent.tools -> same as -n myagent --scripts tools + +Common flags: + -c, --connector Override the LLM connector for this test run. The connector ID + corresponds to a connector defined in the application (e.g. gpt4o, claude, deepseek). + If not specified, the agent's default connector is used. + This is useful for testing the same agent against different models. + + -u, --user Set the user ID for the test context (default: "test-user"). + The agent sees this as the current user identity. Useful for testing + permission-related logic or user-specific behavior. + + -t, --team Set the team ID for the test context (default: "test-team"). + The agent sees this as the current team. Useful for testing + team-scoped data access or multi-tenant logic. + + --ctx Provide a full context JSON file for fine-grained control over the + test session. Allows setting authorization details (sub, scope, client_id, + session_id, constraints), metadata, client info, and locale. + -u/-t are convenient shortcuts for user_id/team_id only. + When both are provided, --ctx authorized.user_id/team_id take precedence + over -u/-t for the authorization layer. + JSON structure: + { + "chat_id": "session-1", + "authorized": { + "user_id": "admin", "team_id": "ops", + "sub": "jwt-sub", "client_id": "app-1", + "scope": "full", "session_id": "sess-1", + "constraints": { "owner_only": true, "team_only": true } + }, + "metadata": { "key": "value" }, + "locale": "en-us" + } + +AI Integration (recommended flags): + --json Output full JSON with trace diagnostics (completion details, all MCP tool calls + with server/arguments/results/errors, and Next hook data). Use this when an AI + agent needs to analyze test results programmatically. + + Console output is automatically silenced ([robot:*] suppressed) in test mode. + + Example (AI debugging a single agent call): + yao agent test -n myagent -i 'what is the weather in Shanghai' --json + + Example (AI with specific connector): + yao agent test -n myagent -i 'hello' -c gpt4o --json + + Example (AI running test suite): + yao agent test -n myagent -i tests/myagent.jsonl -o results.json --json + + Example (AI running script unit tests): + yao agent test -n myagent --scripts tools --json + yao agent test -n myagent --scripts tools --run TestRecognize --json + + Example (human: E2E): + yao agent test -n myagent -i 'hello' -v + + Example (human: script test): + yao agent test -n myagent --scripts tools + yao agent test -n myagent --scripts tools --run TestRecognize + +Output formats for file mode (-o flag extension): + .jsonl JSONL streaming events (default, includes trace on each result) + .json Full JSON report (includes trace on each result) + .md Markdown report (failed cases expand trace: tool call table + completion summary) + .html HTML report (failed cases have collapsible trace details)`), Run: func(cmd *cobra.Command, args []string) { defer share.SessionStop() defer plugin.KillAll() + // Suppress [robot:*] and other noisy console output during tests + config.Silent = true + + // --scripts mode: combine -n --scripts into scripts.. + if testScripts != "" { + if testAgent == "" { + color.Red(L("Error: -n is required when using --scripts") + "\n\n") + cmd.Help() + os.Exit(1) + } + testInput = "scripts." + testAgent + "." + testScripts + testAgent = "" + } + // Validate input if testInput == "" { - color.Red(L("Error: input is required (-i flag)") + "\n") + color.Red(L("Error: input (-i) or --scripts flag is required") + "\n\n") + cmd.Help() os.Exit(1) } @@ -165,6 +273,7 @@ var TestCmd = &cobra.Command{ AfterAll: testAfter, DryRun: testDryRun, Simulator: testSimulator, + JSONOutput: testJSON, } // Merge with defaults @@ -256,7 +365,6 @@ func init() { TestCmd.Flags().StringVar(&testAfter, "after", "", L("Global AfterAll hook (e.g., env_test.AfterAll)")) TestCmd.Flags().BoolVar(&testDryRun, "dry-run", false, L("Generate test cases without running them")) TestCmd.Flags().StringVar(&testSimulator, "simulator", "", L("Default simulator agent for dynamic mode (e.g., tests.simulator-agent)")) - - // Mark input as required - TestCmd.MarkFlagRequired("input") + TestCmd.Flags().BoolVar(&testJSON, "json", false, L("Output full JSON with trace diagnostics: completion, MCP tool calls (server/args/result/error), Next hook (recommended for AI)")) + TestCmd.Flags().StringVar(&testScripts, "scripts", "", L("Script module to test (use with -n): -n expense --scripts tools → runs assistants/expense/src/tools_test.ts")) } diff --git a/cmd/run.go b/cmd/run.go index aba87dd7..0d3edd9a 100644 --- a/cmd/run.go +++ b/cmd/run.go @@ -28,9 +28,49 @@ var runAuthPath string var runCmd = &cobra.Command{ Use: "run", Short: L("Execute process"), - Long: L("Execute process"), + Long: L(`Execute a Yao process by name with optional arguments. + +IMPORTANT: Run this command from the Yao application root directory (where app.yao is located), + or use the -a flag to specify the application path. + +Usage: + yao run [flags] [args...] + +Arguments: + Arguments are passed positionally to the process. Each argument is parsed as follows: + - Plain string: passed as-is (e.g. hello → "hello") + - Numeric string: auto-converted to number (e.g. 42 → 42) + - ::{ ... } prefix: parsed as JSON object (e.g. '::{\"name\":\"test\"}' → map) + - ::[ ... ] prefix: parsed as JSON array (e.g. '::[1,2,3]' → []int) + + The :: prefix is REQUIRED when passing structured data (objects, arrays, query params). + Without ::, the argument is treated as a plain string, not parsed as JSON. + + Examples: + yao run models.user.Find 1 '::{"select":["id","name"]}' + yao run models.user.Create '::{"name":"test","age":20}' + yao run scripts.demo.Hello world 42 + +AI Integration: + When called by AI agents or automated scripts, use --silent (-s) to suppress + [robot:*] and other noisy console output that interferes with result parsing. + Only the process return value is printed to stdout in silent mode. + + Example (AI recommended): + yao run -s models.user.Find 1 '::{"select":["id","name"]}' + yao run -s models.user.Create '::{"name":"test","status":"active"}'`), Run: func(cmd *cobra.Command, args []string) { + // Propagate silent flag to global config so libraries + // (e.g. agent/robot/logger) can suppress stdout output. + config.Silent = runSilent + + if len(args) < 1 { + color.Red(L("Error: process name is required") + "\n\n") + cmd.Help() + os.Exit(1) + } + // Resolve credential: --auth flag > ~/.yao/credentials > nil (local mode) cred := resolveCredential() @@ -44,7 +84,7 @@ var runCmd = &cobra.Command{ } func init() { - runCmd.PersistentFlags().BoolVarP(&runSilent, "silent", "s", false, L("Silent mode")) + runCmd.PersistentFlags().BoolVarP(&runSilent, "silent", "s", false, L("Silent mode: suppress [robot:*] and other noisy console output (recommended for AI/scripts)")) runCmd.PersistentFlags().StringVar(&runAuthPath, "auth", "", L("Path to credentials file")) } @@ -65,16 +105,6 @@ func resolveCredential() *Credential { // runGRPC executes a process via the remote gRPC server. func runGRPC(cred *Credential, args []string) { - if len(args) < 1 { - if !runSilent { - color.Red(L("Not enough arguments\n")) - color.White(share.BUILDNAME + " help\n") - } else { - fmt.Print(L("Not enough arguments\n")) - } - os.Exit(1) - } - if cred.GRPCAddr == "" { color.Red(" %s\n", L("No gRPC address in credentials. Please re-login.")) os.Exit(1) @@ -161,15 +191,6 @@ func runLocal(args []string) { cfg := config.Conf cfg.Session.IsCLI = true - if len(args) < 1 { - if !runSilent { - color.Red(L("Not enough arguments\n")) - color.White(share.BUILDNAME + " help\n") - return - } - fmt.Print(L("Not enough arguments\n")) - return - } loadWarnings, err := engine.Load(cfg, engine.LoadOption{Action: "run"}) if err != nil { diff --git a/config/config.go b/config/config.go index 96f8a373..3dd3f732 100644 --- a/config/config.go +++ b/config/config.go @@ -284,3 +284,7 @@ func CloseLog() { func IsDevelopment() bool { return Conf.Mode == "development" } + +// Silent indicates whether stdout output should be suppressed +// (set by `yao run -s/--silent`). +var Silent bool