Gutcheck

0.16.0

Private/Kinds/Logon.ps1

                                # The Logon Kind: where the time goes between signing in and a desktop that is ready.

#

# "It takes forever until I can work" is told to a Technician in one sentence, and Windows

# keeps what it would take to answer it in three logs, none of which needs admin rights:

#

#   Microsoft-Windows-Winlogon/Operational

#     2           authentication ended, with a result: 0 is accepted

#     811, 812    a notification subscriber began, and finished, handling an event. The

#                 subscribers are the parts of Windows a sign-in waits for, one after the

#                 other: Profiles loads the User Profile, GPClient applies Group Policy,

#                 SessionEnv, TermSrv and Sens set the session up. Payload: the number of

#                 the event, and the subscriber's name. The sign-in is event 2: observed

#                 to the millisecond beside the User Profile Service's "logon notification

#                 received".

#   Microsoft-Windows-Shell-Core/Operational

#     62170, 62171  a logon task of the shell began, and finished: AllLogonTasks spans

#                   them all. Logged by the Explorer of the account that signed in.

#     9707, 9708    a command of a Run key was started, and finished. Windows starts the

#                   programs of the Run keys one after the other: seen on the machine

#                   this was written on, twelve of them thirty seconds apart, the last

#                   six minutes after the sign-in. What the thirty seconds are, Microsoft

#                   does not say, and the Report says what was measured.

#   Microsoft-Windows-User Profile Service/Operational

#     5             the registry of an account is loaded, under its SID: whose sign-in it is

#

# Verified against the event manifests: docs/research/logon-events.md.

#

# A sign-in is put together from them: the subscribers of event 2 in one Winlogon

# process, the shell's tasks that began next, by the Explorer of one account, and that

# Explorer's Run keys. What the Report shows of the commands is the name of the program,

# which is an autostart entry and state (ADR-0006); of the sign-ins of other accounts it

# shows when, and how long to the desktop, and no programs.

#

# What the Gatherer returns:

#   Days, Since, UnreadableLogs, ScannedLogs, LogCoverage   as the NetworkDisruption Kind

#   SignIns   newest first, each

#             { Time, Account, Own, NotifyMs, Subscribers = { Name, Ms }, ShellSeen,

#               ShellStartMs, ShellTasksMs, DesktopMs, Tasks = { Name, StartMs, Ms },

#               Commands = { Name, StartMs, Ms }, AutostartLastStartMs }

#             Times in milliseconds from the sign-in; $null where a log does not say.

#             Tasks, Commands and AutostartLastStartMs only of the User's own sign-ins.

#

# Not in any log a Run without admin rights can read, and so not a phase here: how long

# the sign-in waited for the network, and how long logon scripts ran. Both are in the

# Group Policy log, which is the GroupPolicy Kind's.

$script:LogonDefaultDays = 30

$script:LogonWinlogonLog = 'Microsoft-Windows-Winlogon/Operational'

$script:LogonShellLog    = 'Microsoft-Windows-Shell-Core/Operational'

$script:LogonProfileLog  = 'Microsoft-Windows-User Profile Service/Operational'

# The number Winlogon gives the sign-in among the events it notifies its subscribers of.

$script:LogonSignInEvent = '2'

# How long after a sign-in its shell may begin and still be that sign-in's, and how long

# after the shell its Run keys may be gone through: Windows holds the programs of the Run

# keys back, and the last of many starts minutes later.

$script:LogonShellWithinSeconds     = 300

$script:LogonAutostartWithinSeconds = 1800

function Get-LogonProgramName {

    <#

    .SYNOPSIS

        The program a command of a Run key starts, by its file name. Pure.

    .DESCRIPTION

        A command is a path with arguments, and the arguments are nobody's to read: a

        file a program is told to open is content (ADR-0006). The name of the program is

        the autostart entry: the first file the command names. Where that is rundll32,

        the library it loads is the program. Where it is another interpreter - cmd,

        PowerShell, the script hosts - the interpreter is all that is named: what it is

        handed may be a document on somebody's desktop.

    #>

    [CmdletBinding()]

    [OutputType([string])]

    param([AllowNull()][AllowEmptyString()][string]$Command)

    $text = "$Command".Trim()

    if (-not $text) { return '' }

    $files = @([regex]::Matches($text, '(?i)([^\\/"\s,]+\.(?:exe|dll|cmd|bat|vbs|ps1|lnk|com|msc))') | ForEach-Object { $_.Groups[1].Value })

    if (-not $files.Count) { return '' }

    if ("$($files[0])" -match '^(?i)rundll32\.exe$') {

        $library = @($files | Where-Object { $_ -match '(?i)\.dll$' })[0]

        if ($library) { return "$library" }

    }

    "$($files[0])"

}

