The AppSense Environment Manager can provide you with valuable information related to the processes involved in login and logoff . Using Windows PowerShell you can easily retrieve this information to assist you in identifying problem spots.

When you install and configure Environment Manager (EM)  it assumes control of your login and logout process, controlling each action and when they are performed. With an efficient design the many steps of your login process can easily be subdivided into separate threads that are performed in parallel. No doubt you will have some tasks that are dependent on previous tasks. If any of those tasks take an extended amount of time to complete, you can experience long login and even logoff times for users.

If you encounter any extended times, you can enable logging in EM to assist you in identifying trouble spots. The key items that you want to enable are the logging of “Trigger Action Times” and “User Logon Success” records. When you enable the logging of these events, you can see exactly how long logins are taking, as well as the time it takes each step to complete.

The function below will pull the events from the AppSense Event Log related to action times and output them as PowerShell objects, that you can further manipulate. Summary information such as total login and logout times are available to determine the total time an action takes. If you need to drill down and identify a specific step that is causing a delay, you can use the detailed information.

  1. <#
  2. .SYNOPSIS
  3.   Parses the AppSense event log to extract information related to timings for actions.
  4. .DESCRIPTION
  5.   The Get-ActionTimes function reads the AppSense event log for AppSense Environment Manager entries related to timing of AppSense events.
  6.  
  7.   Get-ActionTimes interrogates the AppSense event log and retrieves either "Trigger Action Times" or "User Logon Success" records. Records are parsed and then are outputed as an object.  
  8.  
  9.   Requires that AppSense Environment Manager is configured to log Events 9662, and 9405 to the AppSense Event Log.
  10. .EXAMPLE
  11.   C:PS>Get-ActionTimes -Server Server01 -ReportLevel Summary 
  12.  
  13.   Action Duration EndTime                UserID       StartTime
  14.   ------ -------- -------                ------       ---------
  15.   Logoff       41 12/26/2011 8:11:00 PM  DomainUser1 12/26/2011 8:11:00 PM
  16.   Logon     10250 12/26/2011 8:10:52 PM  Domainuser2 12/26/2011 8:10:42 PM 
  17.  
  18.   Description
  19.  
  20.   -----------
  21.  
  22.   This command gets the AppSense Logon/Logoff records for Server 'Server01'.
  23.  
  24. .EXAMPLE
  25.   C:PS>Get-ActionTimes -ReportLevel Detailed
  26.  
  27.   Node      : Login Script
  28.   LogonTime : 12/26/2011 8:10:38 PM
  29.   Duration  : 1
  30.   UserID    : DomainUser1
  31.   StartTime : 12/26/2011 8:10:42 PM
  32.  
  33.   Node      : Populate Start Menu
  34.   LogonTime : 12/26/2011 8:10:38 PM
  35.   Duration  : 1
  36.   UserID    : DomainUser1
  37.   StartTime : 12/26/2011 8:10:42 PM
  38.  
  39.    Description
  40.  
  41.   -----------
  42.  
  43.   This command gets the detailed AppSense steps performed by Environment Manager for the local host.
  44. .PARAMETER ComputerName
  45.   Name of the computer to pull the event logs from.
  46. .PARAMETER ReportLevel
  47.   The level of reporting data to return.
  48.  
  49.   Possible values are either 'Detailed' or 'Summary'
  50. .PARAMETER UserName
  51.   Retrieve only the information for the specified user. Otherwise all records will be retrieved. 
  52.  
  53. #>
  54. Function Get-ActionTimes
  55. {
  56. param
  57. (
  58. [parameter(Mandatory=$False,ValueFromPipeline=$False)]
  59. [alias("Server")]
  60. [String]$ComputerName = "localhost"
  61. ,
  62. [parameter(Mandatory=$False,ValueFromPipeline=$False)]
  63. [ValidateSet('Summary','Detailed')]
  64. [String]$ReportLevel = 'Summary'
  65. ,
  66. [parameter(Mandatory=$False,ValueFromPipeline=$False)]
  67. [string]$UserName = $Null
  68. )
  69.  
  70. if ($ReportLevel -eq 'Summary')
  71. {
  72.         Write-Verbose '$ReportLevel -eq Summary'
  73.  
  74.         $AppSenseCollection = @()
  75.         Get-EventLog -ComputerName $ComputerName -LogName 'AppSense' -InstanceID 9662 | %{ 
  76.  
  77.                 if ( ( $_.UserName -ne 'NT AUTHORITYSYSTEM' ) -and ($_.Username -match [regex]::Escape("$UserName") ) )
  78.                 {
  79.  
  80.                         $UserRegex = [regex]'Trigger: (?<Action>w*) Start Time: (?<StartTime>S*) End Time: (?<EndTime>S*)  Duration: (?<Duration>d*)'
  81.                         $_.Message -match $UserRegex | Out-Null
  82.                         $EventAction = $Matches['Action']
  83.                         $EventStartTime = $Matches['StartTime']
  84.                         $EventEndTime = $Matches['EndTime']
  85.                         $EventDuration = $Matches['Duration']
  86.  
  87.                         Write-Verbose "EventAction = $EventAction"
  88.                         Write-Verbose "EventStartTime = $EventStartTime"
  89.                         Write-Verbose "EventEndTime = $EventEndTime"
  90.                         Write-Verbose "EventDuration = $EventDuration"
  91.  
  92.                         $AppSenseInfo = New-Object PSObject -Property @{
  93.                                 UserID = [string]$_.UserName
  94.                                 Action = [string]$EventAction
  95.                                 StartTime = ([datetime]$EventStartTime).ToLocalTime()
  96.                                 EndTime = ([datetime]$EventEndTime).ToLocalTime()
  97.                                 Duration = [Int32]$EventDuration
  98.                         }
  99.  
  100.                         $AppSenseCollection += $AppSenseInfo
  101.                 }
  102.         }
  103.  
  104.         Write-Output $AppSenseCollection
  105.  
  106. }
  107. elseif ($ReportLevel -eq 'Detailed')
  108. {
  109.         Write-Verbose '$ReportLevel -eq Detailed'
  110.  
  111.         $AppSenseCollection = @()
  112.         Get-EventLog -ComputerName $ComputerName -LogName 'AppSense' -InstanceID 9405 | %{
  113.                 if ( ( $_.UserName -ne 'NT AUTHORITYSYSTEM' ) -and ($_.Username -match [regex]::Escape("$UserName") ) )
  114.                 {
  115.                         $UserRegex = [regex]'Logon Time: (?<LogonTime>S*) Node Name: (?<Node>.*) Start Time: (?<StartTime>S*) Duration: (?<Duration>d*)ms.'
  116.                         $_.Message -match $UserRegEx | Out-Null
  117.                         $LogonTime = $Matches['LogonTime']
  118.                         $Node = $Matches['Node']
  119.                         $StartTime = $Matches['StartTime']
  120.                         $Duration = $Matches['Duration'] 
  121.  
  122.                         Write-Verbose "LogonTime = $LogonTime"
  123.                         Write-Verbose "Node = $Node"
  124.                         WRite-Verbose "StartTime = $StartTime"
  125.                         Write-Verbose "Duration = $Duration"
  126.                         $AppSenseInfo = New-Object PSObject -Property @{
  127.                                 UserID = [string]$_.UserName
  128.                                 LogonTime = ([datetime]$LogonTime).ToLocalTime()
  129.                                 Node = [string]$Node
  130.                                 StartTime = ([datetime]$StartTime).ToLocalTime()
  131.                                 Duration = [Int32]$Duration
  132.  
  133.                         }
  134.                         $AppSenseCollection += $AppSenseInfo
  135.                 }
  136.  
  137.         }
  138.         $AppSenseCollection
  139.  
  140. }
  141.  
  142. }