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.
This commit is contained in:
Max
parent
04c3114344
commit
9326f4b747
13 changed files with 533 additions and 107 deletions
|
|
@ -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)
|
||||
}
|
||||
}
|
||||
|
|
|
|||
|
|
@ -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
|
||||
}
|
||||
|
||||
|
|
|
|||
|
|
@ -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
|
||||
|
|
|
|||
|
|
@ -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")
|
||||
|
|
|
|||
|
|
@ -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 = `<!DOCTYPE html>
|
|||
<td>{{.DurationMs}}ms</td>
|
||||
<td>
|
||||
{{if .Error}}<div class="error-msg">{{.Error}}</div>{{end}}
|
||||
{{if and (ne (printf "%s" .Status) "passed") .Trace}}<details><summary>Trace</summary><pre style="white-space:pre-wrap;font-size:0.8rem;margin-top:0.5rem;color:var(--text-secondary);">{{traceJSON .Trace}}</pre></details>{{end}}
|
||||
</td>
|
||||
</tr>
|
||||
{{end}}
|
||||
|
|
|
|||
|
|
@ -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
|
||||
}
|
||||
|
|
|
|||
|
|
@ -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
|
||||
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)
|
||||
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
|
||||
|
|
|
|||
|
|
@ -207,9 +207,12 @@ func (r *ScriptRunner) Run() (*ScriptTestReport, error) {
|
|||
return nil, err
|
||||
}
|
||||
|
||||
// Print header
|
||||
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)
|
||||
}
|
||||
if !quiet {
|
||||
r.output.Info("Tests: %d functions (filtered by: %s)", len(tests), r.opts.Run)
|
||||
} else {
|
||||
}
|
||||
} 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,8 +245,10 @@ func (r *ScriptRunner) Run() (*ScriptTestReport, error) {
|
|||
if err != nil {
|
||||
return nil, fmt.Errorf("failed to load context file: %w", err)
|
||||
}
|
||||
if !quiet {
|
||||
r.output.Info("Context: %s", r.opts.ContextFile)
|
||||
}
|
||||
}
|
||||
|
||||
// Create environment with optional context config
|
||||
var env *Environment
|
||||
|
|
@ -250,8 +257,10 @@ func (r *ScriptRunner) Run() (*ScriptTestReport, error) {
|
|||
} else {
|
||||
env = NewEnvironment(r.opts.UserID, r.opts.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)
|
||||
}
|
||||
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
|
||||
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
|
||||
// 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 {
|
||||
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()
|
||||
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
|
||||
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()
|
||||
if !quiet {
|
||||
r.output.TestResult(result.Status, duration)
|
||||
r.output.TestError(result.Error)
|
||||
}
|
||||
return result
|
||||
}
|
||||
|
||||
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 {
|
||||
|
|
|
|||
|
|
@ -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"`
|
||||
|
||||
|
|
|
|||
|
|
@ -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)
|
||||
|
|
|
|||
|
|
@ -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 <agent_id> to specify the agent explicitly, to avoid ambiguity.
|
||||
|
||||
Modes:
|
||||
Direct message (-n <agent> -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 <agent> -i file.jsonl):
|
||||
Run test cases from a JSONL file with assertions and reporting.
|
||||
|
||||
Script test (-n <agent> --scripts <module>):
|
||||
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 <regex> 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 <id> 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 <id> 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 <id> 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 <file.json> 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 <agent> --scripts <module> into scripts.<agent>.<module>
|
||||
if testScripts != "" {
|
||||
if testAgent == "" {
|
||||
color.Red(L("Error: -n <agent> 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"))
|
||||
}
|
||||
|
|
|
|||
63
cmd/run.go
63
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] <process> [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 {
|
||||
|
|
|
|||
|
|
@ -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
|
||||
|
|
|
|||
Loading…
Add table
Reference in a new issue