Temporary User Profiles and the Citrix ICA Client

Howdy folks, Scott Goad again to talk about an issue that I thought you might find useful.

I recently worked with a customer who opened a case for an intermittent profile issue. Windows XP workstations would not load the local profile, resulting in the user receiving a temporary profile. The issue seemed to happen when a user logged off and then needed to log back into the workstation, resulting in the temporary profile.

We started the usual troubleshooting steps for working on this type of profile load problems. We enabled USERENV debug logging (more on that here). The customer readily enabled the logging and proceeded to reproduce the issue. They were able to gather a problematic log along with a saved copy of MSINFO32, which grabs the processes running and their associated Process ID. This is useful to identify what process is running, which is recorded in the USERENV log. The USERENV log did show a problem:

USERENV(350.354) 10:32:02:454 Local Existing Profile Image is reachable
USERENV(350.354) 10:32:02:454 Local profile name is <C:\Documents and Settings\**********>
USERENV(350.354) 10:32:02:454 RestoreUserProfile: No central profile. Attempting to load local profile.
USERENV(350.354) 10:32:02:485 MyRegLoadKey: Failed to load subkey <S-1-5-21-*********-1284227242-725345543-121116>, error =32
USERENV(350.354) 10:32:02:485 MyRegLoadKey: Returning 00000020
USERENV(350.354) 10:32:02:501 RestoreUserProfile: MyRegLoadKey returned FALSE.
USERENV(350.354) 10:32:02:501 ReportError: Impersonating user.
USERENV(350.354) 10:32:02:501 ReportError: Logging Error <Windows cannot load the locally stored profile. Possible causes of this error include insufficient security rights or a corrupt local profile. If this problem persists, contact your network administrator.

DETAIL - The process cannot access the file because it is being used by another process.
>

USERENV(350.354) 10:32:02:501 ErrorDialogEx: Calling DialogBoxParam
USERENV(350.354) 10:32:02:501 ErrorDlgProc:: DialogBoxParam

At this point we knew the problem was an issue with WINLOGON trying to load the profile, but couldn’t because another process was holding a file hostage within the profile. The USERENV log will tell us what process is being called, but here 350 (hexadecimal for 848) is WINLOGON:

image

This was good to know, but not helpful as to why the profile could not be loaded. The next step in the troubleshooting process was to get a Process Monitor trace of the issue. This provided a bit of a challenge, since this happens at logon. We used Process Monitor and enabled boot logging, which started a trace in the background. The customer had to restart the workstation for the logging to start, and try to reproduce the problem.

When the problem was reproduced, USERENV logged the following 1508 event in the Application Log:

image

Now we knew what to look for in the Process Monitor trace, so we cracked the PML file open and set a few filters. After filtering the trace, we saw where the problem resides. We started with including the path of UsrClass.dat and also to exclude RESULT is SUCCESS. This showed the problem, which is a SHARING VIOLATION. Here is a screenshot of the trace, with the surrounding events displayed (removing the RESULT is SUCCESS filter):

The culprit process in this trace appears to be SSONSVR.exe. The details can be seen here:

 

image

image

At this point we engaged Citrix and looked into the issue. This has been documented as a known problem with the 10.200 release of the Citrix ICA client, and is fixed in a future release. Citrix has documented the issue in their knowledge center, and a link is detailed below.

The issue presents itself in Windows XP (all current service packs) where prefetch loads SSONSVR.exe into memory to enhance boot time performance. This is causing a race condition with WINLOGON and SSONSVR trying to both access the profile, resulting in the SHARING VIOLATION.

The customer was in the process of rolling out the 10.200 version of Citrix ICA Client, so they decided to go with disabling prefetch for the SSONSVR.exe process, as outlined in KB 969100, by deleting the SSONSVR*.pf from %SYSTEMROOT%\prefetch directory at logoff.

Resources:

969100 When you log on to a Windows XP-based computer that is running version 10.200 of the Citrix ICA client, Windows XP may create a user profile instead of loading your cached profile

https://support.microsoft.com/default.aspx?scid=kb;EN-US;969100

Citrix Knowledge Center – User Client Computer Profile is not Loaded Properly when Single Sign-on is Enabled - https://support.citrix.com/article/CTX118226

221833 How to enable user environment debug logging in retail builds of Windows

https://support.microsoft.com/default.aspx?scid=kb;EN-US;221833

Understanding How to Read USERENV logs – AskDS Blog by Mark Ramey

https://blogs.technet.com/askds/archive/2008/11/11/understanding-how-to-read-a-userenv-log-part-1.aspx

https://blogs.technet.com/askds/archive/2008/11/11/understanding-how-to-read-a-userenv-log-part-2.aspx

Process Monitor v2.04

https://technet.microsoft.com/en-us/sysinternals/bb896645.aspx

 

Until next time,

Scott “Scooter” Goad