function ConvertTo-LogonPair {

    <#

    .SYNOPSIS

        Events that begin something and events that finish it, as what was begun with how

        long it took. Pure.

    .DESCRIPTION

        Paired by a key the caller reads out of each: a "finished" with the "begun" of

        the same key that came last before it. A "begun" that nothing finished comes back

        too, with no end and no length: a task that hangs is the one somebody asks about.

        What finished without having begun in what was read is left out.

        In the order of time, then of the record's number, then of the id: two events of

        one millisecond are otherwise in whatever order they were handed over, and a

        "finished" ahead of its "begun" pairs everything after it wrongly. The id of a

        "begun" is the lower one in every pair this Kind reads.

    #>

    [CmdletBinding()]

    [OutputType([psobject])]

    param(

        [AllowNull()][AllowEmptyCollection()]$LogEntry,

        [Parameter(Mandatory)][int[]]$BeginId,

        [Parameter(Mandatory)][int[]]$EndId,

        [Parameter(Mandatory)][scriptblock]$Key

    )

    $open = [ordered]@{}

    foreach ($entry in @($LogEntry | Where-Object { $_ } | Sort-Object TimeCreated, RecordId, Id)) {

        $name = "$(& $Key $entry)"

        if (-not $name) { continue }

        if ($BeginId -contains [int]$entry.Id) {

            # What began again without having finished is given back as it stands.

            if ($open.Contains($name)) { [pscustomobject]@{ Name = $name; Start = [datetime]$open[$name]; End = $null; Ms = $null } }

            $open[$name] = $entry.TimeCreated

        }

        elseif ($EndId -contains [int]$entry.Id -and $open.Contains($name)) {

            [pscustomobject]@{

                Name  = $name

                Start = [datetime]$open[$name]

                End   = [datetime]$entry.TimeCreated

                Ms    = [double]([datetime]$entry.TimeCreated - [datetime]$open[$name]).TotalMilliseconds

            }

            $open.Remove($name)

        }

    }

    foreach ($name in @($open.Keys)) { [pscustomobject]@{ Name = "$name"; Start = [datetime]$open[$name]; End = $null; Ms = $null } }

}

function Get-LogonOffset {

    <#

    .SYNOPSIS

        How long after a sign-in something happened, in whole milliseconds. Pure.

    #>

    [CmdletBinding()]

    [OutputType([double])]

    param([datetime]$From, [AllowNull()]$At)

    if ($null -eq $At) { return $null }

    [math]::Round(([datetime]$At - $From).TotalMilliseconds)

}

