[NoBrainer] Start-Sleep takes longer that it seems

While doing some tests with our new TraceListener and log server I did some tests where I wanted to find out how long the log server would take to start accepting messages.

So I started to constantly send messages from the console:

1..1000 | % { $traceSource.TraceInformation($_);
Start-Sleep -Milliseconds 1;

When I looked at the server logs I noticed that the arriving messages came in unusually slow. So I started measuring the time on the client:

PS > Measure-Command { 1..1000 | %  { Start-Sleep -Milliseconds 1; } }

Ticks             : 157088640
TotalMilliseconds : 15708.864

Ok, the overhead of the Start-Sleep cmdlet (or the % loop?) was taking at least 10 times more than the actual sleep time.

However, when using the native .NET equivalent, things started looking much better:

PS > Measure-Command { 1..1000 | %  { [System.Threading.Thread]::Sleep(1); } }

Ticks             : 10452903
TotalMilliseconds : 1045.2903

So sometimes it really makes sense to fall back to native .NET methods…