Private/WebsiteNetLog.ps1
|
# Reading a net log: what a page did, from the file a Chromium browser wrote while it loaded it. # # Pure, every function of it: text in, a record of the page out. The Website Kind's Gatherer # hands it the net log of the browser it started; the tests hand it fixtures trimmed from # real net logs. Kept apart from the Kind, as BrowserProfile.ps1 is from the browser Kinds, # because it changes for a different reason: when Chromium writes its net log differently. # Which sources of a net log lie beneath which: a request, the job that finds it a stream, # the stream's jobs, what those connect with, and the sockets and name lookups at the # bottom. The parse follows a source dependency only downwards in this order. Upwards # would lead from a shared socket back to every other request that used it, Edge's own # among them. Names, not numbers: the numbers are the document's (see the constants). $script:WebsiteSourceLayer = @{ URL_REQUEST = 0 HTTP_STREAM_JOB_CONTROLLER = 1 HTTP_STREAM_JOB = 2 TRANSPORT_CONNECT_JOB = 3 TCP_CONNECT_JOB = 3 SSL_CONNECT_JOB = 3 SOCKS_CONNECT_JOB = 3 HTTP_PROXY_CONNECT_JOB = 3 QUIC_SESSION_POOL_DIRECT_JOB = 3 QUIC_SESSION_POOL_PROXY_JOB = 3 QUIC_SESSION_POOL_JOB = 3 HTTP2_SESSION = 3 QUIC_SESSION = 3 SOCKET = 4 HOST_RESOLVER_IMPL_JOB = 4 } function ConvertFrom-WebsiteCertificate { <# .SYNOPSIS Who a certificate is for, who issued it and how long it is valid, from the PEM text a net log holds. Nothing for text that is no certificate. Pure. .DESCRIPTION The names are those of its subject alternative names, where it has them, and else the one in its subject: the names a browser holds the address against. #> [CmdletBinding()] [OutputType([psobject])] param([AllowNull()][AllowEmptyString()][string]$Pem) $body = ($Pem -replace '-----(BEGIN|END) CERTIFICATE-----', '' -replace '\s', '') if (-not $body) { return $null } try { $certificate = New-Object System.Security.Cryptography.X509Certificates.X509Certificate2 -ArgumentList (, [Convert]::FromBase64String($body)) # The extension's text is written in the language of Windows ("DNS-Name=" or # "DNS Name="); what stands after each "=" is the name either way. $alternative = @($certificate.Extensions | Where-Object { $_.Oid.Value -eq '2.5.29.17' } | ForEach-Object { [regex]::Matches($_.Format($false), '=\s*([^,\r\n]+)') | ForEach-Object { $_.Groups[1].Value.Trim() } }) if (-not $alternative.Count) { $alternative = @($certificate.GetNameInfo([System.Security.Cryptography.X509Certificates.X509NameType]::SimpleName, $false)) } [pscustomobject]@{ Subject = $certificate.Subject Issuer = $certificate.Issuer NotBefore = $certificate.NotBefore NotAfter = $certificate.NotAfter Names = @($alternative | Where-Object { $_ }) } } catch { $null } } function Get-WebsiteSignIn { <# .SYNOPSIS Whether the page asked for a sign-in, with which schemes, whether the browser was allowed to answer with the User's Windows account, and whether the site turned the answer down. Nothing for a page that asked for none. Pure. .DESCRIPTION The schemes are what the 401 answers offered. The rest is in the request's authentication controller, which the request names as a source dependency: Chromium says there whether it may send the User's own credentials to this site (allows_default_credentials - false where the site is not in the Local Intranet zone or the AuthServerAllowlist policy), and whether the site rejected what it sent. The credentials themselves are never in a net log of the default mode. #> [CmdletBinding()] [OutputType([psobject])] param([Parameter(Mandatory)]$Request, [Parameter(Mandatory)][hashtable]$BySource, [Parameter(Mandatory)][hashtable]$TypeName, [Parameter(Mandatory)][hashtable]$SourceName) if (-not $Request.Challenges.Count) { return $null } $allowed = $null $rejected = $false $controllers = @($Request.Dependencies | Where-Object { $SourceName["$($_.type)"] -eq 'HTTP_AUTH_CONTROLLER' } | ForEach-Object { "$($_.id)" } | Select-Object -Unique) foreach ($id in $controllers) { if (-not $BySource.ContainsKey($id)) { continue } foreach ($e in $BySource[$id]) { switch ($TypeName["$($e.type)"]) { 'AUTH_HANDLER_CREATE_RESULT' { $may = $e.params.allows_default_credentials if ($may -eq $true) { $allowed = $true } elseif ($may -eq $false -and $allowed -ne $true) { $allowed = $false } } 'AUTH_HANDLE_CHALLENGE' { if ("$($e.params.authorization_result)" -eq 'reject') { $rejected = $true } } } } } [pscustomobject]@{ PSTypeName = 'Gutcheck.WebsiteSignIn' Schemes = @($Request.Challenges) DefaultCredentials = $allowed Rejected = $rejected } } function Get-WebsiteProxy { <# .SYNOPSIS The proxy the page went through and how the browser found it. Pure. .DESCRIPTION How the browser was told to find one is its proxy configuration, written to the net log whenever it changed: a PAC file (pac_url), automatic detection (WPAD, auto_detect), a fixed server (single_proxy or proxy_per_scheme), or none. The one in force when the page was requested counts. from_system says it came from the User's Windows settings; a configuration without it came from somewhere else, and in a Run - where Gutcheck gives the browser no proxy of its own - that is a policy. Each attempt to fetch a PAC file is kept with where it came from: WPAD, which failing only means there is none, or the PAC address, which failing is a fault. #> [CmdletBinding()] [OutputType([psobject])] param( [Parameter(Mandatory)][AllowEmptyCollection()]$Events, [Parameter(Mandatory)][hashtable]$BySource, [Parameter(Mandatory)][hashtable]$TypeName, [Parameter(Mandatory)][hashtable]$SourceName, [string]$Begin, [string]$End, [AllowNull()]$Before, [Parameter(Mandatory)][scriptblock]$NetError, [AllowNull()][AllowEmptyString()][string]$Used, [AllowNull()]$ResolveMs, [bool]$SignInAsked ) $config = $null foreach ($e in $Events) { if ($null -eq $e -or $TypeName["$($e.type)"] -ne 'PROXY_CONFIG_CHANGED') { continue } if ($null -ne $Before -and $null -ne $config -and [long]$e.time -gt [long]$Before) { break } $config = $e.params.new_config } $fetches = @(foreach ($id in $BySource.Keys) { $list = $BySource[$id] if ($SourceName["$($list[0].source.type)"] -ne 'PAC_FILE_DECIDER') { continue } $from = $null; $started = $null foreach ($e in $list) { if ($TypeName["$($e.type)"] -ne 'PAC_FILE_DECIDER_FETCH_PAC_SCRIPT') { continue } if ("$($e.phase)" -eq $Begin) { $from = "$($e.params.source)"; $started = [long]$e.time } elseif ("$($e.phase)" -eq $End) { [pscustomobject]@{ Source = $from Wpad = $from -match '^WPAD' Error = & $NetError $e.params Ms = $(if ($null -ne $started) { [long]$e.time - $started }) } } } }) if ($null -eq $config -and -not $Used -and -not $fetches.Count) { return $null } $pac = "$($config.pac_url)".Trim() $server = @(@($config.single_proxy) + @($config.proxy_per_scheme) | Where-Object { $_ } | ForEach-Object { "$_".Trim('[', ']', ' ') }) -join '; ' $mode = 'Direct' if ($pac) { $mode = 'Script' } elseif ($config.auto_detect -eq $true) { $mode = 'Detect' } elseif ($server) { $mode = 'Server' } [pscustomobject]@{ PSTypeName = 'Gutcheck.WebsiteProxy' Mode = $mode AutoDetect = [bool]($config.auto_detect -eq $true) PacUrl = $pac Server = $server FromSystem = $(if ($null -eq $config) { $null } else { [bool]($config.from_system -eq $true) }) Used = $Used ResolveMs = $ResolveMs PacFetches = $fetches SignInAsked = $SignInAsked } } function Read-WebsiteNetLogDocument { <# .SYNOPSIS A net log's text as a document, mended where it was cut off. Pure. .DESCRIPTION A browser writes its net log one event a line and closes the brackets when it exits. One that was stopped - which is what the time limit does to a page that hangs - leaves the last line half written and no closing brackets. Such a log is read up to its last whole event, and says that it was cut off. #> [CmdletBinding()] [OutputType([psobject])] param([AllowNull()][AllowEmptyString()][string]$Text) $none = [pscustomobject]@{ Document = $null; CutOff = $false } if (-not "$Text".Trim()) { return $none } try { return [pscustomobject]@{ Document = ($Text | ConvertFrom-Json -ErrorAction Stop); CutOff = $false } } catch { } $lines = $Text -split "`r?`n" $head = -1 for ($i = 0; $i -lt $lines.Count; $i++) { if ($lines[$i] -match '^\s*"events"\s*:\s*\[\s*$') { $head = $i; break } } if ($head -lt 1) { return $none } $kept = New-Object System.Collections.Generic.List[string] for ($i = $head + 1; $i -lt $lines.Count; $i++) { $line = $lines[$i].Trim() if (-not $line) { continue } if (-not $line.StartsWith('{')) { break } $kept.Add($line.TrimEnd(',')) } # The last line is the one the stop may have cut. Read on its own it is cheap to try, # where trying the whole document again costs seconds on a large one. while ($kept.Count) { try { $null = $kept[$kept.Count - 1] | ConvertFrom-Json -ErrorAction Stop; break } catch { $kept.RemoveAt($kept.Count - 1) } } $mended = (($lines[0..$head]) -join "`n") + "`n" + ($kept -join ",`n") + "`n]}" try { return [pscustomobject]@{ Document = ($mended | ConvertFrom-Json -ErrorAction Stop); CutOff = $true } } catch { return $none } } function ConvertTo-WebsiteHostName { <# .SYNOPSIS The host in the forms a net log writes it - "https://host", "host:443", a whole URL - as the bare lowercase name. Pure. #> [CmdletBinding()] [OutputType([string])] param([AllowNull()][AllowEmptyString()][string]$Value) $text = "$Value".Trim() if (-not $text) { return '' } $uri = $null if ($text -match '^[a-z][a-z0-9+.-]*://' -and [uri]::TryCreate($text, [UriKind]::Absolute, [ref]$uri)) { return $uri.Host.ToLowerInvariant() } ($text -replace ':\d+$', '').Trim('[', ']').ToLowerInvariant() } function Select-WebsiteStepAttempt { <# .SYNOPSIS Of the attempts at one step, the one the page went on with, and what became of it: Measured, Cached, Failed or Open. Nothing where there was none. Pure. .DESCRIPTION The first to succeed, where one did - for a tie the shorter, which is the one the page itself waited for. Else an answer from the browser's cache: a lookup that took no time, and is no reading of the DNS server. Else the first to fail, with how long it took to. Else one begun and never ended: the browser was stopped while it waited. #> [CmdletBinding()] [OutputType([psobject])] param([AllowNull()][AllowEmptyCollection()]$Attempt) $all = @($Attempt | Where-Object { $_ }) $done = @($all | Where-Object { $null -ne $_.End -and -not $_.Error -and -not $_.Cached } | Sort-Object @{ Expression = { [long]$_.End } }, @{ Expression = { [long]$_.Begin }; Descending = $true }) if ($done.Count) { return [pscustomobject]@{ State = 'Measured'; Begin = $done[0].Begin; End = $done[0].End; Error = $null; Proxy = $done[0].Proxy } } $cached = @($all | Where-Object { $_.Cached } | Sort-Object { [long]$_.Begin }) if ($cached.Count) { return [pscustomobject]@{ State = 'Cached'; Begin = $cached[0].Begin; End = $null; Error = $null; Proxy = $cached[0].Proxy } } $failed = @($all | Where-Object { $null -ne $_.End -and $_.Error } | Sort-Object { [long]$_.End }) if ($failed.Count) { return [pscustomobject]@{ State = 'Failed'; Begin = $failed[0].Begin; End = $failed[0].End; Error = $failed[0].Error; Proxy = $failed[0].Proxy } } $open = @($all | Where-Object { $null -eq $_.End } | Sort-Object { [long]$_.Begin }) if ($open.Count) { return [pscustomobject]@{ State = 'Open'; Begin = $open[0].Begin; End = $null; Error = $null; Proxy = $open[0].Proxy } } $null } function Get-WebsiteHostStep { <# .SYNOPSIS The steps of a page at one host as the waterfall draws them: name resolution, connection, TLS, the wait for the first byte and the span of its requests, each with where it began on the page's time axis and how long it took. Pure. .DESCRIPTION Only the steps the net log shows: a connection the page found open has none of its own. StartMs is counted from the page's start (the Origin), Ms is the step's own length - for one that failed, how long it took to fail. A name answered from the browser's cache has a start and no length. The span of the requests (Step Response) runs from the first of the page's requests to the host to the end of the last; it failed where every one that ended ended in an error. .PARAMETER Attempts Every attempt at a step, by "host|step", as the walk of the net log collected them. .PARAMETER Hops The page's requests at this host, one per address they were sent to. #> [CmdletBinding()] [OutputType([psobject])] param( [Parameter(Mandatory)][hashtable]$Attempts, [AllowNull()][AllowEmptyCollection()]$Hops, [Parameter(Mandatory)][string]$HostName, [Parameter(Mandatory)][long]$Origin ) $step = { param([string]$Name, $Chosen) if (-not $Chosen) { return } [pscustomobject]@{ PSTypeName = 'Gutcheck.WebsiteStep' Step = $Name State = $Chosen.State StartMs = $(if ($null -ne $Chosen.Begin) { [long]$Chosen.Begin - $Origin }) Ms = $(if ($null -ne $Chosen.End -and $null -ne $Chosen.Begin) { [long]$Chosen.End - [long]$Chosen.Begin }) Error = $Chosen.Error Proxy = "$($Chosen.Proxy)" } } foreach ($name in 'Dns', 'Connect', 'Tls') { $key = '{0}|{1}' -f $HostName, $name if ($Attempts.ContainsKey($key)) { & $step $name (Select-WebsiteStepAttempt -Attempt $Attempts[$key]) } } $hopList = @($Hops | Where-Object { $_ }) # The wait for the first byte: from a request sent to its answer beginning to arrive. $waits = @(foreach ($hop in $hopList) { if ($null -eq $hop.ReadBegin) { continue } if ($null -ne $hop.FirstByte) { [pscustomobject]@{ Begin = $hop.ReadBegin; End = $hop.FirstByte; Error = $null; Cached = $false; Proxy = '' } } elseif ($null -ne $hop.End -and $hop.Error) { [pscustomobject]@{ Begin = $hop.ReadBegin; End = $hop.End; Error = $hop.Error; Cached = $false; Proxy = '' } } elseif ($null -eq $hop.End) { [pscustomobject]@{ Begin = $hop.ReadBegin; End = $null; Error = $null; Cached = $false; Proxy = '' } } }) & $step 'FirstByte' (Select-WebsiteStepAttempt -Attempt $waits) if (-not $hopList.Count) { return } $first = ($hopList | Measure-Object -Property Begin -Minimum).Minimum $ended = @($hopList | Where-Object { $null -ne $_.End } | Sort-Object { [long]$_.End }) $span = [pscustomobject]@{ State = 'Open'; Begin = $first; End = $null; Error = $null; Proxy = '' } if ($ended.Count) { $span.End = $ended[-1].End if (@($ended | Where-Object { -not $_.Error }).Count) { $span.State = 'Measured' } else { $span.State = 'Failed'; $span.Error = $ended[0].Error } } & $step 'Response' $span } function ConvertFrom-WebsiteNetLog { <# .SYNOPSIS Turns a net log a browser wrote into what the page did: whether it was answered, where it ended, and what happened at every host it needed. Pure. .DESCRIPTION Which requests are the page's: the navigation to the address (Chromium marks it "main frame") and every request the page started that carries the page's network isolation key - the site of the page, which Chromium partitions everything a page loads by. Edge's own requests carry its own key or none, or say that no origin started them, and are left out however many of them there are. The net log has no dependency from a navigation to what the page then loads; this key is the link. What happened at a host is read through the source dependencies, from each of the page's requests down to the stream it got, the connection that stream used and the name lookup and socket under it - downwards only, see WebsiteSourceLayer. Racing attempts are normal (Chromium tries QUIC and TCP at once and drops the loser), so a host counts as resolved, connected or encrypted when any attempt was, and as failed at that step only when none was. Event types, source types, phases and net error names are read from the document's own constants: their numbers change between browser versions. Problem is 'Unreadable' for a document that is no net log, and 'NoPage' for one in which the page was never requested. .PARAMETER Url The address the browser was asked to load. Picks the navigation where there were several; without it, the first is the page. #> [CmdletBinding()] [OutputType([psobject])] param( [AllowNull()][AllowEmptyString()][string]$Text, [AllowNull()][AllowEmptyString()][string]$Url ) $read = Read-WebsiteNetLogDocument -Text $Text $record = [ordered]@{ PSTypeName = 'Gutcheck.WebsitePage' Problem = $null CutOff = [bool]$read.CutOff CaptureMode = $null Url = $null FinalUrl = $null Redirects = @() Status = $null Finished = $false Error = $null ElapsedMs = $null Requests = @() Hosts = @() PageHosts = @() SignIn = $null Proxy = $null Timings = $null } $document = $read.Document $constants = Get-DataProperty $document 'constants' $events = @(Get-DataProperty $document 'events') $eventType = Get-DataProperty $constants 'logEventTypes' $source = Get-DataProperty $constants 'logSourceType' $phase = Get-DataProperty $constants 'logEventPhase' if (-not $eventType -or -not $source -or -not $phase -or -not $events.Count) { $record.Problem = 'Unreadable' return [pscustomobject]$record } $record.CaptureMode = "$(Get-DataProperty $constants 'logCaptureMode')" # Number to name, for the three tables read by name. $typeName = @{}; foreach ($p in $eventType.PSObject.Properties) { $typeName["$($p.Value)"] = $p.Name } $sourceName = @{}; foreach ($p in $source.PSObject.Properties) { $sourceName["$($p.Value)"] = $p.Name } $errorName = @{} $errors = Get-DataProperty $constants 'netError' if ($errors) { foreach ($p in $errors.PSObject.Properties) { $errorName["$($p.Value)"] = $p.Name } } $begin = "$(Get-DataProperty $phase 'PHASE_BEGIN')" $end = "$(Get-DataProperty $phase 'PHASE_END')" $netError = { param($Params) $code = $Params.net_error if ($null -eq $code) { return $null } $name = $errorName["$code"] [pscustomobject]@{ Name = $(if ($name) { $name } else { $null }); Code = [long]$code } } # Every event under its source, in the order written, which is the order things happened. $bySource = @{} foreach ($e in $events) { if ($null -eq $e -or $null -eq $e.source) { continue } $id = "$($e.source.id)" if (-not $bySource.ContainsKey($id)) { $bySource[$id] = New-Object System.Collections.Generic.List[psobject] } $bySource[$id].Add($e) } # The requests, each read once. $requests = New-Object System.Collections.Generic.List[psobject] $typed = $false foreach ($id in $bySource.Keys) { $list = $bySource[$id] if ($sourceName["$($list[0].source.type)"] -ne 'URL_REQUEST') { continue } $r = [ordered]@{ Id = $id; Urls = New-Object System.Collections.Generic.List[string]; Sites = @(); Initiator = $null MainFrame = $false; Status = $null; Redirects = New-Object System.Collections.Generic.List[psobject] Error = $null; Finished = $false; Start = $null; End = $null; Dependencies = New-Object System.Collections.Generic.List[psobject] Challenges = New-Object System.Collections.Generic.List[string]; ProxyAuth = $false; ReadBegin = $null; WaitMs = $null; WaitBegin = $null # Each address the request was sent to in turn - one per redirect - with when it # was sent, when the answer began to arrive and when it was done: what the # waterfall draws at the host of each. Hops = New-Object System.Collections.Generic.List[psobject] } $leg = $null foreach ($e in $list) { $name = $typeName["$($e.type)"] $at = "$($e.phase)" $p = $e.params switch ($name) { 'REQUEST_ALIVE' { if ($at -eq $begin) { $r.Start = [long]$e.time $first = "$($p.url)" if ($first -and -not $r.Urls.Count) { $r.Urls.Add($first) } } elseif ($at -eq $end) { $r.Finished = $true $r.End = [long]$e.time $failed = & $netError $p if ($failed) { $r.Error = $failed } # The request's own error is its last address's: a proxy that # refused the tunnel ends the job quietly and the request with it. if ($leg) { if ($null -eq $leg.End) { $leg.End = [long]$e.time } if ($failed -and -not $leg.Error) { $leg.Error = $failed } } } } 'URL_REQUEST_START_JOB' { if ($at -eq $begin) { $hop = "$($p.url)" if ($hop -and (-not $r.Urls.Count -or $r.Urls[$r.Urls.Count - 1] -ne $hop)) { $r.Urls.Add($hop) } $kind = $p.request_type if ($null -ne $kind) { $typed = $true } if ("$kind" -eq 'main frame') { $r.MainFrame = $true } $key = "$($p.network_isolation_key)".Trim() if ($key) { $r.Sites = @($r.Sites) + @(($key -split '\s+')[0]) } if (-not $r.Initiator) { $r.Initiator = "$($p.initiator)" } $r.Status = $null $sentTo = $hop if (-not $sentTo -and $r.Urls.Count) { $sentTo = $r.Urls[$r.Urls.Count - 1] } $leg = [pscustomobject]@{ Host = (ConvertTo-WebsiteHostName $sentTo); Begin = [long]$e.time; ReadBegin = $null; FirstByte = $null; End = $null; Error = $null } $r.Hops.Add($leg) } elseif ($at -eq $end) { $failed = & $netError $p if ($failed -and -not $r.Error) { $r.Error = $failed } if ($leg -and $null -eq $leg.End) { $leg.End = [long]$e.time; $leg.Error = $failed } } } { $_ -in 'HTTP_TRANSACTION_READ_RESPONSE_HEADERS', 'URL_REQUEST_FAKE_RESPONSE_HEADERS_CREATED' } { $line = "$(@($p.headers)[0])" if ($line -match '^HTTP/\S+\s+(?<code>\d{3})') { $r.Status = [int]$Matches['code'] } if ($r.Status -eq 407) { $r.ProxyAuth = $true } # Waiting for the answer: from the request sent to its head arriving. if ($null -ne $r.ReadBegin) { $r.WaitMs = [long]$e.time - $r.ReadBegin; $r.WaitBegin = $r.ReadBegin; $r.ReadBegin = $null if ($leg -and $null -eq $leg.FirstByte -and $null -ne $leg.ReadBegin) { $leg.FirstByte = [long]$e.time } } # What a 401 asks for: the schemes it offers, first word of each challenge. if ($r.Status -eq 401) { foreach ($header in @($p.headers)) { if ("$header" -match '^(?i)www-authenticate:\s*(?<scheme>[^\s,]+)') { $scheme = $Matches['scheme'] if (-not $r.Challenges.Contains($scheme)) { $r.Challenges.Add($scheme) } } } } } 'HTTP_TRANSACTION_READ_HEADERS' { if ($at -eq $begin) { $r.ReadBegin = [long]$e.time if ($leg -and $null -eq $leg.ReadBegin) { $leg.ReadBegin = [long]$e.time } } } 'URL_REQUEST_REDIRECTED' { $current = $null if ($r.Urls.Count) { $current = $r.Urls[$r.Urls.Count - 1] } $r.Redirects.Add([pscustomobject]@{ Url = $current; Status = $r.Status; Location = "$($p.location)" }) } } $dependency = $p.source_dependency if ($dependency) { $r.Dependencies.Add($dependency) } } if ($r.Urls.Count) { $requests.Add([pscustomobject]$r) } } # The page: the navigation to the address asked for. A document from a browser that # does not say which request is a navigation falls back to the address alone. $wanted = '' $uri = $null if ($Url -and [uri]::TryCreate($Url.Trim(), [UriKind]::Absolute, [ref]$uri)) { $wanted = $uri.AbsoluteUri } $same = { param($Request) $u = $null $wanted -and [uri]::TryCreate($Request.Urls[0], [UriKind]::Absolute, [ref]$u) -and $u.AbsoluteUri -eq $wanted } $ordered = @($requests | Sort-Object { $_.Start }) $main = $null if ($typed) { $navigations = @($ordered | Where-Object { $_.MainFrame }) $main = @($navigations | Where-Object { & $same $_ }) + @($navigations) | Select-Object -First 1 } else { $main = @($ordered | Where-Object { & $same $_ }) | Select-Object -First 1 } if (-not $main) { $record.Problem = 'NoPage' return [pscustomobject]$record } # The page's site under each address it passed through, and its origins for a request # from a browser that writes no isolation key. $sites = @($main.Sites | Where-Object { $_ } | Select-Object -Unique) $origins = @($main.Urls | ForEach-Object { $u = $null if ([uri]::TryCreate($_, [UriKind]::Absolute, [ref]$u)) { $u.GetLeftPart([UriPartial]::Authority) } }) # The key alone is not enough: Edge sends its own services requests under the page's # key while the page is open (its form-filling service, observed 2026-10-14), and # those say they were started by no origin. What the page asked for names the page. $mine = @($ordered | Where-Object { $_ -eq $main -or (@($_.Sites | Where-Object { $sites -contains $_ }).Count -and $_.Initiator -ne 'not an origin') -or (-not @($_.Sites).Count -and $origins -contains $_.Initiator) }) # What happened at each host, walked from the page's requests. A source is walked once # for the whole page: a connection two requests shared is one connection. $hosts = [ordered]@{} $hostOf = { param([string]$Name) if (-not $hosts.Contains($Name)) { $hosts[$Name] = [ordered]@{ Host = $Name; Requests = 0; Unfinished = 0 Failures = New-Object System.Collections.Generic.List[psobject] Addresses = New-Object System.Collections.Generic.List[string] Resolved = $null; ResolveError = $null; Connected = $null; ConnectError = $null RemoteAddress = $null; Tls = $null; TlsError = $null; Certificate = $null DnsMs = $null; ConnectMs = $null; TlsMs = $null # The proxy the host was reached through, as the browser names it; empty # where it was reached directly. Proxy = '' # Each step at the host as the waterfall draws it. See Get-WebsiteHostStep. Steps = @() } } $hosts[$Name] } $layerOf = { param($Type) $n = $sourceName["$Type"] if ($n -and $script:WebsiteSourceLayer.ContainsKey($n)) { return $script:WebsiteSourceLayer[$n] } 99 } $addAddress = { param($Facts, [string]$Address) $a = ($Address -replace ':\d+$', '').Trim('[', ']') if ($a -and -not $Facts.Addresses.Contains($a)) { $Facts.Addresses.Add($a) } } $walked = @{} # What the walk learns of the proxy: how long the page's requests waited for one to be # chosen, which one the page itself was given, and whether a proxy asked for a sign-in. $resolveBegin = @{} # Every attempt at a step - a name lookup, a connection, a handshake - with when it # began and ended, by host and step: Chromium races attempts, and the page went on with # the one that succeeded first. A step begun and never ended waits in $pending. $attempts = @{} $pending = @{} # Which proxy each stream job controller chose, by its source: none (direct), or the # first of the chain, as the browser names it ("proxy.contoso.example:8080"). $chainOf = @{} foreach ($e in $events) { if ($null -eq $e -or $typeName["$($e.type)"] -ne 'HTTP_STREAM_JOB_CONTROLLER_PROXY_SERVER_RESOLVED') { continue } $chain = "$($e.params.proxy_chain)" $isDirect = (-not $chain) -or $chain -match 'direct://' $chainOf["$($e.source.id)"] = [pscustomobject]@{ Direct = $isDirect Proxy = $(if ($isDirect) { '' } else { ($chain.Trim('[', ']', ' ') -split ',')[0].Trim() }) } } $addAttempt = { param([string]$Name, [string]$Step, $Begin, $At, $Failure, [bool]$Cached, [string]$Via) $key = "$Name|$Step" if (-not $attempts.ContainsKey($key)) { $attempts[$key] = New-Object System.Collections.Generic.List[psobject] } $attempts[$key].Add([pscustomobject]@{ Begin = $Begin; End = $At; Error = $Failure; Cached = $Cached; Proxy = $Via }) } $resolveMs = $null $used = $null $proxySignIn = @($mine | Where-Object { $_.ProxyAuth }).Count -gt 0 foreach ($request in $mine) { $queue = New-Object System.Collections.Generic.Queue[psobject] foreach ($d in $request.Dependencies) { $queue.Enqueue([pscustomobject]@{ Id = "$($d.id)"; Type = "$($d.type)"; Host = ''; Direct = $true; Proxy = '' }) } while ($queue.Count) { $item = $queue.Dequeue() if ($walked.ContainsKey($item.Id) -or -not $bySource.ContainsKey($item.Id)) { continue } $mineLayer = & $layerOf $item.Type if ($mineLayer -eq 0 -or $mineLayer -ge 99) { continue } $walked[$item.Id] = $true $context = $item.Host $direct = $item.Direct $via = $item.Proxy $lookup = '' # Whether the lookup under way here was answered from the browser's own cache: # Chromium says so with a cache hit inside it, and a connection that looks a # name up itself says so with a cache hit alone. $fromCache = $false foreach ($e in $bySource[$item.Id]) { $name = $typeName["$($e.type)"] $at = "$($e.phase)" $p = $e.params switch ($name) { 'HTTP_STREAM_JOB' { if ($at -eq $begin) { $context = ConvertTo-WebsiteHostName "$($p.destination)" # Whether it goes through a proxy is its controller's to say. The # walk may reach the job from the request directly, before the # controller, and would take it for a direct one. $controller = "$($p.source_dependency.id)" if ($chainOf.ContainsKey($controller)) { $direct = $chainOf[$controller].Direct; $via = $chainOf[$controller].Proxy } } } 'PROXY_RESOLUTION_SERVICE' { if ($at -eq $begin) { $resolveBegin[$item.Id] = [long]$e.time } elseif ($at -eq $end -and $resolveBegin.ContainsKey($item.Id)) { $ms = [long]$e.time - $resolveBegin[$item.Id] if ($null -eq $resolveMs -or $ms -gt $resolveMs) { $resolveMs = $ms } } } 'PROXY_RESOLUTION_SERVICE_RESOLVED_PROXY_LIST' { if ($request -eq $main -and -not $used) { $used = "$($p.proxy_info)" } } 'HTTP_TRANSACTION_READ_TUNNEL_RESPONSE_HEADERS' { if ("$(@($p.headers)[0])" -match '^HTTP/\S+\s+407\b') { $proxySignIn = $true } } 'HTTP_STREAM_JOB_CONTROLLER_PROXY_SERVER_RESOLVED' { $direct = $chainOf[$item.Id].Direct $via = $chainOf[$item.Id].Proxy } { $_ -in 'HOST_RESOLVER_MANAGER_JOB', 'HOST_RESOLVER_MANAGER_REQUEST' } { if ($at -eq $begin) { $lookup = ConvertTo-WebsiteHostName "$($p.host)" $fromCache = $false if ($context -and $lookup -eq $context) { $pending["$($item.Id)|dns"] = [pscustomobject]@{ Host = $context; Step = 'Dns'; Begin = [long]$e.time; Proxy = '' } } } elseif ($at -eq $end -and $context -and $lookup -eq $context) { $facts = & $hostOf $context $failed = & $netError $p if ($failed) { if ($facts.Resolved -ne $true) { $facts.Resolved = $false; $facts.ResolveError = $failed } } else { $facts.Resolved = $true; $facts.ResolveError = $null } $began = $pending["$($item.Id)|dns"] if ($began) { & $addAttempt $context 'Dns' $began.Begin ([long]$e.time) $failed $fromCache '' $pending.Remove("$($item.Id)|dns") } $fromCache = $false } } 'HOST_RESOLVER_MANAGER_CACHE_HIT' { if ($pending.ContainsKey("$($item.Id)|dns")) { $fromCache = $true } elseif ($context -and $direct) { $null = & $hostOf $context & $addAttempt $context 'Dns' ([long]$e.time) ([long]$e.time) $null $true '' } } 'HOST_RESOLVER_DNS_TASK' { if ($at -eq $end -and $context -and $lookup -eq $context) { $facts = & $hostOf $context foreach ($result in @($p.results)) { foreach ($endpoint in @($result.endpoints)) { & $addAddress $facts "$($endpoint.address)" } } } } 'TCP_CONNECT' { # Through a proxy, the connection is to the proxy: timed for the # waterfall, which says so, and no evidence about the host itself. if ($context -and $at -eq $begin) { $pending["$($item.Id)|tcp"] = [pscustomobject]@{ Host = $context; Step = 'Connect'; Begin = [long]$e.time; Proxy = $via } } elseif ($context -and $at -eq $end) { $began = $pending["$($item.Id)|tcp"] if ($began) { & $addAttempt $context 'Connect' $began.Begin ([long]$e.time) (& $netError $p) $false $via $pending.Remove("$($item.Id)|tcp") } if (-not $direct) { (& $hostOf $context).Proxy = $via } } if ($context -and $direct) { $facts = & $hostOf $context if ($at -eq $begin) { foreach ($a in @($p.address_list)) { & $addAddress $facts "$a" } } elseif ($at -eq $end) { $failed = & $netError $p if ($failed) { if ($facts.Connected -ne $true) { $facts.Connected = $false; $facts.ConnectError = $failed } } else { $facts.Connected = $true; $facts.ConnectError = $null $remote = "$($p.remote_address)" if ($remote -and -not $facts.RemoteAddress) { $facts.RemoteAddress = $remote } # A name the page had cached is not looked up again, and # a connection to it is the proof it resolved. if ($facts.Resolved -ne $true) { $facts.Resolved = $true; $facts.ResolveError = $null } } } } } 'SSL_CERTIFICATES_RECEIVED' { if ($context) { $facts = & $hostOf $context if (-not $facts.Certificate) { $facts.Certificate = ConvertFrom-WebsiteCertificate (@($p.certificates)[0]) } } } 'SSL_CONNECT' { if ($at -eq $begin -and $context) { $pending["$($item.Id)|tls"] = [pscustomobject]@{ Host = $context; Step = 'Tls'; Begin = [long]$e.time; Proxy = $via } } if ($at -eq $end -and $context) { $facts = & $hostOf $context $failed = & $netError $p if ($failed) { if (-not $facts.Tls) { $facts.TlsError = $failed } } else { $version = "$($p.version)" if ($version) { $facts.Tls = $version; $facts.TlsError = $null } } $began = $pending["$($item.Id)|tls"] if ($began -and ($failed -or "$($p.version)")) { & $addAttempt $context 'Tls' $began.Begin ([long]$e.time) $failed $false $via } $pending.Remove("$($item.Id)|tls") } } } $dependency = $p.source_dependency if ($dependency -and (& $layerOf "$($dependency.type)") -gt $mineLayer) { $queue.Enqueue([pscustomobject]@{ Id = "$($dependency.id)"; Type = "$($dependency.type)"; Host = $context; Direct = $direct; Proxy = $via }) } } } } # A step begun and never ended - the browser was stopped while it waited - is an # attempt without an end. foreach ($began in $pending.Values) { & $addAttempt $began.Host $began.Step $began.Begin $null $null $false $began.Proxy } # Where the page's time axis begins: when the browser began on it, which can be before # the navigation's own request - a name it looked up for the address it was handed. # Only the hosts the page asked something of count; a raced attempt elsewhere does not. $asked = @{} foreach ($request in $mine) { foreach ($u in $request.Urls) { $asked[(ConvertTo-WebsiteHostName $u)] = $true } } $origin = [long]$main.Start foreach ($key in $attempts.Keys) { if (-not $asked.ContainsKey(($key -split '\|')[0])) { continue } foreach ($a in $attempts[$key]) { if ($null -ne $a.Begin -and $a.Begin -lt $origin) { $origin = [long]$a.Begin } } } foreach ($request in $mine) { foreach ($hop in $request.Hops) { if ($hop.Begin -lt $origin) { $origin = [long]$hop.Begin } } } # The requests themselves, counted at every host they passed through - a redirect to a # sign-in host is a request to it - and judged at the host they ended at. $record.Requests = @(foreach ($request in $mine) { $last = $request.Urls[$request.Urls.Count - 1] $name = ConvertTo-WebsiteHostName $last foreach ($passed in @($request.Urls | ForEach-Object { ConvertTo-WebsiteHostName $_ } | Select-Object -Unique)) { (& $hostOf $passed).Requests++ } # Each request that ended in an error, with that error, as the net log says it. # Which of them count as failures is the Judge's to say: some are the browser's # own doing. $facts = & $hostOf $name if (-not $request.Finished) { $facts.Unfinished++ } elseif ($request.Error) { $facts.Failures.Add($request.Error) } [pscustomobject]@{ PSTypeName = 'Gutcheck.WebsiteRequest' Url = $last Host = $name Status = $request.Status Error = $request.Error Finished = $request.Finished StartMs = $(if ($null -ne $request.Start) { $request.Start - $origin }) EndMs = $(if ($null -ne $request.End) { $request.End - $origin }) } }) $record.Url = $main.Urls[0] $record.FinalUrl = $main.Urls[$main.Urls.Count - 1] $record.Redirects = @($main.Redirects) $record.Status = $main.Status $record.Finished = $main.Finished $record.Error = $main.Error $record.PageHosts = @($main.Urls | ForEach-Object { ConvertTo-WebsiteHostName $_ } | Select-Object -Unique) $record.SignIn = Get-WebsiteSignIn -Request $main -BySource $bySource -TypeName $typeName -SourceName $sourceName $record.Proxy = Get-WebsiteProxy -Events $events -BySource $bySource -TypeName $typeName -SourceName $sourceName ` -Begin $begin -End $end -Before $main.Start -NetError $netError -Used $used -ResolveMs $resolveMs -SignInAsked $proxySignIn if ($main.Finished -and $null -ne $main.End -and $null -ne $main.Start) { $record.ElapsedMs = $main.End - $main.Start } $hops = @($mine | ForEach-Object { $_.Hops }) $record.Hosts = @(foreach ($name in $hosts.Keys) { # Every host the walk reached, those with no request of their own too (an attempt # the browser raced and dropped): Requests says which. $facts = $hosts[$name] $facts['PSTypeName'] = 'Gutcheck.WebsiteHost' $facts.Failures = @($facts.Failures) $facts.Addresses = @($facts.Addresses) $facts.Steps = @(Get-WebsiteHostStep -Attempts $attempts -Hops @($hops | Where-Object { $_.Host -eq $name }) -HostName $name -Origin $origin) # How long each step took, where it succeeded: the attempt the page went on with. foreach ($pair in @(@('Dns', 'DnsMs'), @('Connect', 'ConnectMs'), @('Tls', 'TlsMs'))) { $step = @($facts.Steps | Where-Object { $_.Step -eq $pair[0] -and $_.State -eq 'Measured' }) | Select-Object -First 1 $facts[$pair[1]] = $(if ($step) { $step.Ms }) } [pscustomobject]$facts }) # The page's own timings: each step at the host it ended at, the wait for its answer, # and the whole load to the last of its requests that finished. The load and the wait # are counted from the page's request; StartMs says where that lies on the page's axis. $finalFacts = $null $finalHost = ConvertTo-WebsiteHostName $record.FinalUrl if ($hosts.Contains($finalHost)) { $finalFacts = $hosts[$finalHost] } $ends = @($mine | Where-Object { $_.Finished -and $null -ne $_.End } | ForEach-Object { $_.End - [long]$main.Start }) $finalDns = $(if ($finalFacts) { @($finalFacts.Steps | Where-Object { $_.Step -eq 'Dns' }) | Select-Object -First 1 }) $record.Timings = [pscustomobject]@{ PSTypeName = 'Gutcheck.WebsiteTimings' StartMs = [long]$main.Start - $origin DnsMs = $(if ($finalFacts) { $finalFacts['DnsMs'] }) DnsCached = [bool]($finalDns -and $finalDns.State -eq 'Cached') ConnectMs = $(if ($finalFacts) { $finalFacts['ConnectMs'] }) TlsMs = $(if ($finalFacts) { $finalFacts['TlsMs'] }) FirstByteStartMs = $(if ($null -ne $main.WaitBegin) { [long]$main.WaitBegin - $origin }) FirstByteMs = $main.WaitMs LoadMs = $(if ($ends.Count) { ($ends | Measure-Object -Maximum).Maximum }) } [pscustomobject]$record } |