Measuring Windows 7 user login times

Question

I Have been asked by a client to calculate average login times for machines and users. So far I have found that the event logs some boots that take longer than the thresholds set by the keys found at:

HKLM\Software\Microsoft\Windows\CurrentVersion\Diagnostics\Performance\Boot

But the keys seem to be locked so I can't edit them to make the thresholds lower to ensure logging of every boot. Is there any methods for finding login times for each log on that is verbose enough to tell the user that is logging in and possible more detailed information, this also needs to be light enough to run on every login and not cause noticeable effects to the user.

Answer 1

I was recently asked to do a very similar thing but to include bootup and logon times and allow for historical reference. so the powershell script below does the following:

1. grabs some environment variables
2. gets the time\date stamp for 4 different event log entries. The 2nd and 4th of these are not exact measurements but after pretty extensive research, troubleshooting and testing they're super close and from what I've seen, the best options.
3. calculates the difference between these 4 events
4. populates all numbers into a simple SQL table [you could adapt to pipe the numbers into anything you want of course]

So the script is meant to run via scheduled task or on some schedule if you have SCCM perhaps (not during logon so as not to change the logon at all). the nice thing is you can change the PCname to anything else to run it from your own PC and get the data from a remote computer (although the username would show up as your own) to troubleshoot and verify the numbers.

I took it another step and used SharePoint to create a list of external data (using BCS) so they have a nice front end GUI. Script below, I've left in most of the commented lines I used while writing it:

$USER = $env:username.ToUpper()
$COMPUTER = $env:computername.ToUpper()
$Current_Time = Get-Date
$PCname = ''
$addedtime = 0

#1. get event time of last OS load
$filterXML = @'
<QueryList>
  <Query Id="0" Path="System">
    <Select Path="System">*[System[Provider[@Name='Microsoft-Windows-Kernel-General'] and (Level=4 or Level=0) and (EventID=12)]]</Select>
  </Query>
</QueryList>
'@
$OSLoadTime=(Get-WinEvent -ComputerName $PCname -MaxEvents 1 -FilterXml $filterXML).timecreated
#Write-Host $PCname
#Write-Host "1. Last System Boot @ " $OSLoadTime

#2. Get event time of Time-Service [pre-Ctrl+Alt-Del] after latest OS load
$filterXML = @'
<QueryList>
  <Query Id="0" Path="System">
    <Select Path="System">*[System[Provider[@Name='Microsoft-Windows-Time-Service'] and (Level=4 or Level=0) and (EventID=35)]]</Select>
  </Query>
</QueryList>
'@
$CtrlAltDelTime=(Get-WinEvent -ComputerName $PCname -MaxEvents 1 -FilterXml $filterXML).timecreated
#Write-Host "2. Time-sync after Boot @ " $CtrlAltDelTime
#get minutes (rounded to 1 decimal) between OS load time and 1st load of GPOs
$BootDuration = "{0:N1}" -f ((($CtrlAltDelTime - $OSLoadTime).TotalSeconds + $addedtime)/60)

#3. get event time of 1st successful logon
$filterXML = @'
<QueryList>
  <Query Id="0" Path="System">
    <Select Path="System">*[System[Provider[@Name='Microsoft-Windows-Winlogon'] and (Level=4 or Level=0) and (EventID=7001)]]</Select>
  </Query>
</QueryList>
'@
$LogonDateTime=(Get-WinEvent -ComputerName $PCname -MaxEvents 1 -FilterXml $filterXML -ErrorAction SilentlyContinue).timecreated

If ($LogonDateTime) { 
    #Write-Host "3. Successful Logon @ " $LogonDateTime 
    } 
    Else {
    #Write-Host "Duration of Bootup = " $BootDuration "minutes" -foregroundcolor blue -BackgroundColor white
    #Write-Host $PCname "has not logged back in." -foregroundcolor red -BackgroundColor white
    Exit
    }
#Write-Host "Duration of Bootup = " $BootDuration "minutes" -foregroundcolor blue -BackgroundColor white

