From ea6d0b969ceaf211a64e7c75cee65345ee2fec75 Mon Sep 17 00:00:00 2001 From: mrhid6 Date: Thu, 13 Aug 2026 12:12:11 +0000 Subject: [PATCH] fix: Trim Windows event log after SCM filtering, not before --- agent/internal/workloads/logs_windows.go | 22 +++++++++++++--- agent/internal/workloads/winparse.go | 16 +++++++++++- agent/internal/workloads/winparse_test.go | 32 ++++++++++++++++++++--- 3 files changed, 62 insertions(+), 8 deletions(-) diff --git a/agent/internal/workloads/logs_windows.go b/agent/internal/workloads/logs_windows.go index cb5ff4d..817d850 100644 --- a/agent/internal/workloads/logs_windows.go +++ b/agent/internal/workloads/logs_windows.go @@ -27,18 +27,32 @@ func logsPlatform(ctx context.Context, kind, id string, tail int) (string, error // ConvertTo-Json, whose DateTime rendering differs between PowerShell // versions — one of them emits /Date(1699...)/. // - // -ErrorAction SilentlyContinue because Get-WinEvent treats "no events - // matched" as a terminating error, and a quiet service is normal. + // $ErrorActionPreference = 'SilentlyContinue' because Get-WinEvent + // treats "no events matched" as a terminating error, and a quiet + // service is normal. names := psQuote(id) if display != "" && display != id { names += "," + psQuote(display) } names += "," + psQuote(scmProvider) + // ProviderName includes the host-wide Service Control Manager, so a + // -MaxEvents cap of exactly tail would apply to the combined stream + // before parseEvents narrows SCM rows down to this service — on a + // host with busy service churn the target's own events could be + // squeezed out of the window entirely. Over-fetch instead, hard-capped + // so a pathological host cannot pull an unbounded batch across the + // wire, and let parseEvents trim to the last tail lines after + // filtering. + fetch := tail * 5 + if fetch > 2500 { + fetch = 2500 + } + script := ` $ErrorActionPreference = 'SilentlyContinue' $rows = Get-WinEvent -FilterHashtable @{LogName='System','Application'; ProviderName=@(` + names + `)} ` + - `-MaxEvents ` + strconv.Itoa(tail) + ` | + `-MaxEvents ` + strconv.Itoa(fetch) + ` | ForEach-Object { [pscustomobject]@{ t = $_.TimeCreated.ToUniversalTime().ToString('o') @@ -54,7 +68,7 @@ ConvertTo-Json -InputObject @($rows) -Depth 3 -Compress if err != nil { return "", fmt.Errorf("read events for %s: %w", id, err) } - return parseEvents(out, id, display) + return parseEvents(out, id, display, tail) default: return "", fmt.Errorf("unknown workload kind %q", kind) diff --git a/agent/internal/workloads/winparse.go b/agent/internal/workloads/winparse.go index 62b1b12..c869f2f 100644 --- a/agent/internal/workloads/winparse.go +++ b/agent/internal/workloads/winparse.go @@ -157,7 +157,16 @@ type winEvent struct { // parseEvents renders Get-WinEvent output as text in the shape journalctl // --output=short-iso produces, so the log dialog needs no per-platform // rendering: " ", oldest first. -func parseEvents(jsonText, serviceName, displayName string) (string, error) { +// +// The caller over-fetches from Get-WinEvent because the ProviderName filter +// includes the host-wide Service Control Manager, and a -MaxEvents cap +// applied before SCM rows are narrowed down to this service would squeeze the +// target's own events out of the window on a host with busy service churn. +// tail is therefore applied here, AFTER filtering and AFTER the oldest-first +// reversal, keeping the last tail lines — the most recent lines are the ones +// worth keeping, matching capLog's front-trim reasoning in the shared +// logs.go. +func parseEvents(jsonText, serviceName, displayName string, tail int) (string, error) { s := strings.TrimSpace(jsonText) if s == "" || s == "null" { return "", nil @@ -188,6 +197,11 @@ func parseEvents(jsonText, serviceName, displayName string) (string, error) { for i, j := 0, len(lines)-1; i < j; i, j = i+1, j-1 { lines[i], lines[j] = lines[j], lines[i] } + + if tail > 0 && len(lines) > tail { + lines = lines[len(lines)-tail:] + } + return strings.Join(lines, "\n"), nil } diff --git a/agent/internal/workloads/winparse_test.go b/agent/internal/workloads/winparse_test.go index 4133097..e2605de 100644 --- a/agent/internal/workloads/winparse_test.go +++ b/agent/internal/workloads/winparse_test.go @@ -118,7 +118,7 @@ func TestParseEventsFormatsAndOrders(t *testing.T) { {"t":"2026-08-13T10:22:03.0000000Z","l":"Information","p":"Contoso","m":"broker starting"} ]` - got, err := parseEvents(in, "Contoso", "Contoso Broker") + got, err := parseEvents(in, "Contoso", "Contoso Broker", 500) if err != nil { t.Fatalf("parseEvents: %v", err) } @@ -138,7 +138,7 @@ func TestParseEventsFiltersOtherServicesSCM(t *testing.T) { {"t":"2026-08-13T10:00:01Z","l":"Information","p":"Service Control Manager","m":"The Contoso Broker service entered the running state."} ]` - got, err := parseEvents(in, "Contoso", "Contoso Broker") + got, err := parseEvents(in, "Contoso", "Contoso Broker", 500) if err != nil { t.Fatalf("parseEvents: %v", err) } @@ -154,9 +154,35 @@ func TestParseEventsFiltersOtherServicesSCM(t *testing.T) { // broken feature. func TestParseEventsEmpty(t *testing.T) { for _, in := range []string{"", "[]", "null"} { - got, err := parseEvents(in, "Contoso", "Contoso Broker") + got, err := parseEvents(in, "Contoso", "Contoso Broker", 500) if err != nil || got != "" { t.Fatalf("parseEvents(%q) = %q, err %v", in, got, err) } } } + +// The over-fetch in logs_windows.go can return more events than the caller +// asked for once SCM rows are filtered down to the target; parseEvents must +// keep the most RECENT tail lines, not the oldest, matching capLog's +// front-trim reasoning in the shared logs.go. +func TestParseEventsTrimsToTailKeepingMostRecent(t *testing.T) { + in := `[ + {"t":"2026-08-13T10:00:06Z","l":"Information","p":"Contoso","m":"event 6"}, + {"t":"2026-08-13T10:00:05Z","l":"Information","p":"Contoso","m":"event 5"}, + {"t":"2026-08-13T10:00:04Z","l":"Information","p":"Contoso","m":"event 4"}, + {"t":"2026-08-13T10:00:03Z","l":"Information","p":"Contoso","m":"event 3"}, + {"t":"2026-08-13T10:00:02Z","l":"Information","p":"Contoso","m":"event 2"}, + {"t":"2026-08-13T10:00:01Z","l":"Information","p":"Contoso","m":"event 1"} + ]` + + got, err := parseEvents(in, "Contoso", "Contoso Broker", 2) + if err != nil { + t.Fatalf("parseEvents: %v", err) + } + + want := "2026-08-13T10:00:05Z Information event 5\n" + + "2026-08-13T10:00:06Z Information event 6" + if got != want { + t.Fatalf("parseEvents =\n%q\nwant\n%q", got, want) + } +}