Repository navigation
perf(logs): filters before the entry is built, one expression for the event table - #18
Conversation
fadwen
left a comment
fadwen
left a comment
There was a problem hiding this comment.
Notes on the lines whose reason the diff does not show.
| if ($wantedTypes -and $type -notin $wantedTypes) { continue } | ||
|
|
||
| $message = $groups['message'].Value | ||
| if ($Pattern -and $message -notmatch $Pattern) { continue } |
There was a problem hiding this comment.
The -match operator on purpose, not a cached regex: Get-IntuneAgentLog applied -Pattern with -notmatch, which is case-insensitive, and a Regex object would be case-sensitive unless told otherwise. Same result as before for every pattern.
|
|
||
| # The newlines between the last kept entry and this one, in one .NET call | ||
| if ($match.Index -gt $counted) { | ||
| $line += $text.Substring($counted, $match.Index - $counted).Split("`n").Length - 1 |
There was a problem hiding this comment.
Lines are counted lazily so a skipped entry costs nothing here; the gap can span many skipped records, so it is one Substring and Split rather than an IndexOf loop, which ran once per newline in PowerShell (3 s of the 80,000-entry read).
|
|
||
| # component, then type, then thread, in the order every agent log writes them; context and file | ||
| # sit between and after them and are not read | ||
| $script:IslCmTraceAttributeRegex = [regex]::new('component="([^"]*)".*?type="(\d)".*?thread="(\d+)"', |
There was a problem hiding this comment.
One expression in the agent's attribute order replaces three. If a record lacks any of the three the whole match fails and the entry falls back to the defaults (no component, Information, no thread), as it did when the individual match failed.
| # The same pattern with its capturing groups named <prefix><n>, so every group of the | ||
| # combined expression below has a name and the matched alternative is the first group that | ||
| # succeeded. A "(" opens a capture unless it is escaped, inside a class, or followed by "?" | ||
| function ConvertTo-NamedGroup { |
There was a problem hiding this comment.
Every group needs a name because .NET numbers unnamed groups before named ones: with the inner captures left unnamed, the first successful group after group 0 would be a capture from the matched alternative, not the alternative itself.
| Event = $definition.Event | ||
| Regex = [regex]::new($definition.Pattern, $singleline) | ||
| Event = $definition.Event | ||
| Regex = [regex]::new($definition.Pattern, $singleline) |
There was a problem hiding this comment.
The per-definition regex is kept for -ListEvent, which prints the pattern, and for the tests that check a message against one definition. The matching path no longer uses it.
| $_.Name -eq 'Skip' -and $_.GetParameters()[1].ParameterType -eq [int] | ||
| } | Select-Object -First 1).MakeGenericMethod($groupType) | ||
| $first = ($enumerable.GetMethods() | Where-Object { | ||
| $_.Name -eq 'FirstOrDefault' -and $_.GetParameters().Count -eq 2 -and |
There was a problem hiding this comment.
.NET 6 added FirstOrDefault(source, defaultValue), also two parameters, so the overload is picked by its predicate type rather than by parameter count; on .NET Framework the filter is harmless.
| $needles = @(foreach ($definition in $script:IslAgentLogEvents) { | ||
| if ($definition.Event -in $EventName) { $definition.Needle } | ||
| }) | ||
| if ($needles.Count -eq @($EventName | Select-Object -Unique).Count) { $parseSplat.Contains = $needles } |
There was a problem hiding this comment.
The shortcut is taken only when every wanted event has a literal. AppDetectionRule's pattern starts with a group and has none; asking for it alongside others disables the prefilter rather than dropping its messages.
… event table Get-IntuneAgentLog built an object for every record of every log, then filtered, then classified each entry with a call that tried 44 regular expressions one by one. Each of those is a PowerShell statement run 80,000 times for a 15 MB log, and together they were most of what a read cost: 62 s for every entry, 25 s for one policy's entries, 90 s for an event filter with -Last. ConvertFrom-IslCmTraceLog takes the filters Get-IntuneAgentLog offers (-Level, -After, -Before, -Pattern, -Id, and -Contains for the literal text the wanted events' patterns start with) and applies them to the raw record, so an entry nobody wants is never built; the line number is counted over the skipped text in one call per kept entry. The attribute regexes are compiled once; the timestamp is one TryParseExact instead of two regexes and six conversions. Get-IslAgentLogEvent takes a batch of messages and matches one combined expression per message, every group named, the matched alternative found with Enumerable.FirstOrDefault rather than a loop over 44 candidates; alternation keeps the table's order at a position, so a message two patterns fit resolves as before. Get-IntuneAgentLog classifies a file's kept messages in one call and skips a rolled-over file last written before -After. Measured on the 15 MB log, fresh process, PowerShell 7.6: every entry 30 s against 62 s; -Id 5 s against 25 s; -EventName -Last 12 s against 90 s; a timeline by id 5 s against 26 s. Same entries in every case.
1 participant
Summary
Get-IntuneAgentLogbuilt an object for every record of every log, filtered afterwards, then classified each entry with a call that tried 44 regular expressions one by one. Each of those is a PowerShell statement run 80,000 times for a 15 MB agent log, and together they were most of what a read cost. The filters now run on the raw record before an entry is built, the event table is one expression matched once per message, and a rolled-over file last written before-Afteris not read. Results are unchanged.Measured on a 15 MB log of 80,000 entries, fresh process, PowerShell 7.6.6, this change against
main:-Id-EventName ScriptExit -Last 5Get-IntuneAgentTimeline -IdOn Windows PowerShell 5.1 the same
-Idread takes 2 s.Stacked on #17 (base branch); the diff is this change only. Merge #16, #17, then this.
Changes
Private/ConvertFrom-IslCmTraceLog.ps1. Takes-Level,-After,-Before,-Patternand-Id, the filtersGet-IntuneAgentLogoffers, and-Contains, and applies them to the raw record before the object is built. Line numbers are counted over the skipped text in one call per kept entry. The three attribute regexes become one compiled expression in the order every agent log writes them; the timestamp is oneTryParseExactinstead of two regexes and six conversions.Private/Get-IslAgentLogEvent.ps1. Takes a batch of messages, one result each in order. The 44 patterns are compiled into one alternation with every capturing group named, so the matched alternative is the first successful group after group 0, found withEnumerable.FirstOrDefaultand aGroup.Successdelegate rather than a loop. Alternation keeps the table's order at a position, so a message two patterns fit resolves to the earlier one, as before. Each definition also carries the literal text its pattern starts with.Public/Get-IntuneAgentLog.ps1. Passes the filters to the parser; with-EventName, passes the wanted events' leading literals as-Containswhen every one of them has one; classifies a file's kept messages in one call; skips a file whose last write is before-After.Private/ConvertTo-IslCmTraceTime.ps1. OneTryParseExactwithM-d-yyyy H:mm:ss.FFFFFFF, the bias cut off first.-After.Verification
Get-IntuneAgentLog's parameters and output are unchanged, so no help changes.Notes
[pscustomobject]with eleven properties, 80,000 times. A class would halve it but changes the type name the format view binds to; left for a later change if anyone reads whole logs that size.