analyze-scheduled-task-run-durations

analyze-scheduled-task-run-durations.ps1

<# Analyze normal run duration of scheduled tasks.
 # Gathers insight into how long tasks run, analyzes
 # which tasks run shorter or longer than normal,
 # reports back to console, and writes out its report
 # as a CSV (spreadsheet).
 #
 # The script assumes that the user account running it
 # has access to the computer and is allowed to read its 
 # event log.
 #
 # Author: A.E.Veltstra
 # Version: 2.21.819.1505
 #>

<#
 # Get the host name of the local computer.
 #>
$cs = Get-ComputerInfo;
$h = $cs.CsDNSHostName;

# Event filter for the initial query for all "Start" events in the last 24 hours
$EventFilter = @{
    LogName = 'Microsoft-Windows-TaskScheduler/Operational'
    Id = 100
    StartTime = [datetime]::Now.AddDays(-1)
};

# PropertySelector for the Correlation id (the InstanceId) and task name
[string[]]$PropertyQueries = @(
    'Event/EventData/Data[@Name="InstanceId"]'
    'Event/EventData/Data[@Name="TaskName"]'
);
$PropertySelector = New-Object System.Diagnostics.Eventing.Reader.EventLogPropertySelector @(,$PropertyQueries);

$taskRuns = @();
[int32]$zero = 0;
# Specify which tasks to profile.
$taskNameStartsWith = "\Microsoft";

# Loop through the start events
Write-Output "Retrieving events from host $h...";
$hostEvents = Get-WinEvent -FilterHashtable $EventFilter;
$amount = $hostEvents.Length;
Write-Output "Filtering $amount events retrieved from host $h to include only tasks whose name starts with $taskNameStartsWith...";
$filteredTaskRuns = @();
foreach($event in $hostEvents){
    # Grab the InstanceId and Task Name from the start event
    $InstanceId,$TaskName = $event.GetPropertyValues($PropertySelector);
    if ($TaskName.StartsWith($taskNameStartsWith)) {
        $filteredTaskRuns += $event;
    }
}
$amount = $filteredTaskRuns.Length;
$hostTaskRuns = @();
if ($zero -eq $amount) {
    Write-Output "Found 0 matching task runs on host $h. Skipping.";
} else {
    Write-Output "Found $amount matching task runs on host $h. Retrieving end times...";
    $hostTaskRuns = foreach($taskStart in $filteredTaskRuns){
        # Grab the InstanceId and Task Name from the start event
        $InstanceId,$TaskName = $taskStart.GetPropertyValues($PropertySelector);
        # Retrieve the end time for the event.
        $taskEndTime = $(Get-WinEvent -FilterXPath "*[System[(EventID=102)] and EventData[Data[@Name=""InstanceId""] and Data=""{$InstanceId}""]]" -LogName 'Microsoft-Windows-TaskScheduler/Operational' -ErrorAction SilentlyContinue).TimeCreated;
        # Create custom object with the host, name, start time, and end time.
        [pscustomobject]@{
            Host = $h
            TaskName = $TaskName
            StartTime = $taskStart.TimeCreated
            EndTime = $taskEndTime
        }
    }
}
$taskRuns += $hostTaskRuns;


if ($zero -eq $taskRuns.Length) {
    Write-Output "Found no qualifying tasks. Exiting.";
    exit 0;
}

Write-Output "`r`n`r`nAll tasks gathered. Sorting, grouping, and calculating durations in minutes...";

$sorted = $taskRuns | select Host, TaskName, StartTime, EndTime | sort Host, TaskName, StartTime;
$groups = [ordered]@{};
$name = '';
$lastGroup = '';
foreach($record in $sorted) {
    $name = $record.Host + $record.TaskName;
    if ($name -ne $lastGroup) {
        $lastGroup = $name;
        $groups[$name] = @();
    }
    $groups[$name] += [pscustomobject]@{
        Start = $record.StartTime
        Duration = ($record.EndTime - $record.StartTime).TotalMinutes
    };
}


Write-Output 'Done sorting and grouping. Durations calculated:';
$groups | ft -AutoSize | Write-Output;

Write-Output "`r`n`r`nCalculating outliers...";

# Outliers will be a list of records with named values, so it can be exported as CSV.
$outliers = @();
$lastGroup = '';
$lowerDurationThreshold = 1;

foreach($group in $groups.Keys) {
    Write-Output "Calculating outliers for task $group...";
    $records = $groups[$group];
    
    # calculate the mean
    $n = 0;
    $sumDuration = 0;
    foreach($record in $records) {
        # negative durations indicate that the task hasn't ended yet.
        if ($lowerDurationThreshold -lt $record.Duration) {
            $n += 1;
            $sumDuration += $record.Duration;
        }
    }

    #correct the amount for follow-up divisions
    $n = if ($n -lt 1) { 1 } else { $n };

    $μ = $sumDuration / $n;

    # calculate the standard deviation
    $sumDifference = 0;
    foreach($record in $records) {
        # negative durations indicate that the task hasn't ended yet.
        if ($lowerDurationThreshold -lt $record.Duration) {
            $diff = [math]::Pow([math]::Abs($record.Duration - $μ), 2);
            $sumDifference += $diff;
        }
    }
    $α = [math]::Sqrt($sumDifference / $n);

    # outliers: all records whose duration is further from μ than 2 α.
    foreach($record in $records) {
        # negative durations indicate that the task hasn't ended yet.
        if ($lowerDurationThreshold -lt $record.Duration) {
            $isOutlier = [math]::Abs($record.Duration - $μ) -gt (2*$α);
            if ($isOutlier) {
                $outliers += [pscustomobject]@{
                    Task = $group
                    Start = $record.Start
                    Duration = [math]::Round($record.Duration, 2)
                    Mean = [math]::Round($μ, 2)
                    StandardDeviation = [math]::Round($α, 2)
                    DoubleDeviation = [math]::Round(2*$α, 2)
                };
            }
        }
    }

}

$amount = $outliers.Length;
if ($zero -eq $amount) {
    Write-Output "`r`n`r`nNo outliers found. Exiting.";
    Exit 0;
}

Write-Output "`r`n`r`nOutliers:";
$outliers | ft -AutoSize | Write-Output;

$now = Get-Date -DisplayHint DateTime -UFormat %Y%m%dT%H%S;
$outputPath = "\\storage\path\outliers-$now.csv";
Write-Output "`r`n`r`nCreating CSV: '$outputPath'...";
$outliers | ForEach-Object {
    $_ | Select Task, Start, Duration, Mean, StandardDeviation, DoubleDeviation | Export-CSV -Path $outputPath -NoTypeInformation -NoClobber -Append;
};

A multi-threaded version is available, too: https://gist.github.com/aev-mambro2/287e4588a4537f368e1f4c44b83764c4