-
Notifications
You must be signed in to change notification settings - Fork 289
Add raw flag to monitor command and implement log formatting for SSE on azd ai agent monitor #7210
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,151 @@ | ||
| // Copyright (c) Microsoft Corporation. All rights reserved. | ||
| // Licensed under the MIT License. | ||
|
|
||
| package cmd | ||
|
|
||
| import ( | ||
| "encoding/json" | ||
| "fmt" | ||
| "strings" | ||
| "time" | ||
|
|
||
| "github.com/fatih/color" | ||
| ) | ||
|
|
||
| // logStreamEntry represents a container log line (stdout, stderr, or status message). | ||
| type logStreamEntry struct { | ||
| Timestamp string `json:"timestamp"` | ||
| Stream string `json:"stream"` | ||
| Message string `json:"message"` | ||
| } | ||
|
|
||
| // logSessionEntry represents a session-level status event. | ||
| type logSessionEntry struct { | ||
| Timestamp string `json:"timestamp"` | ||
| SessionID string `json:"session_id"` | ||
| SessionState string `json:"session_state"` | ||
| Agent string `json:"agent"` | ||
| Version string `json:"version"` | ||
| LastAccessed string `json:"last_accessed"` | ||
| } | ||
|
|
||
| // logFormatter parses SSE log lines from the monitor stream and produces | ||
| // human-readable, color-coded output. | ||
| type logFormatter struct { | ||
| pendingEvent string // last seen "event: <type>" value | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. [LOW] Written and cleared but never read - no formatting decision uses the event type. If it's planned for future use, a TODO would help; otherwise it can go. |
||
|
|
||
| // Color printers, auto-disabled when NO_COLOR is set or stdout is not a TTY. | ||
| dimColor *color.Color | ||
| stderrColor *color.Color | ||
| statusColor *color.Color | ||
| sessionColor *color.Color | ||
| } | ||
|
|
||
| func newLogFormatter() *logFormatter { | ||
| return &logFormatter{ | ||
| dimColor: color.New(color.Faint), | ||
| stderrColor: color.New(color.FgRed), | ||
| statusColor: color.New(color.FgCyan), | ||
| sessionColor: color.New(color.FgGreen), | ||
| } | ||
| } | ||
|
|
||
| // formatLine processes a single raw line from the SSE stream. | ||
| // Returns the formatted string to print, or empty string if the line | ||
| // should be suppressed (e.g. an "event:" prefix line). | ||
| func (f *logFormatter) formatLine(line string) string { | ||
| // SSE event prefix — remember it for the next data line. | ||
| if after, ok := strings.CutPrefix(line, "event: "); ok { | ||
| f.pendingEvent = strings.TrimSpace(after) | ||
| return "" | ||
| } | ||
|
|
||
| // SSE data payload — parse and format. | ||
| if data, ok := strings.CutPrefix(line, "data: "); ok { | ||
| defer func() { f.pendingEvent = "" }() | ||
| return f.formatData(data) | ||
| } | ||
|
|
||
| // Blank lines are SSE event separators — suppress. | ||
| if strings.TrimSpace(line) == "" { | ||
| return "" | ||
| } | ||
|
|
||
| // Anything else (unexpected format) — pass through as-is. | ||
| return line | ||
| } | ||
|
|
||
| // formatData parses the JSON payload from a "data: " line and returns | ||
| // a formatted string. Falls back to the raw data on parse failure. | ||
| func (f *logFormatter) formatData(data string) string { | ||
| // Try stream entry first (most common). | ||
| var stream logStreamEntry | ||
| if err := json.Unmarshal([]byte(data), &stream); err == nil && stream.Stream != "" { | ||
| return f.formatStreamEntry(&stream) | ||
| } | ||
|
|
||
| // Try session status entry. | ||
| var session logSessionEntry | ||
| if err := json.Unmarshal([]byte(data), &session); err == nil && session.SessionState != "" { | ||
| return f.formatSessionEntry(&session) | ||
| } | ||
|
|
||
| // Unrecognized JSON or plain text — return as-is. | ||
| return data | ||
| } | ||
|
|
||
| // formatStreamEntry formats a container log line: "HH:MM:SS stream message" | ||
| func (f *logFormatter) formatStreamEntry(entry *logStreamEntry) string { | ||
| ts := formatTimestamp(entry.Timestamp) | ||
| msg := strings.TrimRight(entry.Message, "\n") | ||
| label := entry.Stream | ||
|
|
||
| var labelStr string | ||
| switch label { | ||
| case "stderr": | ||
| labelStr = f.stderrColor.Sprint(label) | ||
| case "status": | ||
| labelStr = f.statusColor.Sprint(label) | ||
| default: | ||
| labelStr = label | ||
| } | ||
|
|
||
| return fmt.Sprintf("%s %-8s %s", | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. [MEDIUM] Fix: pad the label text before colorizing, then use |
||
| f.dimColor.Sprint(ts), | ||
| labelStr, | ||
| msg, | ||
| ) | ||
| } | ||
|
|
||
| // formatSessionEntry formats a session status line with state, version, and last accessed time. | ||
| func (f *logFormatter) formatSessionEntry(entry *logSessionEntry) string { | ||
| ts := formatTimestamp(entry.Timestamp) | ||
| lastAccessed := formatTimestamp(entry.LastAccessed) | ||
|
|
||
| stateStr := f.sessionColor.Sprint(entry.SessionState) | ||
| details := fmt.Sprintf("v%s, last accessed: %s", entry.Version, lastAccessed) | ||
|
|
||
| return fmt.Sprintf("%s %-8s %s (%s)", | ||
| f.dimColor.Sprint(ts), | ||
| f.sessionColor.Sprint("session"), | ||
| stateStr, | ||
| details, | ||
| ) | ||
| } | ||
|
|
||
| // formatTimestamp parses an ISO 8601 timestamp and returns a short local-time | ||
| // string in "HH:MM:SS" format. Returns the original string on parse failure. | ||
| func formatTimestamp(raw string) string { | ||
| // Try common formats produced by the agent service. | ||
| for _, layout := range []string{ | ||
| time.RFC3339Nano, | ||
| time.RFC3339, | ||
| "2006-01-02T15:04:05.999999999Z", | ||
| "2006-01-02T15:04:05.999999999+00:00", | ||
| } { | ||
| if t, err := time.Parse(layout, raw); err == nil { | ||
| return t.Local().Format("15:04:05") | ||
| } | ||
| } | ||
| return raw | ||
| } | ||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,194 @@ | ||
| // Copyright (c) Microsoft Corporation. All rights reserved. | ||
| // Licensed under the MIT License. | ||
|
|
||
| package cmd | ||
|
|
||
| import ( | ||
| "testing" | ||
|
|
||
| "github.com/fatih/color" | ||
| "github.com/stretchr/testify/assert" | ||
| ) | ||
|
|
||
| func init() { | ||
| // Disable color output in tests so assertions don't depend on ANSI codes. | ||
| color.NoColor = true | ||
| } | ||
|
|
||
| func TestFormatLine_SSEEventSuppressed(t *testing.T) { | ||
| t.Parallel() | ||
| f := newLogFormatter() | ||
| assert.Empty(t, f.formatLine("event: log")) | ||
| } | ||
|
|
||
| func TestFormatLine_BlankLineSuppressed(t *testing.T) { | ||
| t.Parallel() | ||
| f := newLogFormatter() | ||
| assert.Empty(t, f.formatLine("")) | ||
| assert.Empty(t, f.formatLine(" ")) | ||
| } | ||
|
|
||
| func TestFormatLine_NonSSEPassthrough(t *testing.T) { | ||
| t.Parallel() | ||
| f := newLogFormatter() | ||
| assert.Equal(t, "some random line", f.formatLine("some random line")) | ||
| } | ||
|
|
||
| func TestFormatLine_StreamEntry(t *testing.T) { | ||
| t.Parallel() | ||
| f := newLogFormatter() | ||
|
|
||
| _ = f.formatLine("event: log") | ||
| result := f.formatLine(`data: {"timestamp":"2026-03-19T12:50:25.788146040+00:00","stream":"stderr","message":"Traceback (most recent call last):"}`) | ||
|
|
||
| assert.Contains(t, result, "stderr") | ||
| assert.Contains(t, result, "Traceback (most recent call last):") | ||
| // Should contain a formatted timestamp, not the raw ISO string | ||
| assert.NotContains(t, result, "2026-03-19T") | ||
| } | ||
|
|
||
| func TestFormatLine_StreamEntry_Stdout(t *testing.T) { | ||
| t.Parallel() | ||
| f := newLogFormatter() | ||
|
|
||
| _ = f.formatLine("event: log") | ||
| result := f.formatLine(`data: {"timestamp":"2026-03-19T12:50:25.000Z","stream":"stdout","message":"Hello world"}`) | ||
|
|
||
| assert.Contains(t, result, "stdout") | ||
| assert.Contains(t, result, "Hello world") | ||
| } | ||
|
|
||
| func TestFormatLine_StreamEntry_Status(t *testing.T) { | ||
| t.Parallel() | ||
| f := newLogFormatter() | ||
|
|
||
| _ = f.formatLine("event: log") | ||
| result := f.formatLine(`data: {"timestamp":"2026-03-19T12:50:51.705577528Z","stream":"status","message":"Connecting to the container..."}`) | ||
|
|
||
| assert.Contains(t, result, "status") | ||
| assert.Contains(t, result, "Connecting to the container...") | ||
| } | ||
|
|
||
| func TestFormatLine_SessionEntry(t *testing.T) { | ||
| t.Parallel() | ||
| f := newLogFormatter() | ||
|
|
||
| _ = f.formatLine("event: log") | ||
| result := f.formatLine(`data: {"timestamp":"2026-03-19T12:50:51.0988803+00:00","session_id":"8f606b6b-5312-4272-958a-dd906de5f5a5","session_state":"Running","agent":"echo-agent","version":"4","last_accessed":"2026-03-19T12:50:25.007+00:00"}`) | ||
|
|
||
| assert.Contains(t, result, "session") | ||
| assert.Contains(t, result, "Running") | ||
| assert.Contains(t, result, "v4") | ||
| assert.Contains(t, result, "last accessed:") | ||
| } | ||
|
|
||
| func TestFormatLine_MalformedJSON_Fallback(t *testing.T) { | ||
| t.Parallel() | ||
| f := newLogFormatter() | ||
|
|
||
| _ = f.formatLine("event: log") | ||
| result := f.formatLine("data: {not valid json}") | ||
|
|
||
| // Should fall back to returning the raw data (without "data: " prefix) | ||
| assert.Equal(t, "{not valid json}", result) | ||
| } | ||
|
|
||
| func TestFormatLine_DataWithoutEvent(t *testing.T) { | ||
| t.Parallel() | ||
| f := newLogFormatter() | ||
|
|
||
| // data line without a preceding event line should still be parsed | ||
| result := f.formatLine(`data: {"timestamp":"2026-03-19T12:50:25.000Z","stream":"stdout","message":"orphan line"}`) | ||
| assert.Contains(t, result, "orphan line") | ||
| } | ||
|
|
||
| func TestFormatLine_TrailingNewlineStripped(t *testing.T) { | ||
| t.Parallel() | ||
| f := newLogFormatter() | ||
|
|
||
| _ = f.formatLine("event: log") | ||
| result := f.formatLine(`data: {"timestamp":"2026-03-19T12:50:25.000Z","stream":"stderr","message":"error message\n"}`) | ||
|
|
||
| // Trailing newlines from message should be stripped | ||
| assert.NotContains(t, result, "\n") | ||
| } | ||
|
|
||
| func TestFormatLine_EventStateResets(t *testing.T) { | ||
| t.Parallel() | ||
| f := newLogFormatter() | ||
|
|
||
| // First event+data pair | ||
| _ = f.formatLine("event: log") | ||
| r1 := f.formatLine(`data: {"timestamp":"2026-03-19T12:50:25.000Z","stream":"stdout","message":"first"}`) | ||
| assert.Contains(t, r1, "first") | ||
|
|
||
| // Second event+data pair | ||
| _ = f.formatLine("event: log") | ||
| r2 := f.formatLine(`data: {"timestamp":"2026-03-19T12:50:26.000Z","stream":"stderr","message":"second"}`) | ||
| assert.Contains(t, r2, "second") | ||
| } | ||
|
|
||
| func TestFormatTimestamp_RFC3339Nano(t *testing.T) { | ||
| t.Parallel() | ||
| result := formatTimestamp("2026-03-19T12:50:25.788146040+00:00") | ||
| // Should be HH:MM:SS in local time | ||
| assert.Regexp(t, `^\d{2}:\d{2}:\d{2}$`, result) | ||
| } | ||
|
|
||
| func TestFormatTimestamp_RFC3339(t *testing.T) { | ||
| t.Parallel() | ||
| result := formatTimestamp("2026-03-19T12:50:25+00:00") | ||
| assert.Regexp(t, `^\d{2}:\d{2}:\d{2}$`, result) | ||
| } | ||
|
|
||
| func TestFormatTimestamp_ZSuffix(t *testing.T) { | ||
| t.Parallel() | ||
| result := formatTimestamp("2026-03-19T12:50:51.705577528Z") | ||
| assert.Regexp(t, `^\d{2}:\d{2}:\d{2}$`, result) | ||
| } | ||
|
|
||
| func TestFormatTimestamp_Unparseable(t *testing.T) { | ||
| t.Parallel() | ||
| result := formatTimestamp("not-a-timestamp") | ||
| assert.Equal(t, "not-a-timestamp", result) | ||
| } | ||
|
|
||
| func TestFormatTimestamp_Empty(t *testing.T) { | ||
| t.Parallel() | ||
| result := formatTimestamp("") | ||
| assert.Equal(t, "", result) | ||
| } | ||
|
|
||
| func TestFormatLine_FullSSESequence(t *testing.T) { | ||
| t.Parallel() | ||
| f := newLogFormatter() | ||
|
|
||
| // Simulate a full SSE sequence as seen in the real output | ||
| lines := []string{ | ||
| "event: log", | ||
| `data: {"timestamp":"2026-03-19T12:50:51.0988803+00:00","session_id":"8f606b6b","session_state":"Running","agent":"echo-agent","version":"4","last_accessed":"2026-03-19T12:50:25.007+00:00"}`, | ||
| "", | ||
| "event: log", | ||
| `data: {"timestamp":"2026-03-19T12:50:51.705577528Z","stream":"status","message":"Connecting to the container..."}`, | ||
| "", | ||
| "event: log", | ||
| `data: {"timestamp":"2026-03-19T12:50:25.788146040+00:00","stream":"stderr","message":"Traceback (most recent call last):"}`, | ||
| "", | ||
| "event: log", | ||
| `data: {"timestamp":"2026-03-19T12:50:51.706107016Z","stream":"status","message":"Successfully connected to container"}`, | ||
| } | ||
|
|
||
| var outputs []string | ||
| for _, line := range lines { | ||
| if out := f.formatLine(line); out != "" { | ||
| outputs = append(outputs, out) | ||
| } | ||
| } | ||
|
|
||
| assert.Len(t, outputs, 4) | ||
| assert.Contains(t, outputs[0], "session") | ||
| assert.Contains(t, outputs[0], "Running") | ||
| assert.Contains(t, outputs[1], "Connecting to the container...") | ||
| assert.Contains(t, outputs[2], "Traceback") | ||
| assert.Contains(t, outputs[3], "Successfully connected") | ||
| } | ||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
[HIGH] The SSE formatter runs on both the session logstream and the container logstream. Container logs aren't SSE-formatted, so
formatLine()silently drops lines starting withevent:ordata:, and suppresses blank lines in the default (no-flags) path.