Take the 2-minute tour ×
Server Fault is a question and answer site for professional system and network administrators. It's 100% free, no registration required.

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.

share|improve this question
    
What do you mean by "locked"? What's the message when you try changing the values? Did you start Regadit "as Administrator" to circumvent limitations of your current account's permissions or the restrictions set by UAC? –  the-wabbit Jan 30 '12 at 0:44
    
Editing the the key via regedit run as administrator results in, "Cannot edit BootMinorThreshold_Sec: Error writing the value's new contents.' –  Decad Jan 30 '12 at 0:55
    
Make sure you have the permissions to change the values of this key. Also check if your antivirus engine is not blocking registry changes for some unfathomable reason. –  the-wabbit Jan 30 '12 at 1:00
    
No antivirus currently running on this machine as it is a fresh install for testing. I am running as local administrator. Is there a way to check permissions on the keys? –  Decad Jan 30 '12 at 1:03
3  
How do you define "user login time" ? This the time between the user validates its username+password and explorer is ready to launch a program ? –  Gregory MOUSSAT Jan 30 '12 at 1:07

4 Answers 4

up vote 2 down vote accepted
+100

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.

share|improve this answer
    
Thanks for your answer, I'll give it a try –  Decad Feb 2 '12 at 15:03
    
The Time-sync after boot doesn't appear to be happening. I rebooted my test machine and ran the script. I got -4,657.9 Minutes for my boot duration. Due to the time-sync being dated 2 days ago. –  Decad Feb 2 '12 at 15:51
    
I guess my domain policies are setup differently. We have "always wait for the network.." turned on, could be why. Also, if you only need log on duration you could comment out those boot-up parts –  Jordan W. Feb 2 '12 at 16:08
    
This script only times authentication not logon –  Jim B Feb 8 '12 at 19:45

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.

share|improve this answer
    
I looked into xperf a while back. But I had the feeling that this was more of a one off debugging tool? Can it be setup to run for every boot and every login? –  Decad Feb 3 '12 at 14:23
    
it could, but why do you need to measure every boot and every login? –  Jim B Feb 3 '12 at 15:24
    
There has been complaits by some users about login times, they want to be armed with the facts when someone complains about it. As of now they have no facts to back them up. So they want to be able to display and monitor login times for users and for machines. IE machine0001 - average login time is 10seconds. User joe blogs average login time is 8 seconds. This would only need to run for long enough to get enough data to get decent enough averages. –  Decad Feb 3 '12 at 15:51
    
If you have an intermittent problem, an average isn't going to help you. When a user complains the first thing to look at is the group policy processing logs and see if there is a problem (99% of the time it's a script). After that I'd install the tool, reboot and have them login again. –  Jim B Feb 5 '12 at 18:47
    
We solve intermittent cases in a similar manner as you are suggesting and it is normally a script. However they want to be able to display the figures to the users to help show them that login times are not as bad as the reputation that they currently have. –  Decad Feb 5 '12 at 22:19

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 :)

share|improve this answer

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.

share|improve this answer
    
Thanks for the reply, I'll give it a try –  Decad Feb 2 '12 at 15:03
    
The user GPOs are applied after login but before execution of the loginscript. This time would be missing. –  Tom Feb 2 '12 at 15:12
    
If I placed this batch file in the machines startup, it would give a more acceptable reading I think? –  Decad Feb 2 '12 at 15:53
    
@Decad I was going to suggest that as an option, but thought it would easier to deploy the script using a logon script. Personally I'd deploy it as a legacy logon script. i.e. via the Profile tab of the user account property dialogue in ADU&C. This definitely runs as the explorer shell loads. –  Bryan Feb 2 '12 at 17:11
    
I think scripts run during explorerinit, (which is why login scripts slow up logins) –  Jim B Feb 8 '12 at 2:39

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Not the answer you're looking for? Browse other questions tagged or ask your own question.