Tuesday, November 11, 2014

Of Powershell, Pester, DSC and...

It's been since 2009 that I am using Powershell as my favourite administration tool and I must admit it has never evolved as fast as this year. A full bunch of new products and of interesting concepts are born and growing fast both in the language itself and in its surroudings, making it one of the key competence to have in the Windows IT world nowadays.
 
Beside this, Microsoft is pushing its Windows development as fast as it can, and the release of Windows 10 (and of its Server version), with its ton of new cmdlets, is a clear sign of the fact that people in Redmond are doing their best to build on the success of Powershell.
 
On top of this, the community is strongly focusing on making Powershell (which is a tool built for sysadmins and aimed at system administration) take advantage of well established software development processes like Test-Driven Development (TDD). The star on stage here is named Pester, a project started by Scott Muc a few years back, which is a Unit-Testing solution for your Powershell code.
 
Last but not least, by now you should have heard of Desired State Configuration, which, starting with Windows 2012 R2 and Powershell 4.0, is a configuration management solution aimed at preventing configuration drift in your environment. In a few words, DSC provides a set of PowerShell language extensions, in the form of new Windows PowerShell cmdlets, that you can use to declaratively specify how you want your environment to be configured. Talking of DSC with your colleagues, you will hear a lot about the concept of idempotency, which, to make it simple, is the way DSC ensures that the environment desired state will be reached by applying the entire configuration, regardless of the current state.
 
I am currently having fun testing all of this, and, let me tell you, if you are new to Powershell, it's time to get a grasp on it before it is too late.

To stimulate your curiosity, heres' some screenshots from my current labs.

Here you can see that in Windows 10 the Start button is back:


Same for the Server version:


Both come with Powershell 5.0, the ultimate version:


Installing Pester on Windows 10 is now a breeze, thanks to the Package Manager I have already talked of in a previous blog post. Just run

Find-Package Pester
to check which version is available (version 3.1.1 at the time of testing), then:

Install-Package Pester
and you'll get it installed.

Here's a screenshot of the full installation process:


The Pester module will appear in you Module folder:


These are the cmdlets it comes with (I'll come back on them in a future post):

Get-Command -Module Pester

CommandType     Name                                               Version    Source
-----------     ----                                               -------    ------
Function        AfterEach                                          3.1.1      Pester
Function        Assert-MockCalled                                  3.1.1      Pester
Function        Assert-VerifiableMocks                             3.1.1      Pester
Function        BeforeEach                                         3.1.1      Pester
Function        Context                                            3.1.1      Pester
Function        Describe                                           3.1.1      Pester
Function        Get-MockDynamicParameters                          3.1.1      Pester
Function        Get-TestDriveItem                                  3.1.1      Pester
Function        In                                                 3.1.1      Pester
Function        InModuleScope                                      3.1.1      Pester
Function        Invoke-Mock                                        3.1.1      Pester
Function        Invoke-Pester                                      3.1.1      Pester
Function        It                                                 3.1.1      Pester
Function        Mock                                               3.1.1      Pester
Function        New-Fixture                                        3.1.1      Pester
Function        Set-DynamicParameterVariables                      3.1.1      Pester
Function        Setup                                              3.1.1      Pester
Function        Should                                             3.1.1      Pester

So now, there are a lot of new things to learn out there. It's time for you to start having a look at all of this and that's why I am giving you a short list of recent and interesting blog posts to start from.
Stay tuned for more on Powershell!

Monday, November 10, 2014

How to use Powershell to setup a GPO for Script Execution Policy and for WinRM

Last week, during the deployment of a new Active Directory Domain, I was challenged by a colleague of mine to write a Powershell  function that performs  the two following jobs on all the computers in the new Domain:
  • set the script Execution Policy to RemoteSigned
  • enable Powershell Remoting for remote management
To be honest I never thought it had any real use to modify my Default Domain Policy to apply the above settings using Powershell instead of the GUI, since this is a kind of job you do once and for all in your Domain and Powershell brings no added value, unless.... unless you can re-use the same function for all your labs requiring a new Domain. So I accepted the challenge.
 
The function I came up with is the result of a lot of try and guess. I studied the existing policies on others Domain I have and came to the conclusion that the operations my function had to perform were be aimed at modifying a few registry keys, as well as to modify GptTmpl.inf, which is a INF file that keeps the security setting for a given GPO.
 
Let's see this in detail.
 
To change the Execution Policy for scripts, you have to play with the  HKLM\Software\Policies\Microsoft\Windows\Powershell key, and
  • set the value of ExecutionPolicy to RemoteSigned
  • set the value of EnableScripts to 1
Setting up Powershell Remoting configuration is a bit trickier, since you have to work on two fronts. First of all you must go under the HKLM\Software\Policies\Microsoft\Windows\WinRM\Service key and
  • set AllowAutoConfig to 1
  • set IPv4Filter and the IPv6Filter setting to * (or whatever settings is good for you)
Then you have also to set the WinRM service to start automatically, by adding it to the GptTmpl.inf file of your GPO. In my case I applied all this settings to my 'Default Domain policy' but of course you can create a dedicated GPO for this. It's up to you how to tackle the subject in your Domain.

Here's the complete function I wrote:
#Requires –Modules ActiveDirectory

function Set-PowershellDomainPolicy()
    {
    $domain = (Get-ADDomain).forest
    $id = (Get-GPO -name 'Default Domain Policy').id
    $ExecutionPolicyParams = @{
            name='Default Domain Policy';
      key='HKLM\Software\Policies\Microsoft\Windows\PowerShell';
            }
    try {
        Set-GPRegistryValue @ExecutionPolicyParams -ValueName ExecutionPolicy -Value RemoteSigned -Type String -ErrorAction Stop
        Set-GPRegistryValue @ExecutionPolicyParams -ValueName EnableScripts -Value 1 -Type DWord -ErrorAction Stop
        "Script execution policy changed succesfully!"
        }
    catch { "Error changing script execution policy" }

    $RemotingParams = @{
            Name='Default Domain Policy';
            Key = 'HKLM\Software\Policies\Microsoft\Windows\WinRM\Service';
            }
    
    try {
        Set-GPRegistryValue @RemotingParams -ValueName 'AllowAutoConfig' -Value 1 -Type DWord
        Set-GPRegistryValue @RemotingParams -ValueName 'IPv4Filter' -Value '*' -Type String
        Set-GPRegistryValue @RemotingParams -ValueName 'IPv6Filter' -Value '*' -Type String
        "Registry setting for Powershell Remoting OK!"
        }
    catch { "Error enabling remoting policy" }

     #Setting up the here-string
    $inf = @'
[Service General Setting]
"WinRM",2,""
'@

    try {
        $inf |
            Out-File "C:\Windows\SYSVOL\sysvol\$domain\Policies\{$id}\MACHINE\Microsoft\Windows NT\SecEdit\GptTmpl.inf" -Append -ErrorAction Stop
        "WinRM startup set to Automatic in GptTmpl.inf!"
        }
    catch { "Error setting WinRM automatic startup"}
    }

Set-PowershellDomainPolicy
Which you can run by executing:
Set-PowershellDomainPolicy
As you can see, the central cmdlet of my function is Set-GPRegistryValue, which, If I remember well, exists from Powershell 4.0. This cmdlet takes as parameter the GUID of the GPO, which I retrieve using Get-GPO.
 
The Policy runs in a few seconds and its ouput is shown below:
DisplayName      : Default Domain Policy
DomainName       : contoso.com
Owner            : CONTOSO\Domain Admins
Id               : 31b2f340-016d-11d2-945f-00c04fb984f9
GpoStatus        : AllSettingsEnabled
Description      : 
CreationTime     : 05/11/2014 08:18:48
ModificationTime : 10/11/2014 15:44:48
UserVersion      : AD Version: 0, SysVol Version: 0
ComputerVersion  : AD Version: 25, SysVol Version: 25
WmiFilter        : 

DisplayName      : Default Domain Policy
DomainName       : contoso.com
Owner            : CONTOSO\Domain Admins
Id               : 31b2f340-016d-11d2-945f-00c04fb984f9
GpoStatus        : AllSettingsEnabled
Description      : 
CreationTime     : 05/11/2014 08:18:48
ModificationTime : 10/11/2014 15:44:48
UserVersion      : AD Version: 0, SysVol Version: 0
ComputerVersion  : AD Version: 26, SysVol Version: 26
WmiFilter        : 

Script execution policy changed succesfully!

DisplayName      : Default Domain Policy
DomainName       : contoso.com
Owner            : CONTOSO\Domain Admins
Id               : 31b2f340-016d-11d2-945f-00c04fb984f9
GpoStatus        : AllSettingsEnabled
Description      : 
CreationTime     : 05/11/2014 08:18:48
ModificationTime : 10/11/2014 15:44:48
UserVersion      : AD Version: 0, SysVol Version: 0
ComputerVersion  : AD Version: 27, SysVol Version: 27
WmiFilter        : 

DisplayName      : Default Domain Policy
DomainName       : contoso.com
Owner            : CONTOSO\Domain Admins
Id               : 31b2f340-016d-11d2-945f-00c04fb984f9
GpoStatus        : AllSettingsEnabled
Description      : 
CreationTime     : 05/11/2014 08:18:48
ModificationTime : 10/11/2014 15:44:48
UserVersion      : AD Version: 0, SysVol Version: 0
ComputerVersion  : AD Version: 28, SysVol Version: 28
WmiFilter        : 

DisplayName      : Default Domain Policy
DomainName       : contoso.com
Owner            : CONTOSO\Domain Admins
Id               : 31b2f340-016d-11d2-945f-00c04fb984f9
GpoStatus        : AllSettingsEnabled
Description      : 
CreationTime     : 05/11/2014 08:18:48
ModificationTime : 10/11/2014 15:44:48
UserVersion      : AD Version: 0, SysVol Version: 0
ComputerVersion  : AD Version: 29, SysVol Version: 29
WmiFilter        : 

Registry setting for Powershell Remoting OK!
WinRM startup set to Automatic in GptTmpl.inf!
If you want you can manually check that the settings are applied by checking the content of the INF file:
 
 
And for the other settings, check you Group Policy Management GUI:
 
 
Don't forget to run this function on a Domain Controller or on any member server having RSAT.
 
On your clients you must wait for 90 minutes (with a random offset of 0 to 30 minutes) for the GPO to re-apply, or just logoff and logon again.
 
As a side information, this GPO worked well against my new beta Windows 10 clients!
 
If you have any question, feel free to ask and .... please share!

Thursday, November 6, 2014

How to use Sysprep to generalize Windows Server 2012 R2 Running in a VM

Yesterday I was asked by an IT guy if the use of newsid.exe against a cloned Windows 2012 R2 virtual machine would work to prevent SID conflict. Well, what he didn't know, is that newsid is old history now (even the download is no more available) and that a new wonderful switch in the Sysprep utility is born to make the job of generalizing your master VM become a breeze. Let me quickly explain that.

The new switch for Sysprep is /mode:VM

This switch is available only through the command-line and causes Sysprep to skip the physical device recognition phase. This way deploying a clone of any VM becomes very rapid, since detecting changes in the installed hardware was time-consuming.

Here's the complete Sysprep syntax to use. Open an elevated command prompt, move to c:\windows\system32\sysprep, then run:

sysprep.exe /oobe /generalize /shutdown /mode:vm

and you are done. The master virtual machine will shut down and you can keep it as base host from which to deploy any other VM. Each time you start a new clone you'll be asked about your regional settings and input language, and you'll need to enter your activation key again.

Hope this helps.

Sunday, November 2, 2014

Generating a runner pace-band with Powershell

Powershell is about added value. Powershell is built upon .NET. And Powershell is flexible. Three statements. Once you know those, you know that you can cross the borders of what Powershell was meant for, invent something new, and still get great results.

I am a runner. Some days ago I have been running an half-marathon, and, during preparation, I found myself in the need of a wrist pace-band showing split times for each km, in order to evite erratic running speeds.


Of course there are pace-band generators on the web, like the one at RunnersWorld, but I took the decision that I wanted to make one myself with my preferred tool: Powershell.

There are several obstacles to reaching the desired result. I'll walk trough the required steps and we will together build a Powershell function named Get-Pace.

The Powershell function need of course to take in some parameters. The first three parameters are just used for customising your pace-band, so they'll be of type System.String.
  • RunnerName
  • RaceName
  • RaceDate
Then there are the parameters used for actual split pace calculation:
  • Distance as System.Decimal
  • Time as System.TimeSpan
  • Unit as System.String
  • Open as System.Management.Automation.SwitchParameter
We will be casting the values for these variables into the required types by using some well known accelerators.

In Powershell, to cast a Decimal you can use:

[decimal]$Distance = 42.195
or

[decimal]$Distance = '42.195'
They both will convert the passed string to a decimal.

Now we want to tell Powershell that we want to set the expected duration of the race as a TimeSpan.
 
When casting a TimeSpan, Powershell expects you to pass the string in the one of the following formats:

[timespan]$Time = '1:3:4'
will set a TimeSpan of 1 hours, 3 minutes and 4 seconds;

[timespan]$Time = '1:3'
will set a TimeSpan of 1 minutes and 3 seconds;

[timespan]$Time = '3'
will set a TimeSpan of three days;

[timespan]$Time = '3:1:2:3'
will set a TimeSpan of 3 days, 1 hours, 2 minutes and 3 seconds;

When setting a TimeSpan, always remember to enclose the string into quotes, otherwise the interpreter won't be able to do the required conversion and throw the following error:

+ [timespan]$Time = 1:3:4
+                   ~~~~~
    + CategoryInfo          : ObjectNotFound: (1:3:4:String) [], CommandNotFoundException
    + FullyQualifiedErrorId : CommandNotFoundException

The unit must accept only one of two possible value: miles or kilometers. To do so, best option is to use ValidateSet for parameter validation:

[ValidateSet('km', 'mile')][string]$Unit = 'km'
Powerful, isn't it? Parameter validation should be one of your closest allies when working on a Powershell function, remember.
 
Now there is an unfortunate problem when generating a pace-band. One of historical kind. Let me explain that. Most runners need a pace-band when running a marathon. A marathon has a weird distance. More than two milleniums ago, Pheidippides ran from the city of Marathon to Athens for roughly 40 km or 25 miles. When in 1908 the Olympics were held in London, the race was extended to 26.2 miles, or 42.195 km, so the runners could cross the finish line in front of the royal family's viewing box.
 
This brings us to the fact that while a race like a 10k has an exact number of split, races like marathon or half-marathon have a last split of shorter length. And we need to take this in consideration in our script.
 
To determine if a race has only full splits, first we need to round its distance to the closest smaller integer. Two correct ways to do that:

$FullSplits = [decimal]::Floor($Distance)
or

$FullSplits = [System.Math]::Floor($distance)
Then to get the last incomplete split length, just use:

$LastIncompleteSplit = $Distance - $FullSplits
After having determined the number of split, next step is to calculate the number of seconds per split: 
$TimeSpanPerSplit = New-TimeSpan -seconds ($Time.TotalSeconds/$Distance)
and convert it to speed using a simple formula you all know:

$Speed = 60/$TimespanPerSplit.TotalMinutes
Now, since Powershell is object-based, we proceed to the set-up of the array that will contain split information to print on the pace-band.

For each split we are going to show the three basic information each runner needs:
  1. Split number
  2. Target split time
  3. Cumulative time
Since we are printing the data on the wrist band as a string, we can take advange of the -f operator to format data in a readable way while running.

Let's see that:

# Creating an empty array for storing full splits
$Splits = @()
 
# Populating the array with split and cumulate time association
1..$FullSplits | % {
    $CumulateTime = $TimespanPerSplit.TotalSeconds * $_
    $CumulateTimeSpan = New-TimeSpan -Seconds $CumulateTime
    $Splits += "{0:D2} {1} {2:D2}h{3:D2}'{4:D2}''" -f $_,$Unit,$CumulateTimeSpan.Hours,$CumulateTimeSpan.Minutes,$CumulateTimeSpan.Seconds
    }
Notice the use of :D2 to tell -f to pad hours, minutes and seconds with a zero in case they have one digit only, so that 0h25'7'' will appear as 00h25'07''. Useful.

In case there is an additional incomplete split, like in a half marathon where the last split is 97.5 meters long, we repeat the step once more, so to complete the array. Thanks to the if(){} condition, this step will be skipped for races like a 10k or a 20k, because $FullSpits and $Distance will have equal value.

if($Distance -gt $FullSplits)
    {
    $CumulateTimeFinal = $TimespanPerSplit.TotalSeconds * $Distance
    $CumulateTimeFinalSpan = New-TimeSpan -Seconds $CumulateTimeFinal
    $Splits += "{0:N2} {1} {2:D2}h{3:D2}'{4:D2}''" -f $LastIncompleteSplit,$Unit,$CumulateTimeFinalSpan.Hours,$CumulateTimeFinalSpan.Minutes,$CumulateTimeFinalSpan.Seconds
    }
In the next part of the Get-Pace function we are going to generate one text header showing the average target pace:

$Header1 = "{0}'{1}''/{2}" -f $TimespanPerSplit.Minutes,$TimespanPerSplit.Seconds,$Unit
... and one with the average speed: in kmh if we specified 'km' as measure unit, in mph if we chose 'miles'. Notice here the use of Switch(){} statement, which replaces the use of multiple sequential if(){} conditions.

Switch ($Unit)
    {
    "km" {$suffix = 'kmh'}
    "mile" {$suffix = 'mph'}
    }
$Header2 = "$([System.Math]::Round($Speed,2))$suffix"
We continue setting up a side text containing the name and the date of the race:
$SideText = $RaceName + ' ' + $RaceDate
Then we for sure need a footer to encourage the runner to stick to the target pace. Here it comes:
$Footer = "Go $RunnerName!!!"
That was the easy part of the function.

Today we want to push our Powershell a little farther and see if we are capable of outputting the $Array object as well as $Header1, $Header2, $SideText and $Footer to a printable image.

First step is to load the assembly:
Add-Type -AssemblyName System.Drawing
The second step is to set the path and name of the image file:
$FileName = "$home\pace-band.Png"
The third step is to set the image height and width, trying to get something printable. This is very empiric, since the the resulting image size in centimeters will depend upon your DPI.... but this is another story and out of scope here, so take these values as granted but modify them if they don't work for you:
$PngHeight = 20 * 38
$PngWidth = 5 * 38
$Png = New-Object System.Drawing.Bitmap $PngWidth,$PngHeight
Now let's choose the font type and size for our wrist-band:
$FontSmall = New-Object System.Drawing.Font Consolas,8
$FontBig = New-Object System.Drawing.Font Consolas,14
$FontSideText = New-Object System.Drawing.Font Consolas,14
Next is to choose both foreground and background colors:
$BrushBgColor = [System.Drawing.Brushes]::LightYellow
$BrushFgColor = [System.Drawing.Brushes]::DarkBlue
Time to setup the background image:
# Creating a graphic from the image and putting some colors
$Graphics = [System.Drawing.Graphics]::FromImage($Png)
$Graphics.FillRectangle($BrushBgColor,0,0,$Png.Width,$Png.Height)
Once you are here, you have to print on the pace-band each split as a single line and move down on the paper. I did the math, so they could be wrong, but normally this worked well on my screen:
# Adding one line to the pace-band for each split
0..$FullSplits | % {
    $splitlength = $Graphics.MeasureString($Splits[$_],$FontSmall)
    $Graphics.DrawString($Splits[$_],$FontSmall,$BrushFgColor,($PngWidth-$splitlength.Width)/2,$PngHeight / ($Distance) + ($splitlength.Height*$_) + 75) 
    }
Let's now add the two headers as well as the footer text. Notice the use of MeasureString to measure string length, in order to center text on the pace-band with the help of the following formula: (width of the image - string length) / 2. Notice also how I assigned the DirectionVertical flag to my side text, so that it appears vertically centered. Resulting code is here:
# Measuring headers, sidetext and footer in order to center them on pace-band
$Header1Length = $Graphics.MeasureString($Header1,$FontBig)
$Header2Length = $Graphics.MeasureString($Header2,$FontBig)
$FooterLength = $Graphics.MeasureString($Footer.ToUpper(),$FontBig)
$SideTextLength = $Graphics.MeasureString($SideText,$FontSideText)

# Writing headers, footer and sidetext
$Graphics.DrawString($Header1,$FontBig,$BrushFgColor,($PngWidth-$Header1Length.Width)/2,25)
$Graphics.DrawString($Header2,$FontBig,$BrushFgColor,($PngWidth-$Header2Length.Width)/2,50) 
$Graphics.DrawString($Footer.ToUpper(),$FontBig,$BrushFgColor,($PngWidth-$FooterLength.Width)/2,($SplitLength.Height * $Distance) + 125)
$DrawFormat = New-Object System.Drawing.StringFormat("DirectionVertical");
$Graphics.DrawString($SideText.ToUpper(),$FontSideText,$BrushFgColor,$PngWidth-($SideTextLength.Height*1.5),($PngHeight-$SideTextLength.Width)/2,$DrawFormat)
Last two steps, dispose the object that consume memory, such as fonts and graphics (this is robust programming, guys!) and save:
$Graphics.Dispose()
$Png.Save($FileName)
You could now call the function with the following parameters:
Get-Pace -RunnerName Carlo -RaceName "Marathon" -RaceDate "01/XI/2014" -Distance "42.195" -Time "2:59:0" -Unit "km" -Open
and get a printable image like this:

Print it, cut it, cover both front and back with sticky tape, place the band on your wrist and then tape the top edge over the bottom tab.

Of course you could improve this function by adding parameters like the destination file, or the colors to use for your pace-band. I leave that to you on purpose, so you can increase your Powershell skills, but feel free to ask questions as soon as they arise. Enjoy and share!

Wednesday, October 22, 2014

Reading large text files with Powershell

Any sysadmin out there knows that log files are an invaluable asset for troubleshooting issues on their servers. Sometimes though these kind of files can be very large and become difficult to handle, as I had the occasion to notice in a Powershell forum discussion one week ago.

The thing to understand is that the right tool to use in Powershell is determined from the kind of file you are dealing with.

Here's the bunch of options you have for reading text files:

  • Get-Content
  • Get-Content -Raw
  • Get-Content -ReadCount
  • Switch -File
  • [System.IO.File]::ReadAllText()
  • [System.IO.File]::ReadAllLines()
  • [System.IO.File]::ReadLines()
  • [System.IO.File]::OpenText().readtoend()
 
Get-Content is your out-of-the-box option. It works well with small log files and its use is pretty straightforward, but on large log files it can be very slow.

Get-Content .\small.csv

Let's suppose we have four logfiles of different size and number of lines:

- logfile0.log, a small logfile: 4 lines and 1KB size
- logfile1.log, a medium size logfile: 700K lines and 160MB size
- logfile2.log, a large size logfile: 300K lines and 1.2GB size
- logfile3.log, a logfile containing more than a million of lines: 1.4M lines and 650MB size

Let's see what Get-Content can do against these files:

(Measure-Command {Get-Content .\logfile0.log}).TotalSeconds
0,0013753

(Measure-Command {Get-Content .\logfile1.log}).TotalSeconds
12,7561849

(Measure-Command {Get-Content .\logfile2.log}).TotalSeconds
11,9634649

(Measure-Command {Get-Content .\logfile3.log}).TotalSeconds
229,0962224

Pretty swift on the smaller ones, but way too slow on that last large file, which, with its over one million lines becomes difficult to deal with.

Let's see than how the other methods I listed above perform against it. Doing some performance testing is not only fun, but it helps better understanding how your systems work.

As we just saw, with its basic syntax Get-Content performs poorly:

(Measure-Command {Get-Content .\logfile3.log}).TotalSeconds
229,0962224

Since Powershell v3, Get-Content has a -Raw parameter, which makes it to read text files in a text stream, keeping newline character intact. As you can see below, it is way faster than Get-Content:

(Measure-Command {Get-Content .\logfile3.log -Raw}).TotalSeconds
46,4201292

Nonetheless it a huge impact on your memory use:



Happily enough we can dispose data in memory by forcing the Garbage Collector to do its job before continuing our tests:

[GC]::Collect()



Let's move on to the third option: the -ReadCount parameter. As it was showed in the mentioned forum discussion, this switch can speed Get-Content beyond what one could expect, given that you find the right value for it:

(Measure-Command {Get-Content .\logfile3.log -ReadCount 10}).TotalSeconds
33,9024254

(Measure-Command {Get-Content .\logfile3.log -ReadCount 100}).TotalSeconds
11,1052492

(Measure-Command {Get-Content .\logfile3.log -ReadCount 1000}).TotalSeconds
7,9866107

(Measure-Command {Get-Content .\logfile3.log -ReadCount 10000}).TotalSeconds
10,4790464

This -ReadCount switch helps speeding up the process by controlling the number of records Get-Content writes into the pipeline at a time. From my experience, reading the file by chunks of 1000 or 10000 lines usually gives the best results and has low to no impact on CPU and memory even for such a large logfile.

The problem with -ReadCount is that it takes a bit of guessing to find out the right value for a specific file, since performance varies not only with the size of the file but also with the size of each record.

An interesting alternative to Get-Content, which you should know, is the use of the Switch keyword:

(Measure-Command {Switch -File .\logfile3.log {default {$PSItem}}}).TotalSeconds
10,0711553

Not so bad, isn't it? Let's remark that the impact on CPU usage of Switch is slightly higher than Get-Content -ReadCount:



Let's see now if we can have better results by crossing the unwelcoming bridge to .NET.

First option is the ReadAllText() method:

(Measure-Command {[System.IO.File]::ReadAllText('C:\temp\get-content\logfile3.log')}).TotalSeconds
13,5002564

ReadAllText() is very fast but has a temporary impact on system memory.

Second option is ReadAllLines():

(Measure-Command {[System.IO.File]::ReadAllLines('C:\temp\get-content\logfile3.log')}).TotalSeconds
16,3589887

Not as good as ReadAllText(), but it has a slightly less aggressive impact on memory allocation:



Third option is ReadLine(), which differs from ReadAllLines() in the fact that it allows you to start enumerating the collection of strings before the whole collection is returned:

(Measure-Command {[System.IO.File]::ReadLines('C:\temp\get-content\logfile3.log')}).TotalSeconds
6,5551735

Impressive result here.

Let's move to the fourth and last option which is OpenText().readtoend():

(Measure-Command {[System.IO.File]::OpenText('C:\temp\get-content\logfile3.log').readtoend()}).TotalSeconds
10,8803161

Great performance, but, same as for the two other .NET methods, a lot of RAM has to be allocated since they read the entire file into memory and your code could in some cases throw an exception of type System.OutOfMemoryException. Also, you have noticed it, when using .NET, the file path must be fully specified or Powershell won't be able to find it.

In conclusion, seeking through the file with Get-Content -ReadCount seems to be the seconds fastest way to go through a large text file. First option with large files is [System.IO.File]::ReadLines():

  1. [System.IO.File]::ReadLines(): 6 seconds
  2. Get-Content -ReadCount 1000: 7 seconds
  3. Switch -File: 10 seconds
  4. [System.IO.File]::OpenText().readtoend(): 10 seconds
  5. [System.IO.File]::ReadAllText(): 13 seconds
  6. [System.IO.File]::ReadAllLines(): 16 seconds
  7. Get-Content -Raw: 46 seconds
  8. Get-Content: 229 seconds
If you liked this post, please share, or leave a comment if your tests gave you different results.

Wednesday, October 1, 2014

Powershell MVP, once again!

I am so honored to say that I have received the Microsoft MVP award for the second year following my contributions to the Powershell Community and on this very same blog.
 
 
It's definitively been a long year, full of intense moments, like in February when I spoke on Powershell in front of several hundreds of people during the Techdays in Paris with my friend Fabien Dibot and for the first time I met the MVP project coordinators Martine and Marjorie.
 
Or like when I took part in coaching the competing teams during the 2014 Powershell Winter Scripting Games and came to work with brilliant people like Mike F Robbins, Boe Prox, Emin Atac, Jeff Wouters and Jan Egil Ring, just to mention a few.
 
It's always nice to see that the effort I make to publish good content have once again been noticed and that the Community appreciate them. I will do my best to improve content quality up to the highest standards, so stay tuned for more on Powershell and System Administration!

Friday, August 22, 2014

How to disable IPv6 with Powershell

The weekend is approaching fast. I have decided to end the week with a post on how to disable IPv6 on your Windows computer with a simple Powershell oneliner, since I had to do it in a specif infrastructure design this week and wanted to share the how-to. Not that disable IPv6 is something that I would recommend, since, as Microsoft reminds us, "IPv6 is a mandatory part of the Windows operating system" and "Microsoft does not perform any testing to determine the effects of disabling IPv6. If IPv6 is disabled on Windows 7, Windows Vista, Windows Server 2008 R2, or Windows Server 2008, or later versions, some components will not function."

Despite that, there are exceptions, and it could be useful to know how to do it, especially if you are running Windows in Server Core mode. Here's the quick oneliner in charge of it:
New-ItemProperty 'HKLM:\SYSTEM\CurrentControlSet\Services\Tcpip6\Parameters\' `
     -Name  'DisabledComponents' -Value '0xffffffff' -PropertyType 'DWord'
As you can see this oneliner modifies the DisabledComponents registry value, which disables all IPv6 components and affects all network interfaces on your host except the IPv6 loopback interface.
 

Note that you must restart your computer for these changes to take effect:
Restart-Computer
As a side note, let me tell you that you can force pings to use IPv4 or IPv6 just by appending a -4 or -6 switch to your PING command:
ping localhost -4

Pinging happysysadm.com [127.0.0.1] with 32 bytes of data:
Reply from 127.0.0.1: bytes=32 time=1ms TTL=128
Reply from 127.0.0.1: bytes=32 time=1ms TTL=128
Reply from 127.0.0.1: bytes=32 time=1ms TTL=128
Reply from 127.0.0.1: bytes=32 time=1ms TTL=128

Ping statistics for 127.0.0.1:
    Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
Approximate round trip times in milli-seconds:
    Minimum = 0ms, Maximum = 1ms, Average = 0ms

ping localhost -6

Pinging happysysadm.com [::1] with 32 bytes of data:
Reply from ::1: time=1ms
Reply from ::1: time=1ms
Reply from ::1: time=1ms
Reply from ::1: time=1ms

Ping statistics for ::1:
    Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
Approximate round trip times in milli-seconds:
    Minimum = 0ms, Maximum = 0ms, Average = 0ms
I hope you have learned something! Stay tuned for more Powershell tips!

Thursday, July 24, 2014

Windows boot history and boot performance, explored in Powershell

Last week I spent quite a few lines explaining how we could use Powershell to retrieve the Windows boot time with the highest possible precision. I came to the conclusion that the best option we had was to reverse-engineer the system boot timestamp from the [Environment]::TickCount counter using the following command line:

(Get-Date) - ([timespan]::FromMilliseconds([Math]::Abs([Environment]::TickCount)))
This time I wan to dig in the possiblity under Windows client operating systems (Windows 7, Windows 8 and Windows 8.1) to get an even more accurate timestamp using the information offered by the Microsoft-Windows-Diagnostics-Performance provider (which is not available on Windows server versions). I will also take advantage of the large amount of information this provider brings back to build an history of my laptop boots, as well as to retrieve the duration of each boot process.

The little known Event Id 100

The key cmdlet I will be using here, you should now know, is Get-WinEvent, used against the aforementioned provider to fetch events tagged with ID 100:

Get-WinEvent -FilterHashtable @{
     logname='Microsoft-Windows-Diagnostics-Performance/Operational';
     id=100
     } -MaxEvents 10



By investigating all the Event ID 100 events, you will be able to find out exactly how long it took to boot up your system every time since the day you installed your Windows computer. Here's a sample content of an instance of Event ID 100:

Log Name:      Microsoft-Windows-Diagnostics-Performance/Operational
Source:        Microsoft-Windows-Diagnostics-Performance
Date:          09/07/2014 09:38:32
Event ID:      100
Task Category: Boot Performance Monitoring
Level:         Critical
Keywords:      Event Log
User:          LOCAL SERVICE
Computer:      computer.happysysadm.com
Description:
Windows has started up: 
     Boot Duration  : 258644ms
     IsDegradation  : false
     Incident Time (UTC) : ?2014?-?07?-?09T07:33:10.656000200Z
Event Xml:
<Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
  <System>
    <Provider Name="Microsoft-Windows-Diagnostics-Performance" Guid="{CFC18EC0-96B1-4EBA-961B-622CAEE05B0A}" />
    <EventID>100</EventID>
    <Version>2</Version>
    <Level>1</Level>
    <Task>4002</Task>
    <Opcode>34</Opcode>
    <Keywords>0x8000000000010000</Keywords>
    <TimeCreated SystemTime="2014-07-09T07:38:32.025911700Z" />
    <EventRecordID>477</EventRecordID>
    <Correlation ActivityID="{032FBC50-F800-0002-0C58-EA08489BCF01}" />
    <Execution ProcessID="1776" ThreadID="4708" />
    <Channel>Microsoft-Windows-Diagnostics-Performance/Operational</Channel>
    <Computer>computer.happysysadm.com</Computer>
    <Security UserID="S-1-5-19" />
  </System>
  <EventData>
    <Data Name="BootTsVersion">2</Data>
    <Data Name="BootStartTime">2014-07-09T07:33:10.656000200Z</Data>
    <Data Name="BootEndTime">2014-07-09T07:38:09.839166700Z</Data>
    <Data Name="SystemBootInstance">43</Data>
    <Data Name="UserBootInstance">23</Data>
    <Data Name="BootTime">258644</Data>
    <Data Name="MainPathBootTime">224783</Data>
    <Data Name="BootKernelInitTime">22</Data>
    <Data Name="BootDriverInitTime">10421</Data>
    <Data Name="BootDevicesInitTime">1082</Data>
    <Data Name="BootPrefetchInitTime">58338</Data>
    <Data Name="BootPrefetchBytes">347176960</Data>
    <Data Name="BootAutoChkTime">0</Data>
    <Data Name="BootSmssInitTime">29186</Data>
    <Data Name="BootCriticalServicesInitTime">32461</Data>
    <Data Name="BootUserProfileProcessingTime">4496</Data>
    <Data Name="BootMachineProfileProcessingTime">2</Data>
    <Data Name="BootExplorerInitTime">57583</Data>
    <Data Name="BootNumStartupApps">15</Data>
    <Data Name="BootPostBootTime">33861</Data>
    <Data Name="BootIsRebootAfterInstall">false</Data>
    <Data Name="BootRootCauseStepImprovementBits">0</Data>
    <Data Name="BootRootCauseGradualImprovementBits">0</Data>
    <Data Name="BootRootCauseStepDegradationBits">0</Data>
    <Data Name="BootRootCauseGradualDegradationBits">0</Data>
    <Data Name="BootIsDegradation">false</Data>
    <Data Name="BootIsStepDegradation">false</Data>
    <Data Name="BootIsGradualDegradation">false</Data>
    <Data Name="BootImprovementDelta">0</Data>
    <Data Name="BootDegradationDelta">0</Data>
    <Data Name="BootIsRootCauseIdentified">false</Data>
    <Data Name="OSLoaderDuration">2511</Data>
    <Data Name="BootPNPInitStartTimeMS">22</Data>
    <Data Name="BootPNPInitDuration">1333</Data>
    <Data Name="OtherKernelInitDuration">4272</Data>
    <Data Name="SystemPNPInitStartTimeMS">5591</Data>
    <Data Name="SystemPNPInitDuration">10169</Data>
    <Data Name="SessionInitStartTimeMS">15776</Data>
    <Data Name="Session0InitDuration">16869</Data>
    <Data Name="Session1InitDuration">965</Data>
    <Data Name="SessionInitOtherDuration">11350</Data>
    <Data Name="WinLogonStartTimeMS">44962</Data>
    <Data Name="OtherLogonInitActivityDuration">117737</Data>
    <Data Name="UserLogonWaitDuration">40540</Data>
  </EventData>
</Event>
As you can see, there is more information here than you could have hoped for, and I admit one could feel overwhelmed, especially because most of those counters in the EventData node are not so well documented. Fortunately their name is self-explanatory and this helps a bit.

Our attention will focus on four of those fields: BootStartTime, BootEndTime, MainPathBootTime and BootPostBootTime.
 
 
Let's see what they are.

How Windows measures its boot performance
 
To make it simple (even do I think I'll write a specific blog post on this in the future, since this is pretty interesting), when you start your computer, as soon as WinLoad.exe loads the kernel, Windows logs a first timestamp in the BootStartTime variable. When every background service has been started and the computer has been idle for 10 seconds, Windows will log a second timestamp in the BootEndTime variable. The duration between these two timestamps is divided into two separate counters. The first one is MainPathBootTime, which records the number of milliseconds it takes for the system to load all kernel drivers and services that are meant to make Windows available for interaction. Following this, BootPostBootTime measures the time needed to load low-priority processes and services.


 
Great, isn't it? If you had been using a stopwatch to get this information you were on the wrong path. The new event logging system based on ETW and born with Windows Vista is seriously doing a great job of recording handy performance data and Event ID 100 is a great example of this mechanism.

Here's the values for these fields on my laptop.

BootStartTime                                               2014-07-09T07:33:10.656000200Z
BootEndTime                                                 2014-07-09T07:38:09.839166700Z
MainPathBootTime                                            224783
BootPostBootTime                                            33861
As I said, the values of MainPathBootTime and of BootPostBootTime are expressed in milliseconds. Each time the Diagnostics-Performance provider asynchronously writes this information in the event log, the event severity is dinamically calculated against some values which are stored in the registry under HKLM:\SOFTWARE\Microsoft\Windows\CurrentVersion\Diagnostics\Performance\Boot.

Their default values can be retrieved in Powershell and are exactly the same on Windows 7 or Windows 8:

cd HKLM:
cd .\SOFTWARE\Microsoft\Windows\CurrentVersion\Diagnostics\Performance
Get-Item Boot

Hive: HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows\CurrentVersion\Diagnostics\Performance

Name                           Property
----                           --------
Boot                           PostBootMajorThreshold_Sec      : 60
                               PostBootMinorThreshold_Sec      : 30
                               BootMajorThreshold_Sec          : 120
                               HardThresholds_CritServicesList : CscService,DcomLaunch,EventLog,EventSystem,gpsvc,PlugPlay,ProfSvc,RpcSs,SENS,Themes,MMCSS,AudioEndpointBuilder,Audiosrv,Windefend
                               BootMinorThreshold_Sec          : 60
                               PostBootDelay_Sec               : 90
                               UserWaitTimeout_Sec             : 60
                               PostBoot_TimeToAccumulate_Sec   : 10
                               PostBoot_BusyThreshold          : 20
                               MinDelayPercentageToIdentify    : 10
                               NumInitialBootsToIgnore         : 1
Twelve keys here. As far as I was able to determine, here's the logic behind the level (critical, error, warning) assignment:
  • if MainPathBootTime duration is less than BootMinorThreshold_Sec and BootPostBootTime is less than PostBootMinorThreshold_Sec you will get a Warning event. You will always have at least a Warning, even with an SSD drive (which makes Windows usually stay in the MainPathBootTime phase for less than 10 seconds).
  • if MainPathBootTime duration is less than BootMajorThreshold_Sec and more than BootMinorThreshold_Sec and BootPostBootTime is less than PostBootMajorThreshold_Sec and more than PostBootMinorThreshold_Sec you will get an Error event.
  • if MainPathBootTime exceeds BootMajorThreshold_Sec or BootPostBootTime exceeds PostBootMajorThreshold_Sec you will get a Critical event.
In a few words, whichever value is more critical, this is what Windows ultimately attaches to event ID 100.

The script - Building a boot history based on events with Id 100

In the first part of the script I build an object containing the Windows boot history. Notice that you need to make sure that you have the admin token to access the information of the Diagnostics-Performance provider, otherwise you'll get an error. Happily enough, checking for admin rights has become pretty easy in Powershell 4.0 thanks to the new #requires syntax.

#requires -version 4.0
#requires –runasadministrator

#Retrieving all events with ID 100

$BootEvents = Get-WinEvent -FilterHashtable @{
  logname='Microsoft-Windows-Diagnostics-Performance/Operational';
  id=100}

#Building a boot history with, for each boot, the duration of the boot process

$BootHistory = $BootEvents | Select-Object TimeCreated, LevelDisplayName,
        @{
   n="BootStartTime";
   e={Get-Date -Date (([xml]$_.ToXml()).Event.EventData.Data |
  Where-Object {$_.name -eq "BootStartTime"})."#text"}
  },
        @{
   n="BootEndTime";
   e={Get-Date -Date (([xml]$_.ToXml()).Event.EventData.Data |
  Where-Object {$_.name -eq "BootEndTime"})."#text"}
  },
        @{
   n="MainPathBootTime";
   e={([timespan]::FromMilliseconds((([xml]$_.ToXml()).Event.EventData.Data |
  Where-Object {$_.name -eq "MainPathBootTime"})."#text"))}
  },
 @{
   n="BootPostBootTime";
   e={([timespan]::FromMilliseconds((([xml]$_.ToXml()).Event.EventData.Data |
  Where-Object {$_.name -eq "BootPostBootTime"})."#text"))}
  }

The script - Setting up temporary variables

In the second part I work out temporary variables to evite too long lines and make the script more readable (though this is pretty difficult in a blog...). Notice also that in the .ToString method I use backslashes to escape the colons, which otherwise have a special meaning.

$BootStartTime = $BootHistory.bootstarttime

$MainPathBootTime = $BootHistory.MainPathBootTime

$PostBootTime = $BootHistory.BootPostBootTime

$LastBootDate = $BootStartTime | Select-Object -First 1

$OldestRecordedBoot = $BootStartTime | Select-Object -last 1

$BootFrequencyInDays = ($LastBootDate - $OldestRecordedBoot).days / $BootStartTime.Count

$AvgMainBootDuration = [timespan]::FromSeconds((($MainPathBootTime.totalseconds |
  Measure -A).average)).ToString("hh\:mm\:ss")

$AvgPostBootDuration = [timespan]::FromSeconds((($PostBootTime.totalseconds |
  Measure -A).average)).ToString("hh\:mm\:ss")

$ActualWindowsBootTime = (Get-Date) - `
  ([timespan]::FromMilliseconds([Math]::Abs([Environment]::TickCount)))

$LastEvent12 = Get-WinEvent -FilterHashtable @{
  LogName='System';
  ProviderName='Microsoft-Windows-Kernel-General';
  ID=12} -MaxEvents 1 | Select -ExpandProperty TimeCreated

The script - Generating summary information on Windows boot performance

In the third part I build an object contaning summary information on Windows boot performance, like the average boot duration (divided in main boot phase and post boot phase), or the current boot date as retrieved from the last event 12 of the Microsoft-Windows-Kernel-General provider.

#Building an object containing a quick summary of your last computer boot, as
#well as of the average boot duration. 

$BootInformation = 1 | Select-Object BootFrequencyInDays, AvgMainBootDuration, `
   AvgPostBootDuration, LastBootDate, OldestRecordedBoot, `
   ActualWindowsBootTime, LastEvent12
$BootInformation.BootFrequencyInDays = $BootFrequencyInDays
$BootInformation.AvgMainBootDuration = $AvgMainBootDuration
$BootInformation.AvgPostBootDuration = $AvgPostBootDuration
$BootInformation.LastBootDate = $LastBootDate
$BootInformation.OldestRecordedBoot = $OldestRecordedBoot
$BootInformation.ActualWindowsBootTime = $ActualWindowsBootTime
$BootInformation.LastEvent12 = $LastEvent12

The script - Assessing Windows boot performance

In the fourth and last part I implement an object which allow you to see how Windows assesses boot performance, based on the values of the registry keys we saw above.

#Grouping boot events by Level, in order to see if your computer boot duration is below or
#beyond the thresholds defined in the Registry
$BootAnalysis = Get-WinEvent -FilterHashtable @{
  logname='Microsoft-Windows-Diagnostics-Performance/Operational';
  id=100} |
  Group-Object LevelDisplayName

The results - Windows boot history based on event with Id 100

Here's a sample output of each portion of this script:

$BootHistory | Format-Table

TimeCreated           LevelDisplayName   BootStartTime        BootEndTime            MainPathBootTime   BootPostBootTime
-----------           ----------------   -------------         -----------           ----------------   ----------------
09/07/2014 09:38:32   Critical           09/07/2014 09:33:10   09/07/2014 09:38:09   00:03:44.7830000   00:00:33.8610000
01/07/2014 09:45:33   Critical           01/07/2014 09:41:37   01/07/2014 09:45:28   00:02:27.4760000   00:00:51.8410000
27/06/2014 10:11:47   Critical           27/06/2014 10:08:11   27/06/2014 10:11:35   00:02:18.1190000   00:00:46.0080000
Powerful, isn't it? For improved readabilty, why not to take advantage of the cmdlet Out-GridView to generate a nice GUI:


The results - Windows boot overview

Here's my laptop boot summary. You can see that I boot my test machine roughly every month (32 days to be exact) and that the Main Boot Phase lasts twice the Post Boot Phase.
$BootInformation

BootFrequencyInDays       : 32,0810810810811
AvgMainBootDuration       : 00:02:08
AvgPostBootDuration       : 00:00:50
LastBootDate              : 09/07/2014 09:33:10
OldestRecordedBoot        : 09/04/2011 01:48:37
ActualWindowsBootTime     : 09/07/2014 09:33:34
LastEvent12               : 09/07/2014 09:33:10

The results - Windows boot assessment

The information contained in $BootAnalysis shows us that I have pretty bad boot performance, with a majority of Critical events, which means that my total boot time exceeds 3 minutes, and that some investigation should be on my action plan.

$BootAnalysis | Format-Table -Property Name, Count -AutoSize

Name          Count
----          -----
Critical         24
Error            7
Warning          6

Off-topic - Diagnostics-Performance is only for Windows clients

As I said at the beginning of this blog post, the "Microsoft-Windows-Diagnostics-Performance/Operational" provider is available only on Windows Client systems. If you used my script above against any Windows Server (2008 or 2012) you would get this red error:

Get-WinEvent : There is not an event log on the localhost computer that matches "Microsoft-Windows-Diagnostics-Performance/Operational".
At line:4 char:11
+ $events = Get-WinEvent -FilterHashtable @{logname='Microsoft-Windows-Diagnostics ...
+ ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
    + CategoryInfo          : ObjectNotFound: (Microsoft-Windo...nce/Operational:String) [Get-WinEvent], Exception
    + FullyQualifiedErrorId : NoMatchingLogsFound,Microsoft.PowerShell.Commands.GetWinEventCommand
So, before running the script, check you have the provider:

Get-WinEvent -ListLog Microsoft-Windows-Diagnostics-Performance/Operational

LogMode   MaximumSizeInBytes RecordCount LogName
-------   ------------------ ----------- -------
Circular             3080192         497 Microsoft-Windows-Diagnostics-Performance/Operational

Off-topic - Changing event log sizes

Let me add here that an important action that should be part of any Windows management process is to customize these event log sizes for storing more boot events.

The code below helps to you increase the System log file size of your choice to the desired value:

Get-EventLog -list | Where-Object {$_.logdisplayname -eq "System"}

  Max(K) Retain OverflowAction        Entries Log
  ------ ------ --------------        ------- ---
   1 024      0 OverwriteAsNeeded      23 327 System

Limit-EventLog -LogName 'System' -MaximumSize 30MB

Get-EventLog -list | Where-Object {$_.logdisplayname -eq "System"}

  Max(K) Retain OverflowAction        Entries Log
  ------ ------ --------------        ------- ---
  30 720      0 OverwriteAsNeeded      23 327 System
As for changing the size of the new Microsoft-Windows-Diagnostics-Performance/Operational log, there is no way for the moment you can do that using Limit-EventLog (because it doesn't work on the additional event logs existing from Windows Vista), and .NET must be leveraged in order to accomplish the task. Fortunately this is a breeze in Powershell:

$Log = New-Object -TypeName System.Diagnostics.Eventing.Reader.EventLogConfiguration -ArgumentList "Microsoft-Windows-Diagnostics-Performance/Operational"

$Log.MaximumSizeInBytes = 3080192

$Log.SaveChanges()

$Log

LogMode   MaximumSizeInBytes LogName
-------   ------------------ -------
Circular             3080192 Microsoft-Windows-Diagnostics-Performance/Operational
Increasing the timespan of recorded events will give you a better insight of your computer boot duration over a long period of time.

Conclusions

Each version of Windows has a great deal of new features and functionalities aimed at making system administration more precise than it was before. This is meant to make Windows a better operating system, in the sense that any Windows owner can have access to a lot of technical information that were before hidden behind the interface. Having access to all the information stored in events tagged with Id 100 is an example of this philosophy, which I like. Powershell, as always, it the tool for the job, and anyone interested in system administration should give it a try to see how the best of both worlds (Unix-like and Windows) has been put into it.

Hope you enjoyed this second trip inside windows boot, and, as always, if you have any question on the code, please leave a comment and I'll be more than happy to explain. If you enjoyed the content of this post, please share!
Until next time!

Tuesday, July 8, 2014

Windows boot time, explored in Powershell

In this post I am going to explore most of the existing ways offered by Windows and Powershell to return the timestamp of the last boot.
 
Let's start with saying that there are multiple ways to retrieve this piece of information and exploring them all will make for what I hope is an interesting trip through some Windows internal mechanisms. Be wary by the way that this subject is very wide, and I have allowed myself some small off-topics that are meant to shed some light on the pieces of code we are now so used to see out there.

Windows is booting, but what time is it?
In old times (more or less one to two decades ago) we could (and still we can) use various legacy tools to fetch a Windows computer boot timestamp.
 
In more recent Windows versions some alternatives to those legacy Tools have appeared and we can today use the information stored:
  • in the Performance counters
  • in the Win32_OperatingSystem WMI instance
  • in the Windows event logs
Each of this approach has pros and cons. Some syntaxes are easier and some are trickier. Going through them all will give you an interesting insight of how you can take advantage of Windows Powershell as your all-in-one administration tool. In any case, please notice that the following examples have been prepared and tested on computers with European settings for the date (dd/MM/yyyy). As a consequence those that are based on text parsing or regular expressions might need some correction if you want to run them on a computer with different regional settings.

Let's start from the beginning: there are three possible legacy executables that you can use the retrieve the last reboot date:
  1. systeminfo.exe in C:\Windows\System32
  2. net.exe in C:\Windows\System32
  3. wmic.exe in C:\Windows\System32\wbem
1. System boot time with SYSTEMINFO
 
Systeminfo.exe is the old good tool every Windows admin used to get a quick look at system information. Used in conjunction with another legacy command, FIND, it allows you to see system boot time.

systeminfo | find "System Boot Time:"
System Boot Time:          07/07/2014, 17:41:11
The returned information is of System.String type.
systeminfo |
     find "System Boot Time:" |
     Get-Member |
     Select-Object Typename -Unique

TypeName                                                                                          
--------
System.String
As usual in Powershell, our aim is to return a re-usable object. In this case, better than a System.String, we would like to have a System.DateTime variable. The transformation can be achieved with an easy one-liner (for an explication of which you can refer to the final part my other blog post:

[datetime]::ParseExact($(systeminfo |
     find "System Boot Time:").substring(27,20),"dd/MM/yyyy, HH:mm:ss",$null)

Monday, July 7, 2014, 17:41:11
The main drawback of using systeminfo is that, since it retrieves the list of all the installed patches, it can take quite a long time to be executed, especially on long living systems, and there is nothing you can do to improve that.
 
2.  System boot time with NET

The second legacy executable is net.exe, which has two possible syntaxes, a long one (net statistics server) and a short one (net stats srv), both returning the same result:

net statistics server
Server Statistics for \\SRV01


Statistics since 07/07/2014 17:41:21


Sessions accepted                  0
Sessions timed-out                 0
Sessions errored-out               0

Kilobytes sent                     16
Kilobytes received                 0

Mean response time (msec)          0

System errors                      0
Permission violations              0
Password violations                0

Files accessed                     21
Communication devices accessed     0
Print jobs spooled                 0

Times buffers exhausted

  Big buffers                      0
  Request buffers                  0

The command completed successfully.
Lot of text in the output, as you can see, and the proceeding to get something meaningful out of it is a bit less comfortable, since some regex pattern matching needs to be done (if you have any kind of question do not hesitate to ask in the comment section below):

[datetime]::ParseExact($($(net stats srv) `
     -match "\d{2}/\d{2}/\d{4}").substring(17,19),"dd/MM/yyyy HH:mm:ss",$null)

Monday, July 7, 2014, 17:41:11

3. System boot time with WMIC
 
Third option, WMIC (which, if don't have it yet, you can get with the WMI Administrative Tools). The only thing you need to know for the moment is that WMIC is an alias based tool which interfaces with WMI (Windows Management Instrumentation). While it has many uses, I find it especially useful for querying certain system parameters, like the type and frequency of the processor, such as in 'wmic cpu get Name'.

To get the system boot up time, the syntax is:
wmic os get lastbootuptime

LastBootUpTime
20140707174111.489051+120
To explain the result of this WMIC example, let me start a brief discussion on the ways WMI stores dates and times, which is always good to know if you are a Windows sysadm. The Common Information Model (CIM) standard, where WMI is sitting on, uses the Universal Time Coordinate (UTC) format. Although UTC dates are non-intuitive at first glance, they are relatively easy to convert to a standard date-time format.

Let's have a look at their format, 20140707174111.489051+120, which is easy for humans to translate to yyyymmddHHMMSS.mmmmmmsUUU (full syntax over here)
In technical terms, this is a variant VT_BSTR returned by WMI as a 27 chars string (where the last two characters are blank in the WMIC output).
wmic os get lastbootuptime | Get-Member | Select-Object typename -Unique

TypeName
--------
System.String
Luckily, to convert this string to a valid Datetime, we can rely on the SWbemDateTime object. This is an object which, starting from Windows XP (way old, isn't it?) is used as a helper to parse CIM datetime values, as in the following example I wrote, where I first use a REGEX expression to skip the undesired text, then I force the remaining data into the Value property:
# Convert from VT_BSTR to System.Datetime
$DateTimeObject = New-Object -ComObject WbemScripting.SWbemDateTime 
$DateTimeObject.Value = $($(wmic os get lastbootuptime) `
     -match "\d{14}\.\d{6}\+\d{3}").TrimEnd() #TrimEnd removes the 2 last blank chars
$DateTimeObject.GetVarDate($DateTimeObject.Value)

Monday, July 7, 2014, 17:41:11
$DateTimeObject.GetVarDate($DateTimeObject.Value) |
     Get-Member |
     Select-Object typename -Unique

TypeName : System.DateTime
This was a general introduction to the three golden ways to retrieve the system boot time on a Windows box using legacy executables and returning the result as a DateTime object.

Of course there are other more Powershell-oriented ways to get to this very same result. Let's take the long windy road to that, by starting to introduce some WMI performance class information.

4. An introduction to WMI performance classes

There are two kinds of WMI performance classes: raw counter classes and cooked counter classes (yes, I didn't made it up: 'cooked' is the technical term for them).
The difference? Well, raw counters are simply raw numbers which have gone through no post-processing. Cooked counters, on the other side, are counters supplied by the Formatted Performance Data Provider, which is in charge of supplying calculated counter data.

As an example, take the two performance classes that store the actual uptime, from which, using a simple subtraction, we can make the system boot date:
Get-WmiObject -List Win32_Perf*System | select Name

Name
----
Win32_PerfFormattedData_PerfOS_System
Win32_PerfRawData_PerfOS_System
Both these classes have the same properties with different values, and this can be confusing. But the raw class has two additional information, which you have to use to get the results you expect (and which are pre-cooked in the formatted class) from the raw data:
  • The first is the Timestamp_Object, which is an object-defined timestamp, defined by the provider, storing the current time measure.
  • The second is the Frequency_Object, which represents the frequency, in ticks per second, of the mentioned Timestamp_Object.
5. System boot time from RAW Performance Counters

Wait, ticks you said? You might be wondering what the heck a tick is, and this allows for a nice short discussion on the internals of Microsoft Windows and, more generally, of how a computer works.
 
Inside any CPU there are processor registers which are in charge of storing data used by arithmetic calculations. One of these, named Time Stamp Counter is a 64-bit register present on all x86 processors since the Pentium (remember?) which counts the number of cycles since reset, known as ticks.

Over time a tick has become a constant which is independent from the processor clock, even do tick count is updated at the System clock interval (every 10msec or 15.6 msec on most systems). The value of this constant is 10 millions per second (as stated over here), which gives a tick a duration of 100 ns.

So, each raw measure of the uptime has this Frequency_Object property constantly set at 10 million ticks per second, which is the frequency at which the Timestamp_Object is recorded.
To calculate the system uptime in seconds from this raw data, the following formula should then logically be used:

UptimeInSec = (Timestamp - SystemUptime) / Frequency

where the SystemUptime is another property containing the timestamp at boot expressed in the same unit as Timestamp_Object.

Let's convert this formula to Powershell:

$TimestampAtBoot = Get-WmiObject Win32_PerfRawData_PerfOS_System |
     Select-Object -ExpandProperty systemuptime
$CurrentTimestamp = Get-WmiObject Win32_PerfRawData_PerfOS_System |
     Select-Object -ExpandProperty Timestamp_Object
$Frequency = Get-WmiObject Win32_PerfRawData_PerfOS_System |
     Select-Object -ExpandProperty Frequency_Object
$UptimeInSec = ($CurrentTimestamp - $TimestampAtBoot)/$Frequency
$UptimeInSec

13180,8610781
Fine. We have been able to calculate our system uptime in seconds starting from truly primary data using a short Powershell script. Now let's try to convert this to something more meaningful and show the system boot time as a DateTime like in the previous examples:

(Get-Date) - (New-TimeSpan -seconds $UptimeInSec)

Monday, July 7, 2014, 17:41:11
Here you have your system boot date and time and the type of the returned object is already of DateTime type, so no parsing required. Great!
 
6. System boot time from [Environment]::TickCount

Another way to get your system boot date is to rely on some information exposed by the .NET Environment class. As explained in MSDN, the system timer we talked above behaves in a way that it increments the value of the property TickCount (which stores in a 32-bit signed integer the number of milliseconds elapsed since the system started) going from zero to Int32.MaxValue (where [int32]::MaxValue is 2147483647) for 24.9 days, then jump to Int32.MinValue (where [int32]::MinValue is -2147483648), which is a negative number, and starts incrementing back to zero for the next 24.9 days.

To see the attributes of the TickCount counter, issue:

[Environment]  |
     Select-Object -ExpandProperty DeclaredProperties |
     Where-Object Name -like TickCount
To get the system boot date using [Environment] we have first to get the time span from the number of milliseconds stored in TickCount, then subtract that time interval from the current date and time:

(Get-Date) - ([timespan]::FromMilliseconds([Math]::Abs([Environment]::TickCount)))

Monday, July 7, 2014, 17:41:11
The function [Math]::Abs() is used to return the absolute value of any number, and it is pretty useful here if your tick count is a negative number (which could be the case on systems up from more than 25 days).

7. System boot time from COOKED Performance Counters

Until now we have explained the differences between raw and cooked performance classes and we have seen how to retrieve the system boot time from the current uptime using the New-TimeSpan cmdlet. Time to see how easy is to get the same information using a cooked performance class in conjunction with a time interval.

The class Win32_PerfFormattedData_PerfOS_System contains a number of performance counters related to the operating system, including SystemUpTime, which tells you how many second the machine has been running, while its raw version Win32_PerfRawData_PerfOS_System stored in Systemuptime just a unit showing the time at boot.

(Get-Date) - (New-TimeSpan -Seconds (Get-WmiObject Win32_PerfFormattedData_PerfOS_System).systemuptime)
Lots of different examples to get the same information, isn't it? Now I am going to show you two more way to get the system uptime. One relies on WMI and the other one on the System eventlogs.

8. System boot time from Win32_OperatingSystem

Let's start from the WMI method. All the lessons we learned above on UTC time formatting and conversion operations from VT_BSTR to DATETIME will be re-used in our next examples and will make you more confident with this kind of Powershell game.

For the WMI part, the only class that we need here is Win32_OperatingSystem. The instance of this class keeps a pretty big bunch of information, such as the Manufacturer of your PC, the name of the registered user, or the OS architecture and language. Furthermore there are a few interesting properties containing precious time-oriented information: CurrentTimeZone, InstallDate, LocalDateTime and, can't believe it, LastBootUpTime. As I explained before, WMI dates are returned as strings and not as datetime objects. These strings are compliant with the CIM standards, so to get a valid re-usable System.DateTime object we have first to make some rework.

Two ways to do that.

The first one is, like I showed in the WMIC example, using the SWbemDateTime helper object:

# Convert from VT_BSTR to System.Datetime
$DateTimeObject = New-Object -ComObject WbemScripting.SWbemDateTime 
$DateTimeObject.Value = (Get-WmiObject Win32_OperatingSystem).LastBootUpTime
$DateTimeObject.GetVarDate($DateTimeObject.Value)
The second method relies on the fact that most WMI objects returned by Powershell have a comfortable "ConvertFromDateTime" method implemented out-of-the-box. Cool.
For example:
Get-WmiObject -Class win32_operatingsystem | Get-Member -MemberType ScriptMethod
will return:
ConvertFromDateTime               ScriptMethod  System.Object ConvertFromDateTime();                                                                               
convertToDateTime                 ScriptMethod  System.Object ConvertToDateTime();
Did I already say: "Cool!"?

Let's take advantage of it then:

$OSInfo = Get-WmiObject Win32_OperatingSystem
$OSInfo.ConvertToDateTime($OSInfo.LastBootupTime)
or, if you are a seasoned old school programmer:

$OSInfo  = Get-WmiObject -query "select * from win32_OperatingSystem"
$OSInfo.ConvertToDateTime($OSInfo.LastBootupTime)

For the most curious, there is also a pretty nice ManagementDateTimeConverter Class, which provides methods to convert CIM datetime to System.DateTime:

$OSInfo = Get-WmiObject Win32_OperatingSystem
[Management.ManagementDateTimeConverter]::ToDateTime($OSInfo.lastbootuptime)
That's all for the WMI part.

9. An introduction to Event Tracing for Windows (ETW) 

Time to pass to exploring the information that can be retrieved from your system event logs and see how they compare, but before we see that, and for better understanding, it's interesting to see how the Microsoft Eventing engine has evolved in the past 10 years.

Under Windows NT4 or Windows XP, the Event Log service recorded computer events in three simple logs, like you can see in the following screenshot: System, Security and Application.


Like most Windows developers know (while many administrators have never heard of it), starting with Windows Vista in 2006, the Windows Event Logs has been rewritten on top of the Event Tracing for Windows (ETW) technology, which is a system and software diagnostic, troubleshooting and performance monitoring component.

This new Event Viewer has been completely re-engineered and its appearance has also changed, but it is still familiar enough to not to feel miles from home:


In the new interface there are still a tree pane and a list of events. You can still access the well-known Application, System, and Security logs under the Windows Logs node.
However:
  • some new nodes have been added, such as the Applications and Services logs which is a new category of event logs aimed at storing events from a single application or component rather than systemwide events.
  • the new ForwardedEvents log has been added to the Windows Logs node.
A lot of other Windows components were since then built on top of it, such as Resource Monitor, which allows sysadmins to drill down computer performance much better they could do with Task Manager on older versions.

Version after version, ETW exposes an increasing number of consistent information providers (through the use of a unified event provider model). Those information providers can be retrieved using logman and counted using the Powershell Count() method:

(c:\Windows\System32\logman.exe query providers).count
  • In Windows 8.1 there are 964 providers
  • In Windows 2012 r2 there are 830 providers
  • In Windows 7 there were 668 providers and 513 in Windows 2008 R2
  • In Windows 2003 R2 no more than 10 providers were exposed
Of course these figures increase when additional features or products are installed (such as Active Directory or, say, Hyper-V).

Unlike its predecessors, Windows (starting from Windows NT 4.0/2000/XP) records the system startup and shutdown times in the event log with the following informational Event IDs: 6005,6006,6008,6009.
For what we are trying to achieve, EventID 6005 is the most meaningful, because it occurs when the Event log service is started, just after the system has been booted and Windows has loaded.

In addition to these event IDs, there are some events from the Microsoft-Windows-Kernel-General event provider (exposed by ETW, which we just discussed) which indicate system startup and shutdown time.
You can find deeper information on this event provider as well as on the mentioned events by issuing the following Powershell commands:

c:\Windows\System32\logman.exe query providers Microsoft-Windows-Kernel-General
which can also be used in the form: 

c:\Windows\System32\logman.exe query providers Kernel-General
and:

(Get-WinEvent -listprovider Microsoft-Windows-Kernel-General).events |
     Select-Object Id, Description |
     Format-Table -AutoSize
As you can see in the output, there are thirteen possible events. For calculation our system last boot date, we can optimistically refer to entries tagged with the EventID 12: "The operating system started at system time %7"

Let's focus then on Event ID 12, source Microsoft-Windows-Kernel-General, and Event ID 6005, source EventLog, to see which one gives us the most reliable information on our system boot time.

In Powershell, as you would expect now that you are an accustomed Powershell user, there are six ways to query the Event Logs:
  • Get-WmiObject -Class Win32_NTLogEvent
  • Get-WmiObject -Query "SELECT * FROM Win32_NTLogEvent"
  • Get-EventLog
  • Get-WinEvent -FilterXml
  • Get-WinEvent -FilterHashtable
  • Get-WinEvent -FilterXPath
Let's have a deeper look at each and every one of these possibilities.
 
10. System boot time from Win32_NTLogEvent

First of all, we also have the option of using WMI against the Win32_NTLogEvent class, as shown here:

$Event12 = Get-WmiObject -Class Win32_NTLogEvent `
     -Filter "LogFile = 'System' AND SourceName='Microsoft-Windows-Kernel-General' AND EventCode=12" |
     Select-Object -First 1
$Event12.ConvertToDateTime($Event12.Timegenerated)
and here:

$Event6005 = Get-WmiObject -Class Win32_NTLogEvent `
     -Filter "LogFile = 'System' AND SourceName='EventLog' AND EventCode=6005" |
     Select-Object -First 1
$Event6005.ConvertToDateTime($Event6005.Timegenerated)
or:

$Event12 = Get-WmiObject -Query "SELECT * FROM Win32_NTLogEvent `
     WHERE (logfile='System') AND (SourceName='Microsoft-Windows-Kernel-General') AND (EventCode='12')" |
     Select-Object -First 1
$Event12.ConvertToDateTime($Event12.Timegenerated)
and:

$Event6005 = Get-WmiObject -Query "SELECT * FROM Win32_NTLogEvent `
     WHERE (logfile='System') AND (SourceName='EventLog') AND  (EventCode='6005')" |
     Select-Object -First 1
$Event6005.ConvertToDateTime($Event6005.Timegenerated)

In both cases, the Win32_NTLogEvent WMI class is used to translate instances from the Windows event log, using the same mechanism explained before for Win32_OperatingSystem.
 
11. System boot time from Get-EventLog

Second option (which, let me say, is so Powershell 1.0, and you'll see why in the performance section at the end of the post) is to use Get-EventLog. The main drawback of using Get-EventLog is that it doesn't support much in the way of filtering. That means you have to retrieve all of the entries, and then use Where-Object to filter. Needless to say, it can be pretty CPU and time consuming in case of large logs and can make your System process peak very high. That's why I always suggest to use this cmdlet in conjunction with at least the -After parameters, to shorten the time window.

12, 6005 | % {
     Get-EventLog -LogName System -After 05/05/2012 |
          Where-Object EventId -eq $_ |
          Select-Object EventId, Source, TimeGenerated -First 1
     }
To extract just the TimeGenerated field for Event IDs 12, use:

((Get-EventLog -logname system) | Where-Object {($_.eventid -eq 12) -and ($_.Source -eq 'Microsoft-Windows-Kernel-General') } )[0] | Select-Object -ExpandProperty TimeGenerated
or, for Event IDs 6005:

((Get-EventLog -logname system) | Where-Object {($_.eventid -eq 6005) -and ($_.Source -eq 'EventLog') } )[0] | Select-Object -ExpandProperty TimeGenerated
Notice in both these examples the different syntax I used to index inside the array of the returned results.
 
12. System boot time from Get-WinEvent
 
Third major option is to rely on the powerful Get-WinEvent cmdlet, which was introduced in Powershell 2.0 in 2009.
It does support three types of built-in filtering (making it lighting fast) and it can query the newer log types introduced since Vista/Win2008, so it should be preferred to Get-EventLog.
These three types of filtering are:
    -FilterHashtable 
        
        Required?                    true
        Position?                    0
        Accept pipeline input?       false
        Parameter set name           HashQuerySet
        Aliases                      None
        Dynamic?                     false
        
    -FilterXPath 
        
        Required?                    false
        Position?                    Named
        Accept pipeline input?       false
        Parameter set name           FileSet, GetProviderSet, GetLogSet
        Aliases                      None
        Dynamic?                     false
        
    -FilterXml <xml>
        
        Required?                    true
        Position?                    0
        Accept pipeline input?       false
        Parameter set name           XmlQuerySet
        Aliases                      None
        Dynamic?                     false
FilterXml takes in a XML-style string of text. This is the example for EventID 6005:

$xml6005='<QueryList><Query Id="0" Path="System"><Select Path="System">*[System[Provider[@Name="EventLog"] and (EventID=6005)]]</Select></Query></QueryList>'
Get-WinEvent -FilterXml $xml6005 -MaxEvents 1 | Select-Object -ExpandProperty TimeCreated
and this is the example for EventID 12:

$xml12='<QueryList><Query Id="0" Path="System"><Select Path="System">*[System[Provider[@Name="Microsoft-Windows-Kernel-General"] and (EventID=12)]]</Select></Query></QueryList>'
Get-WinEvent -FilterXml $xml12 -MaxEvents 1 | Select-Object -ExpandProperty TimeCreated
In both cases the returned result is of System.DateTime type. What else?

FilterHashtable takes in a hashtable containing three properties in our case: LogName, Providername and ID:

Get-WinEvent -FilterHashtable @{LogName='System'; ProviderName='Microsoft-Windows-Kernel-General'; ID=12} -MaxEvents 1 | Select-Object -ExpandProperty TimeCreated
Get-WinEvent -FilterHashtable @{LogName='System'; ProviderName='EventLog'; ID=6005} -MaxEvents 1 | Select-Object -ExpandProperty TimeCreated
Last option is to use FilterXPath. To make a long story short, XPath is a language used to query specific nodes from an XML document. If you don't use it often, its syntax can look quit scaring. But I am here to help.

For event 12 you have:

(Get-WinEvent -LogName "System" -MaxEvents 1 -FilterXPath "*[System[Provider[@Name='Microsoft-Windows-Kernel-General']][EventID=12]]").TimeCreated
and for event 6005 you have:

(Get-WinEvent -LogName "System" -MaxEvents 1 -FilterXPath "*[System[Provider[@Name='EventLog']][EventID=6005]]").TimeCreated
This was the last example I wanted to use to show you how to find out the system boot up time and date. To resume, there are 23 possible choices, and it could be difficult to choose the right tool for the job. That's why I have decided that this post wouldn't be complete without a performance analysis.
 
13. Performance
 
Performancewise, any of the above solution has its execution time depending on the information provider. That's why I have tested all of them with Measure-Command on a Windows 2012 R2 and on a Windows 8.1.  The resulting duration is expressed in seconds (from faster to slower):

Duration Title                                   Result              ResultType     
-------- -----                                   ------              ----------     
0,0393308 TickCount + TimeSpan + Get-Date         07/07/2014 17:41:11 System.DateTime
0,0417487 WMI query + SWbemDateTime               07/07/2014 17:41:11 System.DateTime
0,0429207 WMI + ManagementDateTimeConverter       07/07/2014 17:41:11 System.DateTime
0,0459907 Net Statistics Server                   07/07/2014 17:41:21 System.DateTime
0,0484394 WMI + SWbemDateTime                     07/07/2014 17:41:11 System.DateTime
0,0512981 Net Stats Srv                           07/07/2014 17:41:21 System.DateTime
0,0775581 WMI Query 6005 + ConvertToDateTime      07/07/2014 17:41:19 System.DateTime
0,0796125 WMI + ConvertToDateTime                 07/07/2014 17:41:11 System.DateTime
0,0860807 WMI filter 6005 + ConvertToDateTime     07/07/2014 17:41:19 System.DateTime
0,1026782 WMI filter 12 + ConvertToDateTime       07/07/2014 17:41:11 System.DateTime
0,1307235 WMIC + SWbemDateTime                    07/07/2014 17:41:11 System.DateTime
0,2467589 Get-WinEvent + FilterXML 12             07/07/2014 17:41:11 System.DateTime
0,2678846 Get-WinEvent + FilterXPath 6005         07/07/2014 17:41:19 System.DateTime
0,2697007 Get-WinEvent + FilterXPath 12           07/07/2014 17:41:11 System.DateTime
0,2825668 Get-WinEvent + FilterHastTable 6005     07/07/2014 17:41:19 System.DateTime
0,2962874 Get-WinEvent + FilterHastTable 12       07/07/2014 17:41:11 System.DateTime
0,2978704 PerfFormattedData + TimeSpan + Get-Date 07/07/2014 17:41:11 System.DateTime
0,3042627 WMI Query 12 + ConvertToDateTime        07/07/2014 17:41:11 System.DateTime
0,4015614 Get-WinEvent + FilterXML 6005           07/07/2014 17:41:19 System.DateTime
2,7686521 PerfRawData + TimeSpan + Get-Date       07/07/2014 17:41:11 System.DateTime
3,5873439 Systeminfo + ParseExact                 07/07/2014 17:41:11 System.DateTime
12,3051242 Get-EventLog 6005 + Where-Object        07/07/2014 17:41:19 System.DateTime
35,5054786 Get-EventLog 12 + Where-Object          07/07/2014 17:41:11 System.DateTime

The result is self-explanatory:
  • Get-EventLog is to be considered deprecated
  • Systeminfo is pretty time consuming, since it fetches all hotfix information
  • All the others are pretty fast
  • [Environment]::TickCount has jaw-dropping performance
14. Precision

Not all the Tools return the same result. There are three main groups:
  1. those that fetch the system boot date from WMI and those that fetch Event 12 as asynchronously provided from the ETW Kernel-General provider and stored in the System eventlog. This is the most accurate information, and, as I was able to verify, returns the exact time your Windows computer bootstraps after POST.
  2. those that fetch Event 6005, which is less accurate, because it returns the date and time the Event Log service has started and that is 8 seconds late on Kernel-provided information.
  3. those that are based on Network Statistics, which are returning the date and time since when the Server service has started. In this case there is a huge 10 seconds delay from what's being returned by Kernel-General.
Here's the complete result ordered by boot time:

Duration Title                                   Result              ResultType     
  -------- -----                                   ------              ----------     
 3,5873439 Systeminfo + ParseExact                 07/07/2014 17:41:11 System.DateTime
35,5054786 Get-EventLog 12 + Where-Object          07/07/2014 17:41:11 System.DateTime
 0,1307235 WMIC + SWbemDateTime                    07/07/2014 17:41:11 System.DateTime
 0,0484394 WMI + SWbemDateTime                     07/07/2014 17:41:11 System.DateTime
 2,7686521 PerfRawData + TimeSpan + Get-Date       07/07/2014 17:41:11 System.DateTime
 0,0393308 TickCount + TimeSpan + Get-Date         07/07/2014 17:41:11 System.DateTime
 0,2978704 PerfFormattedData + TimeSpan + Get-Date 07/07/2014 17:41:11 System.DateTime
 0,0796125 WMI + ConvertToDateTime                 07/07/2014 17:41:11 System.DateTime
 0,0417487 WMI query + SWbemDateTime               07/07/2014 17:41:11 System.DateTime
 0,0429207 WMI + ManagementDateTimeConverter       07/07/2014 17:41:11 System.DateTime
 0,3042627 WMI Query 12 + ConvertToDateTime        07/07/2014 17:41:11 System.DateTime
 0,1026782 WMI filter 12 + ConvertToDateTime       07/07/2014 17:41:11 System.DateTime
 0,2467589 Get-WinEvent + FilterXML 12             07/07/2014 17:41:11 System.DateTime
 0,2962874 Get-WinEvent + FilterHastTable 12       07/07/2014 17:41:11 System.DateTime
 0,2697007 Get-WinEvent + FilterXPath 12           07/07/2014 17:41:11 System.DateTime
 0,0860807 WMI filter 6005 + ConvertToDateTime     07/07/2014 17:41:19 System.DateTime
 0,0775581 WMI Query 6005 + ConvertToDateTime      07/07/2014 17:41:19 System.DateTime
12,3051242 Get-EventLog 6005 + Where-Object        07/07/2014 17:41:19 System.DateTime
 0,4015614 Get-WinEvent + FilterXML 6005           07/07/2014 17:41:19 System.DateTime
 0,2825668 Get-WinEvent + FilterHastTable 6005     07/07/2014 17:41:19 System.DateTime
 0,2678846 Get-WinEvent + FilterXPath 6005         07/07/2014 17:41:19 System.DateTime
 0,0512981 Net Stats Srv                           07/07/2014 17:41:21 System.DateTime
 0,0459907 Net Statistics Server                   07/07/2014 17:41:21 System.DateTime
15. Conclusions

All in all, taking into consideration speed of execution and precision, the syntax to remember is:

(Get-Date) - ([timespan]::FromMilliseconds([Math]::Abs([Environment]::TickCount)))
I hope you have enjoyed this post. If you do, do not hesitate to leave a comment and to share. Also, if you want to suggest any modification, correction or improvement, or should you need any help with the code, feel free to get in touch.
Related Posts Plugin for WordPress, Blogger...