Edit: I have changed the title of this question from "PowerShell: Why is this timing not working?" I originally thought the times reported had to be wrong, but I was wrong about that. The times reported were correct, and what I learned from the discussion of the question was why the times were so different. So the new title better describes what can be learned from this Q&A.
I'm writing a script to compare the contents of two folders, including a binary comparison if the size and timestamp are the same. I want to monitor how quickly it does the comparisons. But my results of that are way out of whack.
Here is an excerpt of my code that just tests the monitoring of the speed of comparison.
$sFolder_1 = "<path of folder 1, including final \>"
$sFolder_2 = "<path of folder 2, including final \>"
get-ChildItem -path $sFolder_1 -Recurse | ForEach-Object `
{$oItem_1 = $_
$sItem_1 = $oItem_1.FullName
$sItem_rel = $sItem_1.Substring($nLen_1)
$sItem_2 = join-path $sFolder_2 $sItem_rel
if(Test-Path -Type Container $sItem_1) {$sFile = ""} else {$sFile = "F"}
# Check for corresponding item in folder 2:
if (-not (Test-Path $sItem_2)) `
{$sResult = "Not in 2"}
else
# If it's a file, compare in both folders:
{if ($sFile -eq "") `
{$sResult = "Found"}
else
{$nSize_1 = $oItem_1.Length
$dTimeStart = $(get-date)
$nKb = ($nSize_1 / 1024)
Write-Output "$dTimeStart : Checking file ($nKb kb)"
if (Compare-Object (Get-Content $sItem_1) (Get-Content $sItem_2)) `
{$sResult = "Dif content"}
else
{$sResult = "Same"}
$nTimeElapsed = ($(get-date) - $dTimeStart).Ticks / 1e7
$nSpeed = $nKb / $nTimeElapsed
Write-Output "$nKb kb in $nTimeElapsed seconds, speed $nSpeed kb/sec."
} }
Write-Output $sResult
}
Here is the output from running that on a particular pair of folders. The four files in the two folders are all "gvi" files, which is a type of video file.
08/05/2023 08:58:41 : Checking file (75402.453125 kb)
75402.453125 kb in 37.389018 seconds, speed 2016.70054894194 kb/sec.
Same
08/05/2023 08:59:18 : Checking file (67386.28515625 kb)
67386.28515625 kb in 22.6866484 seconds, speed 2970.30588071573 kb/sec.
Same
08/05/2023 08:59:41 : Checking file (165559.28125 kb)
165559.28125 kb in 5.6360258 seconds, speed 29375.1815774158 kb/sec.
Same
08/05/2023 08:59:47 : Checking file (57776.244140625 kb)
57776.244140625 kb in 2.059942 seconds, speed 28047.5101437929 kb/sec.
Same
This says that the comparison ran ten times faster on the third and fourth files than on the first two. That doesn't make sense. I'm guessing that there's something about the way PowerShell is optimizing the process that is causing the difference. Is there a way to find out the actual time spend doing each comparison?