function ConvertTo-LogonSignIn {

    <#

    .SYNOPSIS

        The sign-ins that the events of Winlogon, of the User Profile Service and of the

        shell amount to. Pure.

    .DESCRIPTION

        A sign-in is where the subscriber Profiles begins to handle the sign-in event in

        a Winlogon process. It is counted from the authentication that was accepted in

        that process within the five seconds before, where there was one. Its subscribers

        are those of the sign-in event in that process from then on, for no longer than

        ten minutes and not beyond the next sign-in of that process.

        Whose it is, the User Profile Service says: while Profiles works, it loads the

        registry of the account, and logs under which SID. The shell of the sign-in is

        the Explorer of that account whose logon tasks begin next. Where the account is

        not known - the service's log does not reach back - the shell is the next one

        that begins before any other sign-in does: on a terminal server two people sign

        in within a minute, and a shell taken from the wrong one is somebody else's

        sign-in under this one's name.

        Account is the SID; the Gatherer puts the name there.

    #>

    [CmdletBinding()]

    [OutputType([psobject])]

    param(

        [AllowNull()][AllowEmptyCollection()]$Winlogon,

        [AllowNull()][AllowEmptyCollection()]$Shell,

        [AllowNull()][AllowEmptyCollection()]$UserProfile

    )

    $notify   = @($Winlogon | Where-Object { $_ -and [int]$_.Id -in 811, 812 } | Sort-Object TimeCreated, RecordId, Id)

    $accepted = @($Winlogon | Where-Object { $_ -and [int]$_.Id -eq 2 -and "$(Get-EventPayload -LogEntry $_ -Index 0)" -eq '0' } | Sort-Object TimeCreated)

    $shellLog = @($Shell | Where-Object { $_ } | Sort-Object TimeCreated, RecordId, Id)

    # The registry of an account being loaded: its SID, without what marks its classes.

    $loaded   = @($UserProfile | Where-Object { $_ -and [int]$_.Id -eq 5 } | Sort-Object TimeCreated | ForEach-Object {

        $sid = "$(Get-EventPayload -LogEntry $_ -Index 1)" -replace '(?i)_Classes$', ''

        if ($sid -match '^S-\d-\d+(-\d+)+$') { [pscustomobject]@{ Time = [datetime]$_.TimeCreated; Sid = $sid } }

    })

    $starts = @($notify | Where-Object {

        [int]$_.Id -eq 811 -and "$(Get-EventPayload -LogEntry $_ -Index 0)" -eq $script:LogonSignInEvent -and

        "$(Get-EventPayload -LogEntry $_ -Index 1)" -eq 'Profiles' })

    # The shells that began, each by the Explorer that logged it.

    $shells = [System.Collections.Generic.List[psobject]]::new()

    foreach ($entry in @($shellLog | Where-Object { [int]$_.Id -eq 62170 -and "$(Get-EventPayload -LogEntry $_ -Index 1)" -eq 'AllLogonTasks' })) { $shells.Add($entry) }

    $index = -1

    foreach ($start in $starts) {

        $index++

        $process  = "$($start.ProcessId)"

        $began    = [datetime]$start.TimeCreated

        $later    = @($starts | Select-Object -Skip ($index + 1))

        $nextOwn  = @($later | Where-Object { "$($_.ProcessId)" -eq $process })[0]

        $nextAny  = $later[0]

        $time = $began

        $auth = @($accepted | Where-Object { "$($_.ProcessId)" -eq $process -and $_.TimeCreated -le $began -and ($began - [datetime]$_.TimeCreated).TotalSeconds -le 5 })[-1]

        if ($auth) { $time = [datetime]$auth.TimeCreated }

        $until = $time.AddMinutes(10)

        if ($nextOwn -and [datetime]$nextOwn.TimeCreated -lt $until) { $until = [datetime]$nextOwn.TimeCreated }

        # From the authentication on, or two seconds before Profiles: SessionEnv is

        # notified ahead of it.

        $from = $began.AddSeconds(-2)

        if ($auth) { $from = $time }

        $handled = @($notify | Where-Object {

            "$($_.ProcessId)" -eq $process -and $_.TimeCreated -ge $from -and $_.TimeCreated -lt $until -and

            "$(Get-EventPayload -LogEntry $_ -Index 0)" -eq $script:LogonSignInEvent })

        $pairs = @(ConvertTo-LogonPair -LogEntry $handled -BeginId 811 -EndId 812 -Key { param($e) Get-EventPayload -LogEntry $e -Index 1 } |

            Where-Object { $null -ne $_.Ms })

        # A subscriber is notified more than once: what it took is all of it.

        $subscribers = @($pairs | Group-Object Name | ForEach-Object {

            [pscustomobject]@{ Name = "$($_.Name)"; Ms = [math]::Round(($_.Group | Measure-Object Ms -Sum).Sum); Start = ($_.Group | Sort-Object Start)[0].Start }

        } | Sort-Object Start | ForEach-Object { [pscustomobject]@{ Name = $_.Name; Ms = $_.Ms } })

        $notifyMs = $null

        if ($pairs.Count) { $notifyMs = Get-LogonOffset -From $time -At ($pairs | Sort-Object End)[-1].End }

        # Whose it is: the registry loaded while Profiles worked.

        $profilesDone = @($pairs | Where-Object { $_.Name -eq 'Profiles' } | Sort-Object End)[-1]

        $loadedUntil  = $began.AddSeconds(60)

        if ($profilesDone) { $loadedUntil = $profilesDone.End.AddSeconds(1) }

        $account = "$(@($loaded | Where-Object { $_.Time -ge $began.AddSeconds(-1) -and $_.Time -le $loadedUntil })[0].Sid)"

        # The shell: that account's, or the next one before anybody else signs in.

        $shellUntil = $time.AddSeconds($script:LogonShellWithinSeconds)

        $candidates = @($shells | Where-Object { $_.TimeCreated -ge $time -and $_.TimeCreated -le $shellUntil })

        $explorer = $null

        if ($account) { $explorer = @($candidates | Where-Object { "$($_.UserId)" -eq $account })[0] }

        else {

            $explorer = @($candidates | Where-Object { -not $nextAny -or $_.TimeCreated -lt $nextAny.TimeCreated })[0]

            if ($explorer) { $account = "$($explorer.UserId)" }

        }

        $shellStartMs = $null; $shellTasksMs = $null; $desktopMs = $null

        $tasks = @(); $commands = @()

        $lastStartMs = $null

        if ($explorer) {

            $null   = $shells.Remove($explorer)

            $limit  = ([datetime]$explorer.TimeCreated).AddSeconds($script:LogonAutostartWithinSeconds)

            $theirs = @($shellLog | Where-Object { "$($_.ProcessId)" -eq "$($explorer.ProcessId)" -and $_.TimeCreated -ge $explorer.TimeCreated -and $_.TimeCreated -le $limit })

            $shellStartMs = Get-LogonOffset -From $time -At $explorer.TimeCreated

            $taskPairs = @(ConvertTo-LogonPair -LogEntry @($theirs | Where-Object { [int]$_.Id -in 62170, 62171 }) -BeginId 62170 -EndId 62171 `

                -Key { param($e) Get-EventPayload -LogEntry $e -Index 1 })

            $whole = @($taskPairs | Where-Object { $_.Name -eq 'AllLogonTasks' -and $null -ne $_.Ms })[0]

            if ($whole) {

                $shellTasksMs = [math]::Round($whole.Ms)

                $desktopMs    = Get-LogonOffset -From $time -At $whole.End

            }

            $tasks = @($taskPairs | Where-Object { $_.Name -ne 'AllLogonTasks' } | Sort-Object Start | ForEach-Object {

                [pscustomobject]@{ Name = $_.Name; StartMs = (Get-LogonOffset -From $time -At $_.Start); Ms = $(if ($null -ne $_.Ms) { [math]::Round($_.Ms) }) } })

            # Every command that was started, also one that never "finished": the last

            # of them is when the last program came.

            $commandPairs = @(ConvertTo-LogonPair -LogEntry @($theirs | Where-Object { [int]$_.Id -in 9707, 9708 }) -BeginId 9707 -EndId 9708 -Key {

                param($e)

                if ([int]$e.Id -eq 9707) { Get-EventPayload -LogEntry $e -Index 0 } else { Get-EventPayload -LogEntry $e -Index 1 } })

            $commands = @($commandPairs | Sort-Object Start | ForEach-Object {

                [pscustomobject]@{ Name = (Get-LogonProgramName -Command $_.Name); StartMs = (Get-LogonOffset -From $time -At $_.Start); Ms = $(if ($null -ne $_.Ms) { [math]::Round($_.Ms) }) }

            } | Where-Object { $_.Name })

            if ($commands.Count) { $lastStartMs = ($commands | Sort-Object StartMs)[-1].StartMs }

        }

        [pscustomobject]@{

            Time         = $time

            Account      = $account

            Own          = $false

            NotifyMs     = $notifyMs

            Subscribers  = $subscribers

            # Whether the shell's log holds this sign-in at all: where it does and the

            # shell's tasks never finished, how long it took is not known, and not short.

            ShellSeen    = [bool]$explorer

            ShellStartMs = $shellStartMs

            ShellTasksMs = $shellTasksMs

            DesktopMs    = $desktopMs

            Tasks        = $tasks

            Commands     = $commands

            AutostartLastStartMs = $lastStartMs

        }

    }

}

function Set-LogonOwner {

    <#

    .SYNOPSIS

        Marks the sign-ins of the User, and takes from the others what is not this Run's

        to keep: which tasks and programs started for somebody else, and when the last

        of them did. Pure.

    #>

    [CmdletBinding()]

    [OutputType([psobject])]

    param([AllowNull()][AllowEmptyCollection()]$SignIn, [AllowNull()][AllowEmptyString()][string]$User)

    foreach ($one in @($SignIn | Where-Object { $_ })) {

        $one.Own = [bool]("$User".Trim() -and "$($one.Account)" -eq "$User".Trim())

        if (-not $one.Own) {

            $one.Tasks = @()

            $one.Commands = @()

            $one.AutostartLastStartMs = $null

        }

        $one

    }

}

function Get-LogonData {

    <#

    .SYNOPSIS

        Reads the sign-ins of the period out of the logs of Winlogon, of the User Profile

        Service and of the shell. Judges none of them.

    .DESCRIPTION

        Whose sign-ins are the User's is what the Run handed over as 'RunUser': the

        account at the machine, or the one the Run runs as where nobody is. Not worked

        out here a second time.

        Of the sign-ins of other accounts only when, whose, and how long to the desktop

        are kept: which tasks and programs start for somebody else, and how many, is not

        this Run's to gather (ADR-0006).

    .PARAMETER Observed

        What the Run knows before this Check: 'RunUser'. See ConvertTo-RunUserObserved.

    #>

    [CmdletBinding()]

    [OutputType([psobject])]

    param([hashtable]$Parameters = @{}, [AllowNull()][hashtable]$Observed = @{})

    $days  = [int](Get-Parameter $Parameters 'Days' $script:LogonDefaultDays)

    $since = (Get-Date).AddDays(-$days)

    $unreadable   = @{}

    $scanned      = @()

    $read         = @{}

    $registration = Get-NetworkDisruptionRegistration

    foreach ($wanted in @(

            @{ Log = $script:LogonWinlogonLog; Id = @(2, 811, 812) }

            @{ Log = $script:LogonProfileLog;  Id = @(5) }

            @{ Log = $script:LogonShellLog;    Id = @(62170, 62171, 9707, 9708) })) {

        $read[$wanted.Log] = @()

        if ($registration -and -not $registration.Log.Contains($wanted.Log)) { continue }

        $scanned += $wanted.Log

        $read[$wanted.Log] = @(Get-StabilityEvent -Log $wanted.Log -Id $wanted.Id -Since $since -Unreadable $unreadable)

    }

    $runUser = $null

    if ($Observed -and $Observed.ContainsKey('RunUser')) { $runUser = $Observed['RunUser'] }

    $user = "$(Get-DataProperty $runUser 'LoggedOnUser')".Trim()

    if (-not $user) { $user = "$(Get-DataProperty $runUser 'RunningAs')".Trim() }

    if (-not $user) { try { $user = "$([System.Security.Principal.WindowsIdentity]::GetCurrent().Name)" } catch { } }

    $signIns = @(ConvertTo-LogonSignIn -Winlogon $read[$script:LogonWinlogonLog] -Shell $read[$script:LogonShellLog] `

        -UserProfile $read[$script:LogonProfileLog] | Sort-Object Time -Descending)

    foreach ($signIn in $signIns) {

        $sid = "$($signIn.Account)"

        if (-not $sid) { continue }

        $named = Resolve-AccountName -Sid $sid

        if ($named.Name) { $signIn.Account = $named.Name }

    }

    $signIns = @(Set-LogonOwner -SignIn $signIns -User $user)

    $coverage = @(foreach ($log in $scanned) {

        if ($unreadable.ContainsKey($log)) { continue }

        [pscustomobject]@{ Log = $log; Oldest = Get-NetworkDisruptionLogOldest -Log $log }

    })

    [pscustomobject]@{

        PSTypeName     = 'Gutcheck.Data.Logon'

        Days           = $days

        Since          = $since

        SignIns        = $signIns

        UnreadableLogs = @($unreadable.Keys | Sort-Object)

        ScannedLogs    = [string[]]@($scanned)

        LogCoverage    = $coverage

    }

}

function Format-LogonSeconds {

    <#

    .SYNOPSIS

        A length of time as the Report shows it: "0,7 s" below ten seconds, whole seconds

        up to two minutes, minutes and seconds from there. Empty for none. Pure.

    #>

    [CmdletBinding()]

    [OutputType([string])]

    param([AllowNull()]$Milliseconds)

    $number = ConvertTo-Number $Milliseconds

    if ($null -eq $number) { return '' }

    if ($number -lt 0) { $number = 0 }

    $seconds = [double]$number / 1000

    if ($seconds -lt 10)  { return (Get-Text 'Value.Logon.SecondsTenth' $seconds) }

    if ($seconds -lt 120) { return (Get-Text 'Value.Logon.Seconds' ([int][math]::Round($seconds))) }

    $whole = [int][math]::Round($seconds)

    Get-Text 'Value.Logon.Minutes' ([int][math]::Floor($whole / 60)) ($whole % 60)

}

function Get-LogonSubscriberText {

    <#

    .SYNOPSIS

        What the Report calls a part of Windows a sign-in waits for. One this has no word

        for is shown under its own name: that is what Windows calls it. Pure.

    #>

    [CmdletBinding()]

    [OutputType([string])]

    param([AllowNull()][AllowEmptyString()][string]$Name)

    switch ("$Name") {

        'Profiles'   { return (Get-Text 'Value.Logon.Subscriber.Profiles') }

        'GPClient'   { return (Get-Text 'Value.Logon.Subscriber.GPClient') }

        'SessionEnv' { return (Get-Text 'Value.Logon.Subscriber.SessionEnv') }

        'TermSrv'    { return (Get-Text 'Value.Logon.Subscriber.TermSrv') }

        'Sens'       { return (Get-Text 'Value.Logon.Subscriber.Sens') }

    }

    "$Name"

}

function Get-LogonPhase {

    <#

    .SYNOPSIS

        A sign-in as the phases a Finding names: loading the profile, Group Policy, the

        other parts of Windows, getting to the shell, and the shell's own tasks. Pure.

    .DESCRIPTION

        Each with what it took, in milliseconds, and in the order they happen. A phase a

        log said nothing of is left out. "Shell" is the time from the last part of

        Windows to the shell beginning its tasks: Explorer being started.

    #>

    [CmdletBinding()]

    [OutputType([psobject])]

    param([AllowNull()]$SignIn)

    $subscribers = @((Get-DataCollection $SignIn 'Subscribers') | ForEach-Object { $_ })

    $profileMs = 0; $policyMs = 0; $otherMs = 0

    foreach ($subscriber in $subscribers) {

        $took = [double](ConvertTo-Number (Get-DataProperty $subscriber 'Ms'))

        switch ("$(Get-DataProperty $subscriber 'Name')") {

            'Profiles' { $profileMs += $took }

            'GPClient' { $policyMs += $took }

            default    { $otherMs += $took }

        }

    }

    if ($subscribers.Count) {

        [pscustomobject]@{ Phase = 'Profile'; Ms = [int]$profileMs }

        [pscustomobject]@{ Phase = 'Policy';  Ms = [int]$policyMs }

        [pscustomobject]@{ Phase = 'Other';   Ms = [int]$otherMs }

    }

    $notify = ConvertTo-Number (Get-DataProperty $SignIn 'NotifyMs')

    $shell  = ConvertTo-Number (Get-DataProperty $SignIn 'ShellStartMs')

    if ($null -ne $shell) {

        $from = 0

        if ($null -ne $notify) { $from = [double]$notify }

        [pscustomobject]@{ Phase = 'Shell'; Ms = [int][math]::Max(0, [double]$shell - $from) }

    }

    $tasks = ConvertTo-Number (Get-DataProperty $SignIn 'ShellTasksMs')

    if ($null -ne $tasks) { [pscustomobject]@{ Phase = 'Tasks'; Ms = [int]$tasks } }

}

function Get-LogonPhaseText {

    <#

    .SYNOPSIS

        What the Report calls a phase, and what to do where it is the slow one. Pure.

    #>

    [CmdletBinding()]

    [OutputType([string])]

    param([AllowNull()][AllowEmptyString()][string]$Phase, [Parameter(Mandatory)][ValidateSet('Name', 'Hint')][string]$Part)

    switch ("$Phase|$Part") {

        'Profile|Name' { return (Get-Text 'Value.Logon.Phase.Profile') }

        'Profile|Hint' { return (Get-Text 'Hint.Logon.Phase.Profile') }

        'Policy|Name'  { return (Get-Text 'Value.Logon.Phase.Policy') }

        'Policy|Hint'  { return (Get-Text 'Hint.Logon.Phase.Policy') }

        'Other|Name'   { return (Get-Text 'Value.Logon.Phase.Other') }

        'Other|Hint'   { return (Get-Text 'Hint.Logon.Phase.Other') }

        'Shell|Name'   { return (Get-Text 'Value.Logon.Phase.Shell') }

        'Shell|Hint'   { return (Get-Text 'Hint.Logon.Phase.Shell') }

        'Tasks|Name'   { return (Get-Text 'Value.Logon.Phase.Tasks') }

        'Tasks|Hint'   { return (Get-Text 'Hint.Logon.Phase.Tasks') }

    }

    "$Phase"

}

function Get-LogonDesktopMs {

    <#

    .SYNOPSIS

        How long a sign-in took to the desktop: to the shell having done its tasks. Where

        the shell's log does not hold the sign-in at all, to the last part of Windows.

        $null where neither is known - and where the shell began and its tasks never

        finished: that sign-in hung, and is not one that took two seconds. Pure.

    #>

    [CmdletBinding()]

    [OutputType([double])]

    param([AllowNull()]$SignIn)

    $desktop = ConvertTo-Number (Get-DataProperty $SignIn 'DesktopMs')

    if ($null -ne $desktop) { return [double]$desktop }

    if ([bool](Get-DataProperty $SignIn 'ShellSeen') -or $null -ne (ConvertTo-Number (Get-DataProperty $SignIn 'ShellStartMs'))) { return $null }

    $notify = ConvertTo-Number (Get-DataProperty $SignIn 'NotifyMs')

    if ($null -ne $notify) { return [double]$notify }

    $null

}

function New-LogonDesktopFinding {

    <#

    .SYNOPSIS

        How long the User's sign-ins take to the desktop, and where the time of the last

        one went.

    .DESCRIPTION

        Graded on the middle one of the last sign-ins: one slow sign-in after an update

        is no state. Never a FAIL unless a Check Definition says so.

    #>

    [CmdletBinding()]

    param([AllowNull()]$Data, [hashtable]$Parameters, [AllowNull()][AllowEmptyCollection()]$SignIn)

    $check = Get-Text 'Check.Logon.Desktop'

    $timed = @($SignIn | Where-Object { $null -ne (Get-LogonDesktopMs -SignIn $_) })

    if (-not $timed.Count) {

        # The shell began its tasks and never logged them done: how long the sign-in

        # took is not known, and that is not the same as nothing to report.

        $newest = @($SignIn | Where-Object { $_ })[0]

        if (-not $newest) { return }

        return New-Finding -Category Startup -Check $check -Severity WARN `

            -Value ((Get-Text 'Value.Logon.NeverFinished') -f (ConvertTo-DataTime (Get-DataProperty $newest 'Time'))) `

            -Meaning (Get-Text 'Meaning.Logon.NeverFinished') -Hint (Get-Text 'Hint.Logon.NeverFinished') `

            -Reference @(New-Reference -Section 'Title.Logon.Steps')

    }

    $warn = [double](Get-Parameter $Parameters 'DesktopWarnSeconds' 60)

    $fail = [double](Get-Parameter $Parameters 'DesktopFailSeconds' ([double]::MaxValue))

    $last  = $timed[0]

    $took  = @($timed | Select-Object -First 5 | ForEach-Object { Get-LogonDesktopMs -SignIn $_ } | Sort-Object)

    $typical = $took[[int][math]::Floor(($took.Count - 1) / 2)]

    $phases = @(Get-LogonPhase -SignIn $last)

    $value  = @((Get-Text 'Value.Logon.Desktop') -f (Format-LogonSeconds (Get-LogonDesktopMs -SignIn $last)), (ConvertTo-DataTime (Get-DataProperty $last 'Time')))

    if ($timed.Count -gt 1) { $value += (Get-Text 'Value.Logon.Typical') -f (Format-LogonSeconds $typical), $took.Count }

    if (@($phases | Where-Object { $_.Ms -ge 100 }).Count) {

        # A phase that took no time worth naming is left out of the sentence; the table has it.

        $value += (Get-Text 'Value.Logon.Phases') -f (@($phases | Where-Object { $_.Ms -ge 100 } | ForEach-Object {

            '{0} {1}' -f (Get-LogonPhaseText -Phase $_.Phase -Part Name), (Format-LogonSeconds $_.Ms) }) -join '; ')

    }

    $severity = Get-Severity ($typical / 1000) $warn $fail

    $table    = @((New-Reference -Section 'Title.Logon.SignIns'), (New-Reference -Section 'Title.Logon.Steps'))

    if ($severity -eq 'OK') { return New-Finding -Category Startup -Check $check -Severity OK -Value ($value -join ' | ') -Reference $table }

    # What to do is about the phase that took longest.

    $slowest = @($phases | Sort-Object Ms -Descending)[0]

    $meaning = Get-Text 'Meaning.Logon.Desktop'

    $hint    = @()

    if ($slowest) {

        $meaning = '{0} | {1}' -f $meaning, ((Get-Text 'Meaning.Logon.Slowest') -f (Get-LogonPhaseText -Phase $slowest.Phase -Part Name), (Format-LogonSeconds $slowest.Ms))

        $hint   += Get-LogonPhaseText -Phase $slowest.Phase -Part Hint

    }

    $hint += Get-Text 'Hint.Logon.Desktop'

    New-Finding -Category Startup -Check $check -Severity $severity -Value ($value -join ' | ') `

        -Meaning $meaning -Hint ($hint -join ' | ') -Reference $table

}

function New-LogonAutostartFinding {

    <#

    .SYNOPSIS

        When the last of the programs of the Run keys was started after the User's last

        sign-in. Nothing where the shell's log holds none.

    .DESCRIPTION

        Windows starts them one after the other and gives each up to thirty seconds, so

        the tenth is there five minutes after the desktop - and "Teams is not there when

        I sign in" is that, and no fault of Teams.

    #>

    [CmdletBinding()]

    param([hashtable]$Parameters, [AllowNull()]$SignIn)

    $commands = @((Get-DataCollection $SignIn 'Commands') | ForEach-Object { $_ })

    $lastStart = ConvertTo-Number (Get-DataProperty $SignIn 'AutostartLastStartMs')

    if (-not $commands.Count -or $null -eq $lastStart) { return }

    $warn = [double](Get-Parameter $Parameters 'AutostartWarnSeconds' 180)

    $severity = Get-Severity ([double]$lastStart / 1000) $warn ([double]::MaxValue)

    if ($severity -eq 'OK') { $severity = 'INFO' }

    $late = @($commands | Sort-Object { [double](ConvertTo-Number (Get-DataProperty $_ 'StartMs')) } -Descending | Select-Object -First 3 | ForEach-Object {

        (Get-Text 'Value.Logon.CommandAfter') -f "$(Get-DataProperty $_ 'Name')", (Format-LogonSeconds (Get-DataProperty $_ 'StartMs')) })

    New-Finding -Category Startup -Check (Get-Text 'Check.Logon.Autostart') -Severity $severity `

        -Value (@(

            ((Get-Text 'Value.Logon.Autostart') -f $commands.Count, (Format-LogonSeconds $lastStart))

            ((Get-Text 'Value.Logon.AutostartLate') -f ($late -join '; '))) -join ' | ') `

        -Meaning (Get-Text 'Meaning.Logon.Autostart') -Hint (Get-Text 'Hint.Logon.Autostart') `

        -Reference @(New-Reference -Section 'Title.Logon.Steps')

}

function ConvertTo-LogonFinding {

    [CmdletBinding()]

    [OutputType([psobject])]

    param([AllowNull()]$Data, [hashtable]$Parameters = @{})

    $signIns = @((Get-DataCollection $Data 'SignIns') | ForEach-Object { $_ })

    $own     = @($signIns | Where-Object { [bool](Get-DataProperty $_ 'Own') })

    if (-not $own.Count) {

        $check = Get-Text 'Check.Logon.Desktop'

        $unreadable = @((Get-DataCollection $Data 'UnreadableLogs') | ForEach-Object { $_ })

        if ($unreadable.Count) {

            New-Finding -Category Startup -Check $check -Severity INFO `

                -Value ((Get-Text 'Value.NetworkDisruption.NotAssessable') -f ($unreadable -join ', ')) `

                -Meaning (Get-Text 'Meaning.Logon.Unreadable') -Hint (Get-Text 'Hint.Logon.Unreadable')

        }

        else {

            # No sign-in of this account in what the logs hold: a machine that is not

            # restarted for weeks has one sign-in, and the log may have let it go.

            New-Finding -Category Startup -Check $check -Severity INFO `

                -Value ((Get-Text 'Value.Logon.None') -f (Get-NetworkDisruptionDays -Data $Data)) `

                -Meaning (Get-Text 'Meaning.Logon.None') -Hint (Get-Text 'Hint.Logon.None')

        }

    }

    else {

        New-LogonDesktopFinding -Data $Data -Parameters $Parameters -SignIn $own

        New-LogonAutostartFinding -Parameters $Parameters -SignIn $own[0]

    }

    New-UnreadableLogFinding -Data $Data -Parameters $Parameters

}

function ConvertTo-LogonSection {

    [CmdletBinding()]

    [OutputType([psobject])]

    param([AllowNull()]$Data)

    $signIns = @((Get-DataCollection $Data 'SignIns') | ForEach-Object { $_ })

    $time = Get-Text 'Column.NetworkDisruption.Time'

    New-Section -Title (Get-Text 'Title.Logon.SignIns') -Help (Get-Text 'Help.Logon.SignIns') -Row @(

        $signIns | Select-Object -First 50 | ForEach-Object {

            $phases = @{}

            foreach ($phase in @(Get-LogonPhase -SignIn $_)) { $phases[$phase.Phase] = $phase.Ms }

            $row = [ordered]@{}

            $row[$time] = Get-DataProperty $_ 'Time'

            $row[(Get-Text 'Column.RemoteDesktop.Account')] = "$(Get-DataProperty $_ 'Account')"

            $row[(Get-Text 'Column.Logon.Desktop')]  = Format-LogonSeconds (Get-LogonDesktopMs -SignIn $_)

            foreach ($phase in 'Profile', 'Policy', 'Other', 'Shell', 'Tasks') {

                $row[(Get-LogonPhaseText -Phase $phase -Part Name)] = $(if ($phases.ContainsKey($phase)) { Format-LogonSeconds $phases[$phase] } else { '' })

            }

            $row[(Get-Text 'Column.Logon.LastAutostart')] = Format-LogonSeconds (Get-DataProperty $_ 'AutostartLastStartMs')

            [pscustomobject]$row

        }

    )

    # The last sign-in of the User, step by step.

    $last = @($signIns | Where-Object { [bool](Get-DataProperty $_ 'Own') })[0]

    if (-not $last) { return }

    # Named apart from the parameters of the block below: a variable's name is the same

    # in any case, and "$kind" would be the block's "$Kind".

    $stepColumn  = Get-Text 'Column.Logon.Step'

    $kindColumn  = Get-Text 'Column.NetworkDisruption.Kind'

    $afterColumn = Get-Text 'Column.Logon.After'

    $tookColumn  = Get-Text 'Column.Logon.Took'

    $line  = {

        param([string]$Name, [string]$What, $StartMs, $Ms)

        $row = [ordered]@{}

        $row[$stepColumn]  = $Name

        $row[$kindColumn]  = $What

        $row[$afterColumn] = Format-LogonSeconds $StartMs

        $row[$tookColumn]  = Format-LogonSeconds $Ms

        [pscustomobject]$row

    }

    New-Section -Title (Get-Text 'Title.Logon.Steps') -Help (Get-Text 'Help.Logon.Steps') -Row @(

        foreach ($subscriber in (Get-DataCollection $last 'Subscribers')) {

            & $line (Get-LogonSubscriberText -Name "$(Get-DataProperty $subscriber 'Name')") (Get-Text 'Value.Logon.Step.Windows') $null (Get-DataProperty $subscriber 'Ms')

        }

        # The shell's tasks that took a moment: there are fifty, and most take none.

        foreach ($task in @((Get-DataCollection $last 'Tasks') | Where-Object { [double](ConvertTo-Number (Get-DataProperty $_ 'Ms')) -ge 200 })) {

            & $line "$(Get-DataProperty $task 'Name')" (Get-Text 'Value.Logon.Step.Shell') (Get-DataProperty $task 'StartMs') (Get-DataProperty $task 'Ms')

        }

        foreach ($command in (Get-DataCollection $last 'Commands')) {

            & $line "$(Get-DataProperty $command 'Name')" (Get-Text 'Value.Logon.Step.Autostart') (Get-DataProperty $command 'StartMs') (Get-DataProperty $command 'Ms')

        }

    )

}