Pages

Thursday, May 14, 2020

Troubleshooting slow Windows VDI logon performance with Citrix Director and Windows Event Logs

One of the most common engagements I am engaged with for post Citrix or VMware virtual desktop deployments is to troubleshoot slow Windows VDI login performance and I’ve found that if profile management solutions such as Citrix UPM was deployed correctly, the root cause would typically be the Active Directory Group Policy Objects that are either intentionally or unintentionally applied to the user accounts or desktops. Having gone through an exercise I’ve done numerous in the past today and realizing I never wrote a blog post about it, this post will serve to demonstrate how I typically approach the troubleshooting process in a Citrix XenDesktop VDI environment.

Step #1 – Replicate the issue

The first step is to replicate the issue so use an account that is experiencing the slow logon times and log onto a virtual desktop while making a note of when you logged on and when it completed as you will need these later.

Step #2 – Review the duration for each component during the logon process

Leave the session to the desktop connected once the login process has completed and then proceed to launch the Citrix Director or the Monitor console in Citrix Cloud’s Virtual Apps and Desktops Service and then click on the Trends option:

image

With the Trends console displayed, click on the Logon Performance tab and scroll down to the Logon Duration by User Session section:

image

In the Search associated users field, search for the login name of the user account that was used to test:

image

As shown in the screenshot above, a breakdown of the duration for the logon is displayed in multiple columns. The headings that typically consumes the most amount of time are:

  1. GPOs
  2. Profile Load

GPOs are the Active Directory Group Policy objects that are applied to the account during logon and the Profile Load is, in this case, Citrix UPM that is configured.

From the metrics provided above, we can see that the Profile Load takes approximately 10.966 seconds while the GPOs take 35.99 seconds.

Step #3 – Review Citrix UPM logs

To gain a better understanding of the processes contributing to the Profile Load process, navigate back to the virtual desktop that was used for testing and navigate to the following directory:

C:\Windows\System32\LogFiles\UserProfileManager

**Note that this directory is configurable but this environment uses the default.

The log we are interested in ends with the desktop name_pm.log as shown in the screenshot below:

image

Open the log and navigate to the line with Starting logon processing to review how long each process has taken:

image

Step #4 – Review Event Logs for GPOs

If the GPOs being applied to the user and virtual desktop is causing an extended amount of time during the logon process then the next step is to launch the event logs of the virtual desktop and navigate to the following event log:

Microsoft/Windows/GroupPolicy/Operational

Scroll and locate the event ID 5324 that has a time stamp close to the time you initiated the login:

image

Scroll upwards to later events and you should see an event ID 4001 that states the following details: Starting user logon Policy processing for <your username>:

image

Continue to scroll up and you’ll see another event 4017 entry that specifies which domain controller was used for the LDAP bind:

image 

Continuing to the next event ID 5017 will show how long the LDAP bind took:

image 

The next event ID 5326 will indicate how long the domain controller discovery took:

image 

An event ID 5327 will be written to provide an estimated bandwidth:

image 

From here on the following event entries will allow you to determine how long each component is consuming during the login process for the user.

Registry Extension Processing duration:

image 

Citrix Group Policy Extension Processing duration:

image 

Folder Redirection Extension Processing duration:

image 

Group Policy Drive Maps Extension Processing duration:

image 

Group Policy Printers Extension Processing duration:

image

The last event ID 8001 will display how long the GPO process took for the user:

clip_image002

Note how it is identical to what is logged by Citrix:

clip_image002[5]

Hope this helps anyone who may need to go through this process of identifying the potential causes for long login times.

No comments: