Private/Kinds/AppLog.ps1
|
# The AppLog Kind: what an application wrote into its own log. # # Windows' event log knows that a program crashed. It does not know that the program has # been failing to load a screen forty times a day, because the program caught that, wrote # a line into its own log file, and carried on. That file is where the vendor's support # looks first, and a Technician rarely knows it exists. A Check Definition names it and # says how its lines are built; this Kind counts the errors in it and groups them by where # they came from. # # Built for, and observed on 2026-10-09 with, a .NET application logging through NLog to a # semicolon-separated file with a header line - Number;Level;Date;Logger;Message; # Exception;Location - one file per day, the day in the file's name and only the time of # day in the line. One day's file held 629 lines, 29 of them errors, 28 from one place. # # Two ways a log is read: # # - As delimited text with a header (the default): the Check Definition names the # delimiter and which columns hold the level, the time, the source, the message and # the exception. A quoted field may run over several lines, as a stack trace does. # - Line by line against LinePattern, a regular expression with the named groups # time, level, source and message, for a log that is plain text. A line that does not # match belongs to the entry before it and is not read. # # - Out of a table of a database, where the Check Definition names one (Table): some # applications keep their log in an SQLite file. Observed 2026-10-13 with the service # of a VPN client: a table Logs with Date as text, Severity as a number (0 for what # happened, 1 for a warning, 2 for an error) and Message - about forty entries a day, # two to seven of them errors on a day with nothing wrong. A level that is a number # is given its name by LevelNames. How such a file is read: Private\Sqlite.ps1. # # What is kept. Counts for every level, and of the entries at an error level the time, # the source, the first line of the exception and the message cut to a length - enough to # group by and to show one example. A log holds whatever the application put there, a # Customer's data included; nothing of an entry that is not an error leaves the file. # # A line that names a URL. Where an application writes down that it could not reach its # server, the line often names the server's URL: the SwyxIt! traces write # "EndpointNotFoundException:... https://swyx01.contoso.example:9094/ippbx/... ...", at a # warning and not an error (docs/research/app-logs-https.md). A Check Definition that names # such lines (EventPattern) has each of them kept, at whatever level, and the Judge puts it # on the timeline as a Timed Event on the Service of that host and port - the one the Server # Check and the Links already draw - with the URL in its words, and says how far back the # log reaches (ADR-0010, ADR-0015). Only what EventPattern matched leaves the file, and of it # only the line's message, cut to a length - never inside the URL, which is said in full as # the log wrote it (#173, #174). # # A line that names no server. A socket error says "Connection refused" and not to whom. # Where the application has one server, its configuration names it: the Check Definition # says where (FallbackServer, a key of an ini file), and such a line lands on that server. # # A log rotated into .gz files, as the Nextcloud client gzips the file before its open one, # is read through them as through the open file. # How much of a message and of an exception's first line is kept, and how many error # entries: what is shown is a grouping and an example, not the log. $script:AppLogMessageLength = 300 $script:AppLogExceptionLength = 200 $script:AppLogMaximumErrors = 2000 # How many lines that name a URL are kept: more than any threshold needs, and the timeline # has enough to show when they were. $script:AppLogMaximumEvents = 2000 # How many entries of a database are read at most, the newest first. $script:AppLogMaximumRows = 20000 function Get-AppLogLevelName { <# .SYNOPSIS The name of a level that a log writes as a number, from what the Check Definition says of it; the level as it was written where it says nothing. Pure. #> [CmdletBinding()] [OutputType([string])] param([AllowNull()][AllowEmptyString()][string]$Level, [AllowNull()]$Name) $written = "$Level".Trim() $named = $null if ($Name -is [System.Collections.IDictionary]) { if ($Name.Contains($written)) { $named = $Name[$written] } } elseif ($null -ne $Name -and $Name.PSObject.Properties[$written]) { $named = $Name.PSObject.Properties[$written].Value } if ("$named".Trim()) { return "$named".Trim().ToUpperInvariant() } $written.ToUpperInvariant() } function Get-AppLogDatabaseQuery { <# .SYNOPSIS What is asked of a log's table: time, level, message and source of the entries since a day, the newest first. $null where the Check Definition names something that is no name of a table or a column. Pure. .DESCRIPTION A name goes into the question as it is written, so it is taken only as letters, digits and underscores. The time is compared as text: a log writes it year first. #> [CmdletBinding()] [OutputType([string])] param([hashtable]$Layout = @{}, [datetime]$Since, [int]$Maximum = $script:AppLogMaximumRows) $name = '^[A-Za-z_][A-Za-z0-9_]*$' foreach ($needed in 'Table', 'TimeColumn', 'LevelColumn', 'MessageColumn') { if ("$($Layout[$needed])" -notmatch $name) { return $null } } $source = "''" if ("$($Layout.SourceColumn)" -match $name) { $source = '"{0}"' -f $Layout.SourceColumn } 'select "{0}", "{1}", "{2}", {3} from "{4}" where "{0}" >= ''{5:yyyy-MM-dd}'' order by rowid desc limit {6}' -f $Layout.TimeColumn, $Layout.LevelColumn, $Layout.MessageColumn, $source, $Layout.Table, $Since, $Maximum } function Read-AppLogDatabase { <# .SYNOPSIS The entries of a log kept in an SQLite file, as ConvertFrom-AppLogText gives those of a text file. Asks only; the file is opened as one nobody writes to. #> [CmdletBinding()] [OutputType([psobject])] param([Parameter(Mandatory)][string]$Path, [hashtable]$Layout = @{}, [datetime]$Since) $query = Get-AppLogDatabaseQuery -Layout $Layout -Since $Since if (-not $query) { throw 'BadDefinition' } foreach ($row in (Read-SqliteFile -Path $Path -Query $query)) { [pscustomobject]@{ Level = Get-AppLogLevelName -Level $row[1] -Name $Layout.LevelNames Time = ConvertTo-AppLogTime -Value $row[0] -FileDate $null Source = "$($row[3])".Trim() Message = "$($row[2])" Exception = '' } } } function ConvertTo-AppLogTime { <# .SYNOPSIS When an entry was written, from what the line says and the day of its file. Pure. .DESCRIPTION A time of day alone ("00:02:42.2502") is put on the file's day. A day of the month and a time ("13 08:56:06.402", as the traces of a telephony client write it, observed 2026-10-13) is that day of the file's month - and of the month before where the day is later than the file's own, since a file is dated by when it was last written. Where the file is dated by its name, which is the day it was started, the month is that of when it was last written (-LastWriteTime): a trace started on the 16th and written on the 17th holds the 17th. A whole timestamp is read in the format the Check Definition gives (-Format) where it gives one, else as ISO first and then as the machine writes dates. $null for what is neither: an entry without a time is still counted. #> [CmdletBinding()] [OutputType([datetime])] param([AllowNull()][AllowEmptyString()][string]$Value, [AllowNull()]$FileDate, [AllowNull()]$LastWriteTime, [AllowNull()][string[]]$Format) $text = "$Value".Trim() if (-not $text) { return $null } # A format of the Definition's own: "2026-10-15 13:27:01:123", milliseconds after a # colon, is no time .NET reads by itself. $formats = [string[]]@($Format | Where-Object { "$_".Trim() }) if ($formats.Count) { $exact = [datetime]::MinValue if ([datetime]::TryParseExact($text, $formats, [Globalization.CultureInfo]::InvariantCulture, [Globalization.DateTimeStyles]::AssumeLocal, [ref]$exact)) { return $exact } } if ($text -match '^\d{1,2}:\d{2}(:\d{2}([.,]\d+)?)?$') { if ($null -eq $FileDate) { return $null } $span = [timespan]::Zero if ([timespan]::TryParse(($text -replace ',', '.'), [Globalization.CultureInfo]::InvariantCulture, [ref]$span)) { return ([datetime]$FileDate).Date + $span } return $null } if ($text -match '^(\d{1,2}) (\d{1,2}:\d{2}:\d{2}(?:[.,]\d+)?)$') { $anchor = $FileDate if ($null -ne $LastWriteTime) { $anchor = $LastWriteTime } if ($null -eq $anchor) { return $null } $anchor = ([datetime]$anchor).Date $span = [timespan]::Zero if (-not [timespan]::TryParse(($Matches[2] -replace ',', '.'), [Globalization.CultureInfo]::InvariantCulture, [ref]$span)) { return $null } $day = [int]$Matches[1] $month = $anchor.AddDays(1 - $anchor.Day) if ($day -gt $anchor.Day) { $month = $month.AddMonths(-1) } if ($day -lt 1 -or $day -gt [datetime]::DaysInMonth($month.Year, $month.Month)) { return $null } return $month.AddDays($day - 1) + $span } $when = [datetime]::MinValue $styles = [Globalization.DateTimeStyles]::AssumeLocal if ([datetime]::TryParse(($text -replace ',(\d+)$', '.$1'), [Globalization.CultureInfo]::InvariantCulture, $styles, [ref]$when)) { return $when } if ([datetime]::TryParse($text, [Globalization.CultureInfo]::CurrentCulture, $styles, [ref]$when)) { return $when } $null } function Get-AppLogFileDate { <# .SYNOPSIS The day a log file is for: from its name when the name carries one, else the day it was last written. Pure. .DESCRIPTION The first group of -Pattern is the day, written as a date is ("2026-10-16") or as eight digits ("20261016", as the SwyxIt! traces and the Nextcloud client name their files). #> [CmdletBinding()] [OutputType([datetime])] param([AllowNull()][string]$Name, [AllowNull()]$LastWriteTime, [AllowNull()][AllowEmptyString()][string]$Pattern) if ("$Pattern".Trim()) { try { if ("$Name" -match $Pattern -and $Matches.Count -gt 1) { $day = [datetime]::MinValue if ([datetime]::TryParse($Matches[1], [Globalization.CultureInfo]::InvariantCulture, [Globalization.DateTimeStyles]::None, [ref]$day)) { return $day.Date } if ([datetime]::TryParseExact($Matches[1], 'yyyyMMdd', [Globalization.CultureInfo]::InvariantCulture, [Globalization.DateTimeStyles]::None, [ref]$day)) { return $day.Date } } } catch { } } if ($null -ne $LastWriteTime) { return ([datetime]$LastWriteTime).Date } $null } function ConvertTo-AppLogCut { <# .SYNOPSIS Text on one line, cut to a length between words. Pure. #> [CmdletBinding()] [OutputType([string])] param([AllowNull()][AllowEmptyString()][string]$Text, [int]$Length) $line = ("$Text" -replace '\s+', ' ').Trim() if ($line.Length -le $Length) { return $line } $cut = $line.LastIndexOf(' ', $Length) if ($cut -lt 1) { $cut = $Length } $line.Substring(0, $cut) + ' [...]' } function ConvertFrom-AppLogText { <# .SYNOPSIS One log file's text as entries: level, time, source, message, exception. Pure. .DESCRIPTION -Layout carries what the Check Definition says about the file: Delimiter and the five column names, or LinePattern. Every entry is returned with its level; the caller keeps the errors. An exception is its first line - the type and what it said - without the stack trace. -LastWriteTime is when the file was last written, which places a day of the month (ConvertTo-AppLogTime). #> [CmdletBinding()] [OutputType([psobject])] param([AllowNull()][AllowEmptyString()][string]$Text, [hashtable]$Layout = @{}, [AllowNull()]$FileDate, [AllowNull()]$LastWriteTime) if (-not "$Text".Trim()) { return } $format = @($Layout.TimeFormat) $pattern = "$($Layout.LinePattern)".Trim() if ($pattern) { foreach ($line in ("$Text" -split "`r?`n")) { $match = $null try { $match = [regex]::Match($line, $pattern) } catch { return } if (-not $match.Success) { continue } [pscustomobject]@{ Level = $match.Groups['level'].Value.Trim().ToUpperInvariant() Time = ConvertTo-AppLogTime -Value $match.Groups['time'].Value -FileDate $FileDate -LastWriteTime $LastWriteTime -Format $format Source = $match.Groups['source'].Value.Trim() Message = $match.Groups['message'].Value Exception = '' } } return } $delimiter = "$($Layout.Delimiter)" if (-not $delimiter) { $delimiter = ';' } $rows = @() try { $rows = @(ConvertFrom-Csv -InputObject $Text -Delimiter $delimiter -ErrorAction Stop) } catch { return } foreach ($row in $rows) { $level = "$(Get-DataProperty $row $Layout.LevelColumn)".Trim().ToUpperInvariant() if (-not $level) { continue } [pscustomobject]@{ Level = $level Time = ConvertTo-AppLogTime -Value "$(Get-DataProperty $row $Layout.TimeColumn)" -FileDate $FileDate -LastWriteTime $LastWriteTime -Format $format Source = "$(Get-DataProperty $row $Layout.SourceColumn)".Trim() Message = "$(Get-DataProperty $row $Layout.MessageColumn)" Exception = @("$(Get-DataProperty $row $Layout.ExceptionColumn)" -split "`r?`n")[0] } } } function Get-AppLogLayout { <# .SYNOPSIS What a Check Definition says about how the log is built, with the defaults. Pure. #> [CmdletBinding()] [OutputType([hashtable])] param([hashtable]$Parameters = @{}) @{ LinePattern = "$(Get-Parameter $Parameters 'LinePattern' '')" Delimiter = "$(Get-Parameter $Parameters 'Delimiter' ';')" LevelColumn = "$(Get-Parameter $Parameters 'LevelColumn' 'Level')" TimeColumn = "$(Get-Parameter $Parameters 'TimeColumn' 'Date')" SourceColumn = "$(Get-Parameter $Parameters 'SourceColumn' 'Logger')" MessageColumn = "$(Get-Parameter $Parameters 'MessageColumn' 'Message')" ExceptionColumn = "$(Get-Parameter $Parameters 'ExceptionColumn' 'Exception')" # A log kept in a database: the table, and what its numbers for a level are called. Table = "$(Get-Parameter $Parameters 'Table' '')".Trim() LevelNames = Get-Parameter $Parameters 'LevelNames' $null # How a line writes its time, where .NET does not read it by itself: one format or # several, as DateTime.ParseExact takes them. TimeFormat = @(@(Get-Parameter $Parameters 'TimeFormat' @()) | ForEach-Object { "$_" } | Where-Object { $_.Trim() }) } } function Select-AppLogEvent { <# .SYNOPSIS What an entry says of a Service it could not reach, where -Pattern names it: its time, the URL or the host and port, the error, and the message cut to a length. Nothing for an entry -Pattern does not match. Pure. .DESCRIPTION -Pattern is the Check Definition's EventPattern, matched against the entry's message and then its exception. Which lines it matches is what makes them Timed Events; its named groups say where in the line the Service stands: url - an absolute URL, "https://swyx01.contoso.example:9094/ippbx/..."; host - a host by itself, with port beside it where the line names one; error - what went wrong, in the line's words: "EndpointNotFoundException"; status - the HTTP status the server answered with: "404". A match that names neither a URL nor a host is kept as well: the Judge counts it, and places it on the application's server where its configuration names one. What the URL is a Service of is for the Judge to say. The URL is kept as the log wrote it, its path and its query too: what a Technician reads of it (#173). A full stop, a bracket or a quotation mark the pattern took in after it is the sentence's, and not the URL's. The message is cut to a length, but never inside the URL. #> [CmdletBinding()] [OutputType([psobject])] param([AllowNull()]$Entry, [AllowNull()][AllowEmptyString()][string]$Pattern) if ($null -eq $Entry -or -not "$Pattern".Trim()) { return } foreach ($said in @("$(Get-DataProperty $Entry 'Message')", "$(Get-DataProperty $Entry 'Exception')")) { if (-not $said.Trim()) { continue } $match = [regex]::Match($said, $Pattern) if (-not $match.Success) { continue } $url = '' $named = $match.Groups['url'] if ($named.Success) { $url = $named.Value.Trim() -replace '[.,;:)\]''"]+$', '' } if (-not (Test-ServiceUrl -Text $url)) { $url = '' } # Cut behind the URL at the earliest, so that it is whole. $length = $script:AppLogMessageLength $line = ($said -replace '\s+', ' ').Trim() $at = $(if ($url) { $line.IndexOf($url) } else { -1 }) if ($at -ge 0) { $end = $line.IndexOf(' ', $at + $url.Length) if ($end -lt 0) { $end = $line.Length } $length = [math]::Max($length, $end) } return [pscustomobject]@{ Time = Get-DataProperty $Entry 'Time' Url = $url Host = $match.Groups['host'].Value.Trim() Port = $match.Groups['port'].Value.Trim() Error = $match.Groups['error'].Value.Trim() Status = $match.Groups['status'].Value.Trim() Message = ConvertTo-AppLogCut -Text $line -Length $length } } } function Get-AppLogFallbackServer { <# .SYNOPSIS The server an application's configuration names, from the text of its ini file: the value of the first key in -Section whose name -Key matches. A URL is kept as far as it places the server, its scheme, host and port; anything else as the host it is. Nothing where the file names none. Pure. .DESCRIPTION For the Nextcloud client: Section Accounts, Key ^\d+\\url$, the address of its first account. A line that names no server is about that one (#175). #> [CmdletBinding()] [OutputType([string])] param([AllowNull()][AllowEmptyString()][string]$Text, [AllowNull()][AllowEmptyString()][string]$Section, [AllowNull()][AllowEmptyString()][string]$Key) if (-not "$Key".Trim()) { return '' } foreach ($entry in (ConvertFrom-IniText -Text $Text)) { if ("$Section".Trim() -and $entry.Section -ne "$Section".Trim()) { continue } $named = $false try { $named = $entry.Name -match $Key } catch { return '' } if (-not $named -or -not $entry.Value.Trim()) { continue } # The server is all it is read for, and it is not shown. if (Test-ServiceUrl -Text $entry.Value.Trim()) { return ([uri]$entry.Value.Trim()).GetComponents([UriComponents]::SchemeAndServer, [UriFormat]::UriEscaped) } # A host by itself, never anything with a user or a path in it. if ($entry.Value.Trim() -match '^[A-Za-z0-9.-]+$') { return $entry.Value.Trim() } return '' } '' } function Read-AppLogFile { <# .SYNOPSIS A log file's text, read while the application has it open for writing. .DESCRIPTION A file whose name ends in .gz is a log the application rotated and gzipped, and is read through it: its text is the lines it held. #> [CmdletBinding()] [OutputType([string])] param([Parameter(Mandatory)][string]$Path) $stream = [IO.File]::Open($Path, [IO.FileMode]::Open, [IO.FileAccess]::Read, ([IO.FileShare]::ReadWrite -bor [IO.FileShare]::Delete)) try { $source = $stream if ($Path -match '(?i)\.gz$') { $source = New-Object System.IO.Compression.GZipStream($stream, [IO.Compression.CompressionMode]::Decompress) } $reader = New-Object System.IO.StreamReader($source, [Text.Encoding]::UTF8, $true) try { $reader.ReadToEnd() } finally { $reader.Dispose() } } finally { $stream.Dispose() } } # What Get-AppLogData hands its Judge. See Private/DataShape.ps1. $script:AppLogDataShape = @{ App = 'Value' ConfiguredPath = 'Value' Path = 'Value' Days = 'Value' GatheredAt = 'Answered' Files = 'List' Levels = 'List' ErrorCount = 'Answered' Errors = 'List' # The lines EventPattern matched, and the time of the oldest entry read: how far back # the log reaches, within the days asked for. Events = 'List' Oldest = 'Value' # The server the application's configuration names, where the Definition says where: # what a line that names none is about. FallbackServer = 'Value' } function Get-AppLogData { [CmdletBinding()] [OutputType([psobject])] param([hashtable]$Parameters = @{}) $configured = "$(Get-Parameter $Parameters 'Path' '')".Trim() $days = ConvertTo-Number (Get-Parameter $Parameters 'Days' 7) if ($null -eq $days -or $days -le 0) { $days = 7 } $maximumMB = ConvertTo-Number (Get-Parameter $Parameters 'MaxFileMB' 20) if ($null -eq $maximumMB -or $maximumMB -le 0) { $maximumMB = 20 } $errorLevels = @(@(Get-Parameter $Parameters 'ErrorLevels' @('ERROR', 'FATAL', 'CRITICAL')) | ForEach-Object { "$_".Trim().ToUpperInvariant() } | Where-Object { $_ }) $datePattern = "$(Get-Parameter $Parameters 'FileDatePattern' '(\d{4}-\d{2}-\d{2})')" $layout = Get-AppLogLayout -Parameters $Parameters # Lines at an error level that are no error of their own: a log that writes a stack # trace line by line gives every line of it the level of the error it belongs to. # Observed 2026-10-13: one exception was five lines, and counted as five errors. $ignore = "$(Get-Parameter $Parameters 'IgnoreMessagePattern' '')".Trim() # The lines that say a Service could not be reached, at whatever level. See # Select-AppLogEvent. $eventPattern = "$(Get-Parameter $Parameters 'EventPattern' '')".Trim() # The server a line that names none is about: { Path, Section, Key } of an ini file the # application keeps it in. Read as the log is, as a file nobody writes to. $fallback = '' $fallbackFrom = Get-Parameter $Parameters 'FallbackServer' $null $fallbackPath = "$(Get-DataProperty $fallbackFrom 'Path')".Trim() if ($fallbackPath) { $fallbackPath = [Environment]::ExpandEnvironmentVariables($fallbackPath) if (Test-Path -LiteralPath $fallbackPath -PathType Leaf) { try { $fallback = Get-AppLogFallbackServer -Text (Read-AppLogFile -Path $fallbackPath) ` -Section "$(Get-DataProperty $fallbackFrom 'Section')" -Key "$(Get-DataProperty $fallbackFrom 'Key')" } catch { $fallback = '' } } } $gatheredAt = Get-Date $since = $gatheredAt.Date.AddDays(-($days - 1)) # The last part of the path may hold wildcards: Log*.csv is one log in many files. $path = '' $found = @() if ($configured) { $path = [Environment]::ExpandEnvironmentVariables($configured) $folder = Split-Path -Path $path -Parent $leaf = Split-Path -Path $path -Leaf if ($folder -and (Test-Path -LiteralPath $folder -PathType Container)) { $found = @(Get-ChildItem -LiteralPath $folder -Filter $leaf -File -Force -ErrorAction SilentlyContinue) } } $levels = @{} $files = New-Object 'System.Collections.Generic.List[psobject]' $errors = New-Object 'System.Collections.Generic.List[psobject]' $events = New-Object 'System.Collections.Generic.List[psobject]' $errorCount = 0 $oldest = $null foreach ($file in $found) { $fileDate = Get-AppLogFileDate -Name $file.Name -LastWriteTime $file.LastWriteTime -Pattern $datePattern # A file is in the period by the day it is for, and by when it was last written. if ($file.LastWriteTime -lt $since -and ($null -eq $fileDate -or $fileDate -lt $since)) { continue } $record = [ordered]@{ Name = $file.Name; Length = $file.Length; LastWriteTime = $file.LastWriteTime; Entries = $null; Errors = $null; Skipped = $null } if ($file.Length -gt $maximumMB * 1MB) { $record.Skipped = 'TooLarge' } else { try { if ($layout.Table) { $entries = @(Read-AppLogDatabase -Path $file.FullName -Layout $layout -Since $since) } else { $entries = @(ConvertFrom-AppLogText -Text (Read-AppLogFile -Path $file.FullName) -Layout $layout -FileDate $fileDate -LastWriteTime $file.LastWriteTime) } $record.Entries = $entries.Count $record.Errors = 0 foreach ($entry in $entries) { if ($null -ne $entry.Time -and $entry.Time -lt $since) { continue } if ($null -ne $entry.Time -and ($null -eq $oldest -or $entry.Time -lt $oldest)) { $oldest = $entry.Time } $levels[$entry.Level] = 1 + [int]$levels[$entry.Level] if ($eventPattern -and $events.Count -lt $script:AppLogMaximumEvents) { $said = $null try { $said = Select-AppLogEvent -Entry $entry -Pattern $eventPattern } catch { $eventPattern = '' } if ($said) { $said | Add-Member -NotePropertyName File -NotePropertyValue $file.Name $events.Add($said) } } if ($errorLevels -notcontains $entry.Level) { continue } if ($ignore) { try { if ("$($entry.Message)" -match $ignore) { continue } } catch { $ignore = '' } } $errorCount++ $record.Errors++ if ($errors.Count -ge $script:AppLogMaximumErrors) { continue } $errors.Add([pscustomobject]@{ Time = $entry.Time Level = $entry.Level Source = $entry.Source Exception = ConvertTo-AppLogCut -Text $entry.Exception -Length $script:AppLogExceptionLength Message = ConvertTo-AppLogCut -Text $entry.Message -Length $script:AppLogMessageLength File = $file.Name }) } } catch { $record.Skipped = $_.Exception.GetBaseException().Message } } $files.Add([pscustomobject]$record) } [pscustomobject]@{ PSTypeName = 'Gutcheck.Data.AppLog' App = "$(Get-Parameter $Parameters 'App' '')" ConfiguredPath = $configured Path = $path Days = $days GatheredAt = $gatheredAt Files = @($files) Levels = @($levels.Keys | Sort-Object | ForEach-Object { [pscustomobject]@{ Level = $_; Count = $levels[$_] } }) ErrorCount = $errorCount Errors = @($errors) Events = @($events) Oldest = $oldest FallbackServer = $fallback } } function Get-AppLogErrorGroup { <# .SYNOPSIS The errors by where they came from and what they were: count, last time, one example. Most frequent first. Pure. .DESCRIPTION "Where" is the last part of the source - a logger is named for its class, and the namespaces before it are the same on every line - and "what" is the exception's type, the part before the first colon. #> [CmdletBinding()] [OutputType([psobject])] param([AllowNull()][AllowEmptyCollection()]$ErrorEntry) $order = New-Object 'System.Collections.Generic.List[string]' $groups = @{} foreach ($entry in @($ErrorEntry | Where-Object { $_ })) { # The last part of a logger's name is its class. The name of a program is no # such name: "CLMgr.exe" is not "exe". $source = "$(Get-DataProperty $entry 'Source')".Trim() if ($source -notmatch '(?i)\.(exe|dll)$') { $source = @($source -split '\.')[-1].Trim() } $type = @("$(Get-DataProperty $entry 'Exception')" -split ':', 2)[0].Trim() $type = @($type -split '\.')[-1] if ($type -notmatch '^[A-Za-z_][A-Za-z0-9_`]*$') { $type = '' } # An entry that does not name what kind of error it was: then what it says is # what tells one error from another. Its opening, with the numbers taken out - # "reconnecting in 28 seconds" and "in 11 seconds" are one thing. A log read line # by line never names a kind, and without this all its errors were one group # under the name of the program. if (-not $type) { $said = ("$(Get-DataProperty $entry 'Message')" -replace '\d+', '#' -replace '\s+', ' ').Trim() if ($said.Length -gt 70) { $said = $said.Substring(0, 70).TrimEnd() + ' [...]' } if ($source -and $said) { $source = '{0}: {1}' -f $source, $said } elseif ($said) { $source = $said } } $key = '{0}|{1}' -f $source, $type if (-not $groups.ContainsKey($key)) { $order.Add($key) $groups[$key] = [pscustomobject]@{ Count = 0; Source = $source; Exception = $type; Last = $null; Example = "$(Get-DataProperty $entry 'Message')" } } $group = $groups[$key] $group.Count++ $time = Get-DataProperty $entry 'Time' if ($null -ne $time) { try { if ($null -eq $group.Last -or [datetime]$time -gt [datetime]$group.Last) { $group.Last = [datetime]$time } } catch { } } } # Sort-Object is not stable on Windows PowerShell 5.1: the order of first appearance # breaks a tie. $index = @{} for ($i = 0; $i -lt $order.Count; $i++) { $index[$order[$i]] = $i } $order | Sort-Object @{ Expression = { -$groups[$_].Count } }, @{ Expression = { $index[$_] } } | ForEach-Object { $groups[$_] } } function ConvertTo-AppLogFinding { [CmdletBinding()] [OutputType([psobject])] param( [AllowNull()]$Data, [hashtable]$Parameters = @{} ) New-AppLogErrorFinding -Data $Data -Parameters $Parameters # The lines that name a Service, where the Definition looks for them and a file was # read: a log that was not read says nothing about them, and the Finding above says so. if (-not "$(Get-Parameter $Parameters 'EventPattern' '')".Trim()) { return } if (-not @(Get-DataCollection $Data 'Files' | Where-Object { -not (Get-DataProperty $_ 'Skipped') }).Count) { return } $failed = New-AppLogFailedFinding -Data $Data -Parameters $Parameters $failed ConvertTo-AppLogTimedEvent -Data $Data -Finding $failed -Parameters $Parameters } function Get-AppLogKeptText { <# .SYNOPSIS That the application keeps its log only a short while, where the Check Definition says how long (KeptHours): "Nextcloud hebt sein Protokoll nur etwa einen Tag auf". Nothing where it does not. Pure. .DESCRIPTION Said beside how far back the log reaches: a log of a day that names no failure says nothing of the week before (#175). #> [CmdletBinding()] [OutputType([string])] param([AllowNull()]$Data, [hashtable]$Parameters = @{}) $hours = ConvertTo-Number (Get-Parameter $Parameters 'KeptHours' $null) if ($null -eq $hours -or $hours -le 0) { return '' } $while = (Get-Text 'Value.AppLog.Kept.Hours') -f [math]::Round($hours) if ($hours % 24 -eq 0) { $while = (Get-Text 'Value.AppLog.Kept.Days') -f ($hours / 24) } if ($hours -eq 24) { $while = Get-Text 'Value.AppLog.Kept.Day' } $app = "$(Get-DataProperty $Data 'App')".Trim() if (-not $app) { $app = Get-Text 'Value.AppLog.Kept.TheApplication' } (Get-Text 'Value.AppLog.Kept') -f $app, $while } function Get-AppLogEventService { <# .SYNOPSIS The Service a line that EventPattern matched is about, as ConvertTo-UrlService gives one: Server, Port and Subject, as the Map keys a Service on a port. $null for a line that names none. Pure. .DESCRIPTION A URL is its host and its port, the port of its scheme where it writes none: https://cloud.contoso.example/... is cloud.contoso.example:443. Not the URL as a Service of its own: what failed is the connection to the host's port, and that is the Service the Server Check and the Links draw, the URL going into the event's words (#174); ConvertTo-UrlService is the one rule for that. A host without a port is the Server alone - but for the server of -Fallback, which is on that one's port. A line that names neither is about -Fallback, the server the application's configuration names (#175): a socket error names nobody, and the client has one server. $null where there is none. #> [CmdletBinding()] [OutputType([psobject])] param([AllowNull()]$Line, [AllowNull()][AllowEmptyString()][string]$Fallback) $service = ConvertTo-UrlService -Url "$(Get-DataProperty $Line 'Url')" if ($service) { return $service } $configured = $null if ("$Fallback".Trim()) { $configured = ConvertTo-UrlService -Url $Fallback if (-not $configured) { $configured = New-PortService -Server (ConvertTo-ServerName -Name $Fallback) } } $server = "$(Get-DataProperty $Line 'Host')".Trim() if (-not $server) { return $configured } $service = New-PortService -Server $server -Port (Get-DataProperty $Line 'Port') if ($null -eq $service.Port -and $configured -and (ConvertTo-ServerName -Name $server) -eq $configured.Server) { $service = New-PortService -Server $server -Port $configured.Port } $service } function Get-AppLogEventDetail { <# .SYNOPSIS What a line that EventPattern matched said, as the timeline shows it: its message, with the HTTP status it named given its meaning where it names it. Pure. .DESCRIPTION "... HTTP status 404" is "... HTTP status 404 (nicht gefunden)": a code is never shown without what it means (Format-HttpStatus, with the server's reason where this has no word for it; 0 where the server never answered). The last time the message writes the status is the status; where it does not write it, the status goes after it. #> [CmdletBinding()] [OutputType([string])] param([AllowNull()]$Line) $message = "$(Get-DataProperty $Line 'Message')".Trim() $status = "$(Get-DataProperty $Line 'Status')".Trim() $said = Format-HttpStatus -Status $status -Reason "$(Get-DataProperty $Line 'Error')" if (-not $said) { return $message } $at = [regex]::Matches($message, ('(?<![\d.:/])' + [regex]::Escape($status) + '(?!\d)')) if (-not $at.Count) { if (-not $message) { return $said } return ((Get-Text 'Value.Said.Then') -f $message, $said) } $last = $at[$at.Count - 1] $message.Substring(0, $last.Index) + $said + $message.Substring($last.Index + $last.Length) } function Get-AppLogLogName { <# .SYNOPSIS The log a Timed Event of this Check names: the path as the Check Definition writes it, without a User's folder in it. Pure. #> [CmdletBinding()] [OutputType([string])] param([AllowNull()]$Data) $log = "$(Get-DataProperty $Data 'ConfiguredPath')".Trim() if (-not $log) { $log = "$(Get-DataProperty $Data 'App')".Trim() } $log } function New-AppLogFailedFinding { <# .SYNOPSIS The Finding about the Services the application wrote it could not reach: per Service how often and when last, and what it said. Says there were none where there were none, and how far back the log reaches. .DESCRIPTION A warning above FailedWarnAbove lines about one Service: one line now and then is a client that retried and got through. Each Service is a part of its own, in the colour of its own count (ADR-0015). #> [CmdletBinding()] [OutputType([psobject])] param([AllowNull()]$Data, [hashtable]$Parameters = @{}) $warn = Get-Parameter $Parameters 'FailedWarnAbove' 10 $fail = Get-Parameter $Parameters 'FailedFailAbove' ([double]::MaxValue) $check = Get-Text 'Check.AppLog.Failed' $days = Get-DataProperty $Data 'Days' $events = Get-DataCollection $Data 'Events' $oldest = ConvertTo-DataTime (Get-DataProperty $Data 'Oldest') $kept = Get-AppLogKeptText -Data $Data -Parameters $Parameters $fallback = "$(Get-DataProperty $Data 'FallbackServer')" if (-not $events.Count) { $value = (Get-Text 'Value.AppLog.NoFailuresUnknown') -f $days if ($null -ne $oldest) { $value = (Get-Text 'Value.AppLog.NoFailures') -f $days, $oldest } if ($kept) { $value = '{0}; {1}' -f $value, $kept } return New-Finding -Category Apps -Check $check -Severity OK -Value $value } # Per Service, in the order the lines named them, most often first. $order = New-Object 'System.Collections.Generic.List[string]' $by = @{} foreach ($one in $events) { $service = Get-AppLogEventService -Line $one -Fallback $fallback $key = Get-Text 'Value.AppLog.FailedNowhere' if ($service) { $key = $service.Subject } if (-not $by.ContainsKey($key)) { $order.Add($key) $by[$key] = [pscustomobject]@{ Key = $key; Placed = [bool]$service; Count = 0; Last = $null; Errors = New-Object 'System.Collections.Generic.List[string]' } } $group = $by[$key] $group.Count++ $time = ConvertTo-DataTime (Get-DataProperty $one 'Time') if ($null -ne $time -and ($null -eq $group.Last -or $time -gt $group.Last)) { $group.Last = $time } # What went wrong: the HTTP status with its meaning where the server answered, else # the error in the line's words - a socket error's "Connection refused" says more # than a status of no answer. $what = "$(Get-DataProperty $one 'Error')".Trim() $status = ConvertTo-Number (Get-DataProperty $one 'Status') if ($null -ne $status -and ($status -gt 0 -or -not $what)) { $what = Format-HttpStatus -Status "$(Get-DataProperty $one 'Status')" -Reason $what } if ($what -and -not $group.Errors.Contains($what)) { $group.Errors.Add($what) } } $index = @{} for ($i = 0; $i -lt $order.Count; $i++) { $index[$order[$i]] = $i } $groups = @($order | Sort-Object @{ Expression = { -$by[$_].Count } }, @{ Expression = { $index[$_] } } | ForEach-Object { $by[$_] }) $named = @($groups | ForEach-Object { $item = (Get-Text 'Value.AppLog.FailedAt') -f $_.Key, $_.Count if ($null -ne $_.Last) { $item = (Get-Text 'Value.AppLog.FailedAtLast') -f $_.Key, $_.Count, $_.Last } # Behind it, and not in brackets: a status has its meaning in them already. if ($_.Errors.Count) { $item = (Get-Text 'Value.Said.Then') -f $item, ($_.Errors -join ', ') } $item }) $value = (Get-Text 'Value.AppLog.Failures') -f $events.Count, $days, ($named -join '; ') # How far back the log reaches, so that a short log is not read as a quiet week. $reach = @() if ($null -ne $oldest) { $reach += (Get-Text 'Value.AppLog.Reaches') -f $oldest } if ($kept) { $reach += $kept } if ($reach.Count) { $value = '{0} | {1}' -f $value, ($reach -join '; ') } $severity = 'INFO' $parts = [ordered]@{} foreach ($group in $groups) { $own = Get-Severity $group.Count $warn $fail if ($own -eq 'OK') { $own = 'INFO' } $severity = Get-WorstSeverity $severity $own if ($group.Placed) { $parts[$group.Key] = $own } } # One Service is what the Finding is about, as the drops of one Server are. ADR-0015. $subject = '' if ($parts.Count -eq 1) { $subject = @($parts.Keys)[0] } $app = "$(Get-DataProperty $Data 'App')".Trim() if (-not $app) { $app = Get-Text 'Value.AppLog.TheApplication' } New-Finding -Category Apps -Check $check -Severity $severity -Value $value ` -Meaning ((Get-Text 'Meaning.AppLog.Failed') -f $app) -Hint (Get-Text 'Hint.AppLog.Failed') ` -Subject $subject -Subjects $parts } function ConvertTo-AppLogTimedEvent { <# .SYNOPSIS Every line EventPattern matched as a Timed Event Failed on its Service, with the Finding that counted it, and how far back the log reaches. Pure. ADR-0010. .DESCRIPTION On the Server by its host as the line names it and on the Service of its port (Get-AppLogEventService); the URL and the error stay in the words, as the application wrote them - in the language of Windows, where .NET wrote them - and an HTTP status with its meaning (Get-AppLogEventDetail). A line that names no host is on the server the application's configuration names; where it names none, and where the line's time cannot be read, the line is left out: its Finding counts it, and the timeline cannot place it. The log's reach says, where the Definition gives KeptHours, that the application keeps it only that long. #> [CmdletBinding()] [OutputType([psobject])] param([AllowNull()]$Data, [AllowNull()]$Finding, [hashtable]$Parameters = @{}) $log = Get-AppLogLogName -Data $Data $app = "$(Get-DataProperty $Data 'App')".Trim() $fallback = "$(Get-DataProperty $Data 'FallbackServer')" foreach ($one in (Get-DataCollection $Data 'Events')) { $at = ConvertTo-DataTime (Get-DataProperty $one 'Time') if ($null -eq $at) { continue } $service = Get-AppLogEventService -Line $one -Fallback $fallback if (-not $service) { continue } $detail = Get-AppLogEventDetail -Line $one if ($app) { $detail = (Get-Text 'Value.AppLog.Timeline.Failed') -f $app, $detail } New-TimedEvent -Time $at -Lane Server -Mark Failed -Subject $service.Server -Detail $detail -Log $log ` -Finding $Finding -Port $service.Port } $oldest = ConvertTo-DataTime (Get-DataProperty $Data 'Oldest') $kept = Get-AppLogKeptText -Data $Data -Parameters $Parameters if ($kept -and $log -and $null -ne $oldest) { return New-TimedEvent -Time $oldest -Lane Log -Mark Reaches -Log $log -Detail $kept } ConvertTo-LogCoverageTimedEvent -Coverage @([pscustomobject]@{ Log = $log; Oldest = $oldest }) } function New-AppLogErrorFinding { <# .SYNOPSIS The Finding about the errors the application wrote into its own log. #> [CmdletBinding()] [OutputType([psobject])] param( [AllowNull()]$Data, [hashtable]$Parameters = @{} ) $warn = Get-Parameter $Parameters 'ErrorWarnAbove' 20 $fail = Get-Parameter $Parameters 'ErrorFailAbove' ([double]::MaxValue) $check = Get-Text 'Check.AppLog.Errors' $path = "$(Get-DataProperty $Data 'Path')" if (-not "$(Get-DataProperty $Data 'ConfiguredPath')") { return New-Finding -Category Apps -Check $check -Severity INFO ` -Value (Get-Text 'Value.AppLog.NotConfigured') -Hint (Get-Text 'Hint.AppLog.NotConfigured') } $days = Get-DataProperty $Data 'Days' $files = Get-DataCollection $Data 'Files' if (-not $files.Count) { return New-Finding -Category Apps -Check $check -Severity INFO ` -Value ((Get-Text 'Value.AppLog.NoFiles') -f $path, $days) -Hint (Get-Text 'Hint.AppLog.NoFiles') } $skipped = @($files | Where-Object { Get-DataProperty $_ 'Skipped' }) $read = @($files | Where-Object { -not (Get-DataProperty $_ 'Skipped') }) if (-not $read.Count) { return New-Finding -Category Apps -Check $check -Severity INFO ` -Value ((Get-Text 'Value.AppLog.NoneRead') -f $skipped.Count, (Get-DataProperty $skipped[0] 'Name'), (Get-AppLogSkippedText -Skipped (Get-DataProperty $skipped[0] 'Skipped'))) ` -Hint (Get-Text 'Hint.AppLog.NoneRead') } $count = ConvertTo-Number (Get-DataProperty $Data 'ErrorCount') if ($null -eq $count) { $count = 0 } $lines = @() if (-not $count) { $lines += (Get-Text 'Value.AppLog.NoErrors') -f $days, $read.Count } else { $groups = @(Get-AppLogErrorGroup -ErrorEntry (Get-DataCollection $Data 'Errors')) $last = @($groups | ForEach-Object { $_.Last } | Where-Object { $null -ne $_ } | Sort-Object -Descending) $line = (Get-Text 'Value.AppLog.ErrorCount') -f $count, $days if ($last.Count) { $line = (Get-Text 'Value.AppLog.ErrorCountLast') -f $count, $days, $last[0] } $lines += $line $top = @($groups | Select-Object -First 3 | ForEach-Object { $what = $_.Source if ($_.Exception) { $what = '{0} ({1})' -f $_.Source, $_.Exception } (Get-Text 'Value.AppLog.GroupCount') -f $_.Count, $what }) $lines += (Get-Text 'Value.AppLog.Most') -f ($top -join '; ') } if ($skipped.Count) { $lines += (Get-Text 'Value.AppLog.Skipped') -f $skipped.Count } $severity = Get-Severity $count $warn $fail $hint = '' if ($count) { if ($severity -eq 'OK') { $severity = 'INFO' } $hint = (Get-Text 'Hint.AppLog.Errors') -f (Get-AppLogSectionTitle -Data $Data), $path } New-Finding -Category Apps -Check $check -Severity $severity -Value ($lines -join ' | ') -Hint $hint } function Get-AppLogSectionTitle { <# .SYNOPSIS What the Section of one application's errors is called. Pure. .DESCRIPTION One place, because the Finding's Hint names the Section by this title and the Report makes a link of it only when the two are the same. #> [CmdletBinding()] [OutputType([string])] param([AllowNull()]$Data) $app = "$(Get-DataProperty $Data 'App')".Trim() if ($app) { return (Get-Text 'Title.AppLog.ErrorsOf') -f $app } Get-Text 'Title.AppLog.Errors' } function Get-AppLogSkippedText { <# .SYNOPSIS Why a file was not read, in German. Pure. .DESCRIPTION The Gatherer says TooLarge of a file over MaxFileMB; anything else it says is what Windows said when the file would not open, and stays in Windows' words. #> [CmdletBinding()] [OutputType([string])] param([AllowNull()][AllowEmptyString()][string]$Skipped) if ("$Skipped" -eq 'TooLarge') { return Get-Text 'Value.AppLog.Skipped.TooLarge' } if ("$Skipped" -eq 'NoSqlite') { return Get-Text 'Value.AppLog.Skipped.NoSqlite' } if ("$Skipped" -eq 'BadDefinition') { return Get-Text 'Value.AppLog.Skipped.BadDefinition' } "$Skipped" } function ConvertTo-AppLogSection { [CmdletBinding()] [OutputType([psobject])] param([AllowNull()]$Data) # The column names are what the Report shows, so they are German and live with the # other text. New-Section -Title (Get-AppLogSectionTitle -Data $Data) -Help (Get-Text 'Help.AppLog.Errors') -Row @( Get-AppLogErrorGroup -ErrorEntry (Get-DataCollection $Data 'Errors') | ForEach-Object { $row = [ordered]@{} $row[(Get-Text 'Column.AppLog.Count')] = $_.Count $row[(Get-Text 'Column.AppLog.Source')] = $_.Source $row[(Get-Text 'Column.AppLog.Exception')] = $_.Exception $row[(Get-Text 'Column.AppLog.Last')] = $(if ($null -ne $_.Last) { '{0:yyyy-MM-dd HH:mm}' -f $_.Last } else { '' }) $row[(Get-Text 'Column.AppLog.Example')] = $_.Example [pscustomobject]$row } ) $app = "$(Get-DataProperty $Data 'App')".Trim() $title = Get-Text 'Title.AppLog.Files' if ($app) { $title = (Get-Text 'Title.AppLog.FilesOf') -f $app } New-Section -Title $title -Help (Get-Text 'Help.AppLog.Files') -Row @( foreach ($file in (Get-DataCollection $Data 'Files')) { $row = [ordered]@{} $row[(Get-Text 'Column.AppLog.File')] = Get-DataProperty $file 'Name' $row[(Get-Text 'Column.AppLog.LastWriteTime')] = Get-DataProperty $file 'LastWriteTime' $row[(Get-Text 'Column.AppLog.Length')] = Get-DataProperty $file 'Length' $row[(Get-Text 'Column.AppLog.Entries')] = Get-DataProperty $file 'Entries' $row[(Get-Text 'Column.AppLog.Errors')] = Get-DataProperty $file 'Errors' $row[(Get-Text 'Column.AppLog.Skipped')] = Get-AppLogSkippedText -Skipped (Get-DataProperty $file 'Skipped') [pscustomobject]$row } ) } function ConvertTo-AppLogEvent { <# .SYNOPSIS The errors as rows for events.csv, beside what Windows logged. #> [CmdletBinding()] [OutputType([psobject])] param([AllowNull()]$Data) $app = "$(Get-DataProperty $Data 'App')".Trim() foreach ($entry in (Get-DataCollection $Data 'Errors')) { $message = "$(Get-DataProperty $entry 'Message')" $exception = "$(Get-DataProperty $entry 'Exception')" if ($exception) { $message = '{0} | {1}' -f $message, $exception } [pscustomobject][ordered]@{ Time = Get-DataProperty $entry 'Time' Category = 'AppLog' Provider = ('{0} {1}' -f $app, (Get-DataProperty $entry 'Source')).Trim() Id = Get-DataProperty $entry 'Level' Message = $message } } } |