#4. Get Win License validated after logon (about same time as explorer loads)
$filterXML = @'
<QueryList>
  <Query Id="0" Path="Application">
    <Select Path="Application">*[System[Provider[@Name='Microsoft-Windows-Winlogon'] and (Level=4 or Level=0) and (EventID=4101)]]</Select>
  </Query>
</QueryList>
'@
$DesktopTime=(Get-WinEvent -ComputerName $PCname -MaxEvents 1 -FilterXml $filterXML).timecreated
$LogonDuration = "{0:N1}" -f ((($DesktopTime - $LogonDateTime).TotalSeconds + $addedtime)/60)
#Write-Host "4. WinLicVal after Logon @ " $DesktopTime
#Write-Host "Duration of Logon = " $LogonDuration "minutes" -foregroundcolor blue -BackgroundColor white

#START SQL Injection Section
[void][reflection.assembly]::LoadWithPartialName("Microsoft.SqlServer.Smo")

$sqlServer = "SQLserver01"
$dbName = "BootUpTimes"
$tbl = "tblBootUpTimes"
#$srv = New-Object Microsoft.SqlServer.Management.Smo.Server $sqlServer
#$db = $srv.databases[$dbName]
#$conn = New-Object System.Data.SqlClient.SqlConnection("Data Source=$sqlServer;Initial Catalog=$dbName; Integrated Security=SSPI")
$conn = New-Object System.Data.SqlClient.SqlConnection("server=$sqlServer;database=$dbName;Password=plaintext;User Id=BootUpTimes")
$conn.Open()
$cmd = $conn.CreateCommand()
$cmd.CommandText = "INSERT INTO $tbl VALUES ('$Current_Time','$USER','$COMPUTER','$OSLoadTime','$CtrlAltDelTime','$BootDuration','$LogonDateTime','$DesktopTime','$LogonDuration')"
Try
{
$null = $cmd.ExecuteNonQuery()
}
Catch
{
}
$conn.Close()

In this last SQL section there is a commented out few lines offering another method (security-based) to input into SQL without needing some password in plaintext.

Answer 2

I'm not sure why anyone would think a script would help you determine logon times (after all you can't run the script until someone has logged on, and pulling times won't help since time drift would certainly cause misreporting -which also wouldn't be fixed until startup processing. The tool I'd suggest you use is the xperf tool from the performance toolkit. You want to look at explorerinit times for total logon time. see Windows On/Off Transition Performance Analysis for detailed explanations of what happens from boot to desktop. See Windows Performance Analysis Tools to get xperf and xbootmgr from the appropriate- places.

Answer 3

http://superuser.com/questions/250267/how-to-diagnose-slow-booting-or-logon-in-windows-7

This thread shows the "Microsoft" way of boot diag using Windows Performance Analysis Tools

Very good documented procedure from Microsoft on "On/Off Transition Performance" aka turning Windows on or off: http://msdn.microsoft.com/en-us/windows/hardware/gg463386.aspx

Using these official tools, you can provide an authoritative answer to your client. Far superior than trying to use scripting, in my opinion. May be slightly overkill if your needs are basic.

Also from that thread don't miss Soluto's website if your needs are extremely basic :)

Answer 4

The following batch file executed as a logon script will go some way towards telling you how long it takes from the authentication to the shell being ready.

set logfile=\\server\share\%computername%-%username%.log
net user /domain %username% | find /I "Last logon" > %logfile%
net time %logonserver% >> %logfile%

I've not tested this, and I've made a few assumptions.

1. The logon time returned by net user is the time the DC performed the authentication. I believe this is the case, but can't find anything concrete to back that up.
2. The logon script runs as the user shell loads. This certainly is the case if you use the older legacy NT4 logon scripts, as opposed the logon scripts defined by group policies, but as the GPO logon scripts run hidden from the user (by default), I've never seen the timing of when they are executed.
3. Your usernames don't contain spaces, you might need to put %username% in quotes if this is the case.
4. You have a world writeable share where the data will be logged (\\server\share in the above example). You could log it locally on individual machines, but that will make it harder to examine the results.

Edit:

I've updated the script to deal with time drift that Jim is concerned with. The logon start time from net use command is taken from the clock of the authenticating domain controller. The net time command now also takes the time from the same server.