Interpreting Userenv log files

Applies To: Windows Server 2003, Windows Server 2003 R2, Windows Server 2003 with SP1, Windows Server 2003 with SP2

This topic explains how to interpret userenv log files.

Userenv Logging

When you enable userenv logging, you can perform debug logging of the user profile and the system policy processes. Userenv log files also contain information about the status of each Group Policy extension, such as Application Deployment, Security, and Folder Redirection. Userenv log files reveal what is occurring in the background as a user logs on. Userenv log files are especially useful because they be can be used to troubleshoot Windows 2000 operating systems, in which you cannot use Resultant Set of Policy (RSoP). In addition, if Active Directory replication is not working, RSoP will not work, leaving userenv log files as the only troubleshooting option. RSoP also depends on Windows Management Instrumentation (WMI), which might also fail and leave you with no option but to analyze the userenv log files. With verbose logging, information is logged every second; if something fails you can review the userenv logs and pinpoint the likely source of failure.

Userenv log files contains information about the following:

• Group Policy settings that are not processed or not applied as expected

• Folder redirection that does not occur

• Profile or registry hive load, unload, or deletion failures

• Logon script, or script not applied as expected

• Default behaviors occurring because a slow link was detected

• Roaming profile issues

• Slow logon issues

• Whether a given GPO is accessible, and if not, why access was denied.

• The name of the domain controller that is accessing SYSVOL.

What is in the Userenv log?

The example of the Userenv log in this section shows the type of details of errors in core Group Policy processing that the Userenv log provides. Reading from left to right, this log shows a process code (for example, cc.500), the time it was processed (note the date is not displayed), the process name, and a short statement of the error. The Userenv log displays Group Policy process failures and warnings.

Sample Userenv log

USERENV(178.17c) 13:48:51:089 MyRegUnLoadKey:  Failed to unmount hive 00000005
USERENV(178.17c) 13:48:51:089 DumpOpenRegistryHandle: 3 user registry Handles leaked from \Registry\User\S-1-5-21-2127521184-1604012920-1887927527-2193396
USERENV(178.17c) 13:48:51:089 UnloadUserProfileP: Didn't unload user profile <err = 5>
USERENV(178.2e8) 13:52:00:708 GetGPOInfo:  Local GPO's gpt.ini is not accessible, assuming default state.
USERENV(178.600) 13:52:09:452 GetGPOInfo:  Local GPO's gpt.ini is not accessible, assuming default state.
USERENV(178.4d4) 13:52:15:020 PolicyChangedThread: UpdateUser failed with 6.

General Userenv.log Messages

The following messages have the same meaning no matter where they appear in the log:

• Failed to Allocate…

• Failed to Create…

• Failed to Set…

• Failed to Get…

• These errors normally indicate a problem with system resources at the time when they were called. If you receive multiple errors at the same time, your computer could be having integrity problems. To avoid these problems, try to ensure that the computer is as close to a base install of Windows as possible by removing all third party software programs. If this option is not possible for you, install a new version of Windows and all available service packs on a test machine. If the error is no longer appearing in the log file, slowly install third party software, one program at a time. Monitor the Userenv log after each program is installed to determine which program is causing the error.

The following messages also have the same meaning no matter where they appear in the log:

• Calling function <function failed>

• Calling function <function returned>

• These entries indicate that an underlying function was called and that there was an error in the transaction. Determine which function the entry is causing the error by viewing the error text, and then locate the function that failed in the log. After you have identified the failed function entry in the log, get the return code and start troubleshooting the failed function from there.

ApplyGroupPolicy Messages

ApplyGroupPolicy: Entering. Flags = %x

You use flags to determine what processing Group Policies need to do and what some of the Client Side Extensions (CSEs) are doing. Flags are hexadecimal bits that might need to be converted if the number is above nine.

The values listed in the following table are added to the flags after processing.

CheckGPOs Messages

Most of the log messages from this function are self-explanatory. The following is the most common error that users ask about in relation to CheckGPOs log messages.

CheckGPOs: No GPO changes but couldn't read extension %s's status or policy time.

Group Policy stores the status and the time of each extension as needed for the machine and every user that logs onto the machine. They are stored in the following registry locations:

MACHINE

HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows\CurrentVersion\Group Policy\State\Machine\Extension-List

USER

HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows\CurrentVersion\Group Policy\State\<SID>\Extension-List

If you receive this error, check your registry permissions for any explicit denials on the registry settings. Also, check for any third-party software that might manipulate this key. Some third parties change the Group Policy cache in both the file system and registry to have their product mimic Group Policy.

EnterCriticalPolicySection Messages

This is a potentially serious log message. It could indicate that certain portions of the operating system have become corrupt due to improper shut-down or system crashes. It could also indicate a system resource problem, similar to the "Failed to…" errors mentioned earlier in this section. To troubleshoot this issue, remove all third-party software to determine if a non-Microsoft program is causing this error. If that does not fix the problem, start with a clean installation of Windows, install all necessary service packs, and then introduce the clean computer into your environment. Monitor the Userenv log while installing any additional programs to determine what could be causing this error.

GPOThread

GPOThread: Next refresh will happen in %d minutes

This is an informational message. It is the only place within the operating system that indicates when the next time Group Policy will refresh.

LeaveCriticalPolicySection

See the "EnterCriticalPolicySection" section earlier in this document.

LibMain

LibMain: Process Name: %s"

This is an informational message. This message appears in the userenv.log when an application loads Userenv.dll within its space. Userenv has many exported functions that deal with loading and unloading the user’s profile. Therefore, many application need to go through Userenv to get the profile of the currently logged on user for application specific settings. This message indicates which application is loading an instance of Userenv.dll.

ProcessGPO

ProcessGPO: Found flags of: %d"

This is an informational message. To determine what the flag in the message means, see the following list:

• 0 = Both user and Computer Configuration are Enabled

• 1 = User Configuration is Disabled

• 2 = Computer Configuration is Disabled

ProcessGPO: Found machine version of: GPC is %d, GPT is %d"

ProcessGPO: Found user version of: GPC is %d, GPT is %d"

These two messages are misrepresented in the Userenv log. It states GPC and GPT but it does not actually read from the GPT. It reads both settings from the GroupPolicyContainer Object (GPC) and not SYSVOL. The Attribute it reads is the Version number, which is stored as an integer value. If you believe you have a SYSVOL problem, run GPOTOOL to determine where errors might exist.

ProcessGPORegistryPolicy

ProcessGPORegistryPolicy: Failed to create archive file with %d"

The archive file in question is named ntuser.pol and is located in the user's profile. If you receive this error in the Userenv log, determine whether you are having problems with profile loading or unloading. Also, make sure that the user has write permissions to the profile folder because ntuser.pol is created in the root of the user profile.

ProcessGPOs: Machine role is %d."

This entry includes a decimal number at the end (%d). To determine what processing is going on within Userenv, see the following list:

• 0 = Standalone machine that is not a member of a Directory Services Domain

• 1 = The machine is a member of a NT4 domain

• 2 = The machine is a member of a domain which supports Directory Services.

• 3 = The machine is a domain controller

This information helps you determine what kind of machine you are troubleshooting, which could indicate why a policy is or is not applying.

ProcessGPOs: The DC for domain %s is not available. aborting"

ProcessGPOs: The DC for domain %s is not available."

These messages can be caused by network problems or the Windows XP Fast-User logon Optimization option. Try turning off the Fast-User Optimization option. If that does not cause the errors to stop, you might have a network problem. Troubleshoot this as you would any network problem.

ProcessGPOs: DSGetDCName failed with %d."

DsGetDCName is a public API that performs Domain Controller discovery. Troubleshooting this most of the time will involve name resolution. You can simulate this call by using the utility nltest.exe. Use the command ipconfig /flushdns before using nltest when you are taking a network monitor trace. Windows has a client-side cache, and you want to capture the DNS data in the trace. The syntax for nltest is:

nltest /DSGETDC: DomainName

ProcessGPOs: GetNetworkName failed with %d."

This function writes the FQDN of the domain into the Group Policy Cache. Many of the CSEs and Components that are policy implemented look for this name in the cache. This return code should be used wit the net command to determine the error message. Some of the lower-level functions in this name are Winsock library calls. If this is appearing and you are seeing some policies fail, make sure the machine is free from any viruses, worms, or other forms of malicious software.

ProcessGPOs: Calling GetGPOInfo for normal policy mode"

This is an informational message. This lets you know that you are processing policy in normal mode.

ProcessGPOs: Calling GetGPOInfo for replacement user policy mode"

This is an informational message. This message appears if the computer is in Group Policy loopback mode. Group Policy uses the user policy settings from the location of the computer object, and Group Policy does not honor any of the user policy settings based on the user’s object in Active Directory.

ProcessGPOs: Calling GetGPOInfo for merging user policy mode"

This is an informational message. This message appears when the computer is in Group Policy loopback mode. Group Policy merges the user specific policy settings based on where the user’s object is located in Active Directory along with the location of the computer object settings in Active Directory.

ProcessGPOs: Extension %s skipped with flags 0x%x."

This message indicates that a client-side extension was skipped. Use the flag values to determine why the extension was skipped. Typically, it is background processing, but make sure it was not caused by an error.

ProcessGPOs: Extension %s ProcessGroupPolicy failed, status 0x%x."

This message appears if the extension has actually failed. Use the net command with the return status to determine what the possible causes are. Enable additional logging for the extension specified to determine a more accurate error. Remember the status returned to ProcessGPOs is mapped to a more standard Windows Error. More specific errors might be revealed in the extension's debug log.

ProcessGPOs: Couldn't read status data for %s. Error %d. ignoring..

This is an informational message. This message appears to be an error, however the Group Policy engine automatically processes the extension because it cannot read the status data, hence the "ignoring" notation at the end of the message.

ProcessGPOs: Computer Group Policy has been applied.

ProcessGPOs: User Group Policy has been applied.

These are informational messages. These messages indicate that the Group policy has applied policy to the best of its ability. It does not mean that there were not any errors.

ProcessGPOs: Leaving with %d."

This is an informational message. If this value is not 0, the policy encountered a problem when it was applied. The fact that it appears in the log as well as the two messages above means the Group Policy was able to handle the error gracefully and move on.

SearchDSObject

SearchDSObject: Searching <%s>"

This function is used to determine which policy objects are within scope for the logging on user or computer. It should have a Distinguished Name (DN) of the object in Active Directory. The DN should either be a Site object, Domain object, or an Organizational Unit object. This is the location in Active Directory in which the Group Policy engine is searching for linked policy objects.

SearchDSObject: Too many linked GPOs in search.

This error message is not actually a Group Policy error but rather an LDAP Error, LDAP_SIZELIMIT_EXCEEDED. The value is determined by the Search Request.

SearchDSObject: Found GPO(s): <%s>

Here is an example from a Userenv.log file.

SearchDSObject:  Found GPO(s):  <[LDAP://CN={31B2F340-016D-11D2-945F-00C04FB984F9},CN=Policies,CN=System,DC=corp,DC=mstep,DC=com;0]>

Notice there is a ;0] at the end of the message. This value has meaning and it will appear on every policy that is linked. To determine the value, see the following table :

• 0 = This is the default setting. The policy is enabled

• 1 = This policy is disabled

• 2 = This policy will be forced or cannot be overridden and will win all ties against block policy inheritance

• 3 = Settings 1 and 2 are both enabled hence the policy will be disabled.

SearchDSObject: <%s> has the Block From Above attribute set"

The Block From Above attribute prevents a linked policy from being inherited by a Site, Domain, or OU beneath it. Generally, this is only set at an OU level, however the option is available anywhere a policy can be linked. This setting is stored on the actual container object, just as the policies that are linked to the container. This specific value can be found in on the attribute Gpoption. This attribute is an integer value and only has two settings: zero (0) (default) indicates normal propagation of the policy to the container, and one (1) turns on Block Policy Inheritance, which prevents polices higher in the tree from applying to the container or objects in the container. A policy that has No Override or Force, ignores the Block Policy Inheritance flag and still applies.

RETURN CODES

This section contains the return codes listed throughout a Userenv.log. You can use this section to determine what the codes mean and how to apply them to the specific function that is returning them.

General Rules

Most functions return true, false, or a status code. For this documentation true or successful is represented by a 0. False or unsuccessful is represented by a 1. Status codes have different meanings. This section documents most of the well known status messages.

Most return codes, after they are converted from hexadecimal to decimal, can be described by using the net command. The command-line syntax is:

NET HELPMSG Number

Messages that begin with 0xC or anything similar will probably not work with the net command and are listed in the "Return Codes that cannot be converted with the net command " table later in this document.

Return Codes

Return Codes that cannot be converted with the net command

LDAP ERROR CODES

Some of the messages return LDAP Error codes. You can recognize these error codes because the function usually starts with ldap_.