fix: Trim Windows event log after SCM filtering, not before

This commit is contained in:
2026-08-13 12:12:11 +00:00
parent 4ba9983cf8
commit ea6d0b969c
3 changed files with 62 additions and 8 deletions
+18 -4
View File
@@ -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)
+15 -1
View File
@@ -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: "<timestamp> <level> <message>", 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
}
+29 -3
View File
@@ -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)
}
}