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;
};

Update: Made the output sorted as well. Required changing the gathering hashtable into an ordered dictionary.

This calculates the average run duration of specific scheduled tasks on remote Windows servers in the last time period, then reports any task run that took too much or too little time, as a spreadsheet